Very simple example log file - Recording program execution [closed]

Question

I'm after a very simple example log file with corresponding code, that expresses exactly what would need to be recorded to enable deterministic replay - for the purpose of record/replay debugging.

Thanks.

Answer 1

I'm not quite sure what you're after – the minimum you need to record for a given program to have a deterministic replay isn't well defined. In general, you choose some API boundary – for example, the system call interface, or some set of library calls, or even the interface between the OS and hardware – and then record there. Which API boundary you choose to record at will mean you have to record more or less information in order to guarantee deterministic replay; the question of how to find the API boundary that requires the least amount of storage has been explored in the paper Language-Based Replay via Data Flow Cut.

But perhaps you're after something more practical – an example of a simple program and its corresponding record/replay log. This is something you can get very easily with e.g. Mozilla's rr. Suppose we have the following simple program:

#include <stdio.h>

int main(int argc, char **argv) {
    printf("Hello world: %s\n", argv[1]);
    return 0;
}  

We can then record it under rr:

$ git/rr/bin/rr record ./hello foo
rr: Saving the execution of `./hello' to trace directory `/home/moyix/.rr/hello-1'.
Hello world: foo

And then you can see the information that rr captured using rr dump; a selection of that looks like:

{
  global_time:177, event:`SYSCALL: rrcall_init_buffers' (state:EXITING_SYSCALL) tid:83791, ticks:42871
 rax:0x7fa27fd0b000 rbx:0xfffffffffffffff8 rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0x7ffd504447f0 rbp:0x64 rsp:0x7ffd504447a0 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x7ffd50444800 r13:0x7ffd504447f0 r14:0x1474f r15:0x0 rip:0x70000038 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x1bb
}
{
  global_time:178, event:`SYSCALL: rt_sigprocmask' (state:ENTERING_SYSCALL) tid:83791, ticks:42872
 rax:0xffffffffffffffda rbx:0xfffffffffffffff8 rcx:0xffffffffffffffff rdx:0x0 rsi:0x7ffd50444800 rdi:0x2 rbp:0x64 rsp:0x7ffd504447a0 r8:0x0 r9:0x0 r10:0x8 r11:0x246 r12:0x7ffd50444800 r13:0x7ffd504447f0 r14:0x1474f r15:0x0 rip:0x70000038 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xe
}
{
  global_time:179, event:`SYSCALL: rt_sigprocmask' (state:EXITING_SYSCALL) tid:83791, ticks:42872
 rax:0x0 rbx:0xfffffffffffffff8 rcx:0xffffffffffffffff rdx:0x0 rsi:0x7ffd50444800 rdi:0x2 rbp:0x64 rsp:0x7ffd504447a0 r8:0x0 r9:0x0 r10:0x8 r11:0x246 r12:0x7ffd50444800 r13:0x7ffd504447f0 r14:0x1474f r15:0x0 rip:0x70000038 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xe
}
{
  global_time:180, event:`PATCH_SYSCALL' tid:83791, ticks:43212
  { map_file:"", addr:0x7fa27fc2c000, length:0x1000, prot_flags:"r-xp", file_offset:0x0 }
  { addr:0x7fa27fc2c000, length:0xe }
  { addr:0x7fa27f71ff82, length:0x5 }
  { addr:0x7fa27f71ff87, length:0x3 }
  { addr:0x7fa27f9f3349, length:0x3a }
}

You could also look at another recording interface, e.g. PANDA's. The rr_print utility in PANDA can print out the log of nondeterministic events, e.g.:

{guest_instr_count=4180 pc=0x8265a2c8, secondary=0x82743c28}
        RR_INTERRUPT_REQUEST_2 from RR_CALLSITE_CPU_EXEC_1
{guest_instr_count=4180 pc=0x8265a2c8, secondary=0x82743c28}
        RR_INTERRUPT_REQUEST_2 from RR_CALLSITE_CPU_EXEC_4
{guest_instr_count=4207 pc=0x8d0703f6, secondary=0x848f9818}
        RR_INTERRUPT_REQUEST_2 from RR_CALLSITE_CPU_EXEC_1
{guest_instr_count=4207 pc=0x8d0703f6, secondary=0x848f9818}
        RR_INPUT_4 129 from RR_CALLSITE_CPU_EXEC_2
{guest_instr_count=4234 pc=0x83e3c35e, secondary=0x82750380}
        RR_INPUT_8 3094319282304 from RR_CALLSITE_RDTSC
{guest_instr_count=4451 pc=0x82a4809a, secondary=0x844318d0}
        RR_INPUT_4 61 from RR_CALLSITE_IOPORT_READ
{guest_instr_count=4844 pc=0x82a4809a, secondary=0x00000000}
        RR_INPUT_4 61 from RR_CALLSITE_IOPORT_READ
{guest_instr_count=4859 pc=0x82a4809a, secondary=0x00002ee0}
        RR_INPUT_4 129 from RR_CALLSITE_IOPORT_READ
{guest_instr_count=5576 pc=0x82655e7e, secondary=0x82746c00}
        RR_INPUT_8 3094319823647 from RR_CALLSITE_RDTSC
{guest_instr_count=5630 pc=0x82a34c86, secondary=0x82746c00}
        RR_INTERRUPT_REQUEST_2 from RR_CALLSITE_CPU_EXEC_1

If you can clarify what you're looking I can likely give you a better answer here, though.