search

rr-debugger / rr

Record and Replay Framework
http://rr-project.org/
Other
9.16k stars 587 forks source link

[FATAL src/ReplaySession.cc:516:cont_syscall_boundary()] #3520

Open tysmith opened 1 year ago

tysmith commented 1 year ago

This happened when replaying a recording of a 32-bit process.

I am using commit 0348e30.

[FATAL src/ReplaySession.cc:516:cont_syscall_boundary()]
 (task 498914 (rec:325249) at time 762)
 -> Assertion `false' failed to hold. Replay got unrecorded signal {signo:SIGSEGV,errno:SUCCESS,code:SEGV_ACCERR,addr:0xf62ffba4}
Tail of trace dump:
{
  real_time:2184067.762886 global_time:742, event:`SYSCALL: mmap2' (state:EXITING_SYSCALL) tid:325249, ticks:1200877
eax:0xf0dea000 ecx:0x1000 edx:0x0 ebx:0xf0dea000 esp:0x681ffda0 ebp:0x0 esi:0x22 edi:0xffffffff eip:0x70000002 eflags:0x246 xcs:0x23 xss:0x2b xds:0x2b xes:0x2b xfs:0x0 xgs:0x63 orig_eax:0xc0
  { map_file:"<ZERO>", addr:0xf0dea000, length:0x1000, prot_flags:"---p", file_offset:0x0, device:0, inode:0, data_file:"", data_offset:0x0, file_size:0x1000 }
}
{
  real_time:2184067.763099 global_time:743, event:`SYSCALLBUF_FLUSH' tid:325249, ticks:1204996
  { syscall:'openat', ret:0x3, size:0x10, desched:1 }
  { syscall:'readlinkat', ret:0x9, size:0x19 }
  { syscall:'dup', ret:0x4, size:0x10 }
  { syscall:'dup', ret:0x5, size:0x10 }
  { syscall:'clock_gettime64', ret:0x0, size:0x20 }
  { syscall:'gettid', ret:0x4f681, size:0x10 }
} 
{
  real_time:2184067.763101 global_time:744, event:`SYSCALL: mmap2' (state:ENTERING_SYSCALL) tid:325249, ticks:1204996
eax:0xffffffda ecx:0x200000 edx:0x3 ebx:0x0 esp:0x681ffda0 ebp:0x0 esi:0x22 edi:0xffffffff eip:0x70000002 eflags:0x246 xcs:0x23 xss:0x2b xds:0x2b xes:0x2b xfs:0x0 xgs:0x63 orig_eax:0xc0
}
{
  real_time:2184067.763103 global_time:745, event:`SYSCALLBUF_RESET' tid:325249, ticks:1204996
}
{
  real_time:2184067.763134 global_time:746, event:`SYSCALL: mmap2' (state:EXITING_SYSCALL) tid:325249, ticks:1204996
eax:0xf5500000 ecx:0x200000 edx:0x3 ebx:0x0 esp:0x681ffda0 ebp:0x0 esi:0x22 edi:0xffffffff eip:0x70000002 eflags:0x246 xcs:0x23 xss:0x2b xds:0x2b xes:0x2b xfs:0x0 xgs:0x63 orig_eax:0xc0
  { map_file:"<ZERO>", addr:0xf5500000, length:0x200000, prot_flags:"rw-p", file_offset:0x0, device:0, inode:0, data_file:"", data_offset:0x0, file_size:0x200000 }
}
{
  real_time:2184067.763174 global_time:747, event:`SYSCALL: munmap' (state:ENTERING_SYSCALL) tid:325249, ticks:1205020
eax:0xffffffda ecx:0x100000 edx:0x5684e599 ebx:0xf5600000 esp:0x681ffda0 ebp:0x56c62918 esi:0x100000 edi:0x56c62918 eip:0x70000002 eflags:0x246 xcs:0x23 xss:0x2b xds:0x2b xes:0x2b xfs:0x0 xgs:0x63 orig_eax:0x5b
}
{
  real_time:2184067.763206 global_time:748, event:`SYSCALL: munmap' (state:EXITING_SYSCALL) tid:325249, ticks:1205020
eax:0x0 ecx:0x100000 edx:0x5684e599 ebx:0xf5600000 esp:0x681ffda0 ebp:0x56c62918 esi:0x100000 edi:0x56c62918 eip:0x70000002 eflags:0x246 xcs:0x23 xss:0x2b xds:0x2b xes:0x2b xfs:0x0 xgs:0x63 orig_eax:0x5b
}
{
  real_time:2184067.763533 global_time:749, event:`SYSCALLBUF_FLUSH' tid:325249, ticks:1372106
  { syscall:'gettid', ret:0x4f681, size:0x10 }
}
{
  real_time:2184067.763536 global_time:750, event:`SYSCALL: mmap2' (state:ENTERING_SYSCALL) tid:325249, ticks:1372106
eax:0xffffffda ecx:0x200000 edx:0x3 ebx:0x0 esp:0x681ffda0 ebp:0x0 esi:0x22 edi:0xffffffff eip:0x70000002 eflags:0x246 xcs:0x23 xss:0x2b xds:0x2b xes:0x2b xfs:0x0 xgs:0x63 orig_eax:0xc0
}
{
  real_time:2184067.763537 global_time:751, event:`SYSCALLBUF_RESET' tid:325249, ticks:1372106
}
{
  real_time:2184067.763567 global_time:752, event:`SYSCALL: mmap2' (state:EXITING_SYSCALL) tid:325249, ticks:1372106
eax:0xf5300000 ecx:0x200000 edx:0x3 ebx:0x0 esp:0x681ffda0 ebp:0x0 esi:0x22 edi:0xffffffff eip:0x70000002 eflags:0x246 xcs:0x23 xss:0x2b xds:0x2b xes:0x2b xfs:0x0 xgs:0x63 orig_eax:0xc0
  { map_file:"<ZERO>", addr:0xf5300000, length:0x200000, prot_flags:"rw-p", file_offset:0x0, device:0, inode:0, data_file:"", data_offset:0x0, file_size:0x200000 }
}
{
  real_time:2184067.763607 global_time:753, event:`SYSCALL: munmap' (state:ENTERING_SYSCALL) tid:325249, ticks:1372130
eax:0xffffffda ecx:0x100000 edx:0x5684e599 ebx:0xf5400000 esp:0x681ffda0 ebp:0x56c62918 esi:0x100000 edi:0x56c62918 eip:0x70000002 eflags:0x246 xcs:0x23 xss:0x2b xds:0x2b xes:0x2b xfs:0x0 xgs:0x63 orig_eax:0x5b
}
{
  real_time:2184067.763638 global_time:754, event:`SYSCALL: munmap' (state:EXITING_SYSCALL) tid:325249, ticks:1372130
eax:0x0 ecx:0x100000 edx:0x5684e599 ebx:0xf5400000 esp:0x681ffda0 ebp:0x56c62918 esi:0x100000 edi:0x56c62918 eip:0x70000002 eflags:0x246 xcs:0x23 xss:0x2b xds:0x2b xes:0x2b xfs:0x0 xgs:0x63 orig_eax:0x5b
}
{
  real_time:2184067.763824 global_time:755, event:`SYSCALLBUF_FLUSH' tid:325249, ticks:1414523
  { syscall:'clock_gettime64', ret:0x0, size:0x20 }
  { syscall:'gettid', ret:0x4f681, size:0x10 }
}
{
  real_time:2184067.763827 global_time:756, event:`SYSCALL: mmap2' (state:ENTERING_SYSCALL) tid:325249, ticks:1414523
eax:0xffffffda ecx:0x7000 edx:0x3 ebx:0x0 esp:0x681ffda0 ebp:0x0 esi:0x22 edi:0xffffffff eip:0x70000002 eflags:0x246 xcs:0x23 xss:0x2b xds:0x2b xes:0x2b xfs:0x0 xgs:0x63 orig_eax:0xc0
}
{
  real_time:2184067.763828 global_time:757, event:`SYSCALLBUF_RESET' tid:325249, ticks:1414523
}
{
  real_time:2184067.763858 global_time:758, event:`SYSCALL: mmap2' (state:EXITING_SYSCALL) tid:325249, ticks:1414523
eax:0xf74f4000 ecx:0x7000 edx:0x3 ebx:0x0 esp:0x681ffda0 ebp:0x0 esi:0x22 edi:0xffffffff eip:0x70000002 eflags:0x246 xcs:0x23 xss:0x2b xds:0x2b xes:0x2b xfs:0x0 xgs:0x63 orig_eax:0xc0
  { map_file:"<ZERO>", addr:0xf74f4000, length:0x7000, prot_flags:"rw-p", file_offset:0x0, device:0, inode:0, data_file:"", data_offset:0x0, file_size:0x7000 }
}
{
  real_time:2184067.763902 global_time:759, event:`SYSCALL: mmap2' (state:ENTERING_SYSCALL) tid:325249, ticks:1414618
eax:0xffffffda ecx:0x801000 edx:0x0 ebx:0x0 esp:0x681ffda0 ebp:0x0 esi:0x20022 edi:0xffffffff eip:0x70000002 eflags:0x246 xcs:0x23 xss:0x2b xds:0x2b xes:0x2b xfs:0x0 xgs:0x63 orig_eax:0xc0
}
{
  real_time:2184067.763931 global_time:760, event:`SYSCALL: mmap2' (state:EXITING_SYSCALL) tid:325249, ticks:1414618
eax:0xf4aff000 ecx:0x801000 edx:0x0 ebx:0x0 esp:0x681ffda0 ebp:0x0 esi:0x20022 edi:0xffffffff eip:0x70000002 eflags:0x246 xcs:0x23 xss:0x2b xds:0x2b xes:0x2b xfs:0x0 xgs:0x63 orig_eax:0xc0
  { map_file:"<ZERO>", addr:0xf4aff000, length:0x801000, prot_flags:"---p", file_offset:0x0, device:0, inode:0, data_file:"", data_offset:0x0, file_size:0x801000 }
}
{
  real_time:2184067.763989 global_time:761, event:`SYSCALLBUF_FLUSH' tid:325249, ticks:1414801
  { syscall:'mprotect', ret:0x0, size:0x10 }
  { start:'0xf4b00000', size:'800000', prot:rw- }
}
{
  real_time:2184067.764145 global_time:762, event:`SYSCALL: clone' (state:ENTERING_SYSCALL) tid:325249, ticks:1414801
eax:0xffffffda ecx:0xf52ff3e4 edx:0xf52ffba8 ebx:0x3d0f00 esp:0xfff68b50 ebp:0xf7f6d000 esi:0xfff68b9c edi:0xf52ffba8 eip:0xf7b3a888 eflags:0x246 xcs:0x23 xss:0x2b xds:0x2b xes:0x2b xfs:0x0 xgs:0x63 orig_eax:0x78
  { map_file:"<ZERO>", addr:0xf48ff000, length:0x200000, prot_flags:"rwxp", file_offset:0x0, device:0, inode:0, data_file:"", data_offset:0x0, file_size:0x0 }
  { tid:325249, addr:0xf52ffba8, length:0x4 }
  { tid:325249, addr:0xfff68b9c, length:0x10 }
  { tid:325251, addr:0xfff68b9c, length:0x10 }
  { tid:325251, addr:0xf52ffba8, length:0x4 }
  { tid:325251, addr:0xf52ffba8, length:0x4 }
}
{
  real_time:2184067.764147 global_time:763, event:`SYSCALLBUF_RESET' tid:325249, ticks:1414801
}
=== Start rr backtrace:
rr(_ZN2rr9GdbServer15emergency_debugEPNS_4TaskE+0x158)[0x55d9d945f498]
rr(+0x179cb7)[0x55d9d944ccb7]
rr(+0x179f8f)[0x55d9d944cf8f]
rr(_ZN2rr13ReplaySession21cont_syscall_boundaryEPNS_10ReplayTaskERKNS0_15StepConstraintsE+0x197)[0x55d9d93bbd87]
rr(_ZN2rr13ReplaySession13enter_syscallEPNS_10ReplayTaskERKNS0_15StepConstraintsE+0xc2)[0x55d9d93bc042]
rr(_ZN2rr13ReplaySession18try_one_trace_stepEPNS_10ReplayTaskERKNS0_15StepConstraintsE+0xdb)[0x55d9d93bc77b]
rr(_ZN2rr13ReplaySession11replay_stepERKNS0_15StepConstraintsE+0x125)[0x55d9d93bdf85]
rr(_ZN2rr14ReplayTimeline19replay_step_forwardENS_10RunCommandE+0xb0)[0x55d9d93917b0]
rr(_ZN2rr9GdbServer14debug_one_stepERNS_10GdbRequestE+0x384)[0x55d9d94613d4]
rr(_ZN2rr9GdbServer12serve_replayERKNS0_15ConnectionFlagsE+0xaab)[0x55d9d9462c8b]
rr(+0xf3969)[0x55d9d93c6969]
rr(_ZN2rr13ReplayCommand3runERSt6vectorINSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEESaIS7_EE+0x5ba)[0x55d9d93c7aaa]
rr(main+0x199)[0x55d9d931d739]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf3)[0x7f3a77db9083]
rr(_start+0x2e)[0x55d9d931d9ee]
=== End rr backtrace
rocallahan commented 1 year ago

can you run with rr -F record and when you get the emergency debugger instructions, use them to connect to the crashed tracee, and get a backtrace/registers?

tysmith commented 1 year ago

I am seeing the crash with rr replay. So run with rr -F replay right, or am I confused?

rocallahan commented 1 year ago

sorry, that's right

rocallahan commented 1 year ago

might want to disasm $rip-0x40,+0x80 as well

tysmith commented 1 year ago 
(gdb) bt
#0  0xf7f55364 in pthread_create@@GLIBC_2.1 () from /lib/i386-linux-gnu/libpthread.so.0
#1  0x5681afb4 in pthread_create ()
#2  0x56a5aa57 in mozilla::TimeStamp::ComputeProcessUptime() ()
#3  0x56a590b9 in mozilla::TimeStamp::ProcessCreation() ()
#4  0x56977f37 in mozilla::baseprofiler::CorePS::CorePS() ()
#5  0x569006f9 in mozilla::baseprofiler::CorePS::Create(mozilla::baseprofiler::PSAutoLock const&)
    ()
#6  0x568c5bfa in mozilla::baseprofiler::profiler_init(void*) ()
#7  0x5687a82f in mozilla::baseprofiler::AutoProfilerInit::AutoProfilerInit() ()
#8  0x56877401 in main ()
(gdb) i r
eax            0xf62ffba0          -164627552
ecx            0xf7f6d000          -134819840
edx            0xf7f6d170          -134819472
ebx            0xf52ffba0          -181404768
esp            0xfff68be0          0xfff68be0
ebp            0xfff68c68          0xfff68c68
esi            0xf52ffb40          -181404864
edi            0xf7fd0040          -134414272
eip            0xf7f55364          0xf7f55364 <pthread_create@@GLIBC_2.1+2596>
eflags         0x210282            [ SF IF RF ID ]
cs             0x23                35
ss             0x2b                43
ds             0x2b                43
es             0x2b                43
fs             0x0                 0
gs             0x63                99
(gdb) disassemble $eip-0x40,+0x80
Dump of assembler code from 0xf7f55324 to 0xf7f553a4:
   0xf7f55324 <pthread_create@@GLIBC_2.1+2532>: sarb   $0xf0,0x1(%edx)
   0xf7f5532b <pthread_create@@GLIBC_2.1+2539>: cmpxchg %edx,0x21d0(%ecx)
   0xf7f55332 <pthread_create@@GLIBC_2.1+2546>: jne    0xf7f557a7 <pthread_create@@GLIBC_2.1+3687>
   0xf7f55338 <pthread_create@@GLIBC_2.1+2552>: mov    -0x50(%ebp),%esi
   0xf7f5533b <pthread_create@@GLIBC_2.1+2555>: mov    -0x4c(%ebp),%ecx
   0xf7f5533e <pthread_create@@GLIBC_2.1+2558>: lea    0x60(%esi),%ebx
   0xf7f55341 <pthread_create@@GLIBC_2.1+2561>: mov    %ebx,%eax
   0xf7f55343 <pthread_create@@GLIBC_2.1+2563>: mov    %ebx,-0x88(%ebp)
   0xf7f55349 <pthread_create@@GLIBC_2.1+2569>: or     $0x1,%eax
   0xf7f5534c <pthread_create@@GLIBC_2.1+2572>: mov    %eax,0x21cc(%ecx)
   0xf7f55352 <pthread_create@@GLIBC_2.1+2578>: mov    0x170(%ecx),%eax
   0xf7f55358 <pthread_create@@GLIBC_2.1+2584>: lea    0x170(%ecx),%edx
   0xf7f5535e <pthread_create@@GLIBC_2.1+2590>: mov    %edx,0x64(%esi)
   0xf7f55361 <pthread_create@@GLIBC_2.1+2593>: mov    %eax,0x60(%esi)
=> 0xf7f55364 <pthread_create@@GLIBC_2.1+2596>: mov    %ebx,0x4(%eax)
   0xf7f55367 <pthread_create@@GLIBC_2.1+2599>: mov    %ebx,0x170(%ecx)
   0xf7f5536d <pthread_create@@GLIBC_2.1+2605>: movl   $0x0,0x21cc(%ecx)
   0xf7f55377 <pthread_create@@GLIBC_2.1+2615>: xor    %esi,%esi
   0xf7f55379 <pthread_create@@GLIBC_2.1+2617>: mov    %esi,%eax
   0xf7f5537b <pthread_create@@GLIBC_2.1+2619>: xchg   %eax,0x21d0(%ecx)
   0xf7f55381 <pthread_create@@GLIBC_2.1+2625>: cmp    $0x1,%eax
   0xf7f55384 <pthread_create@@GLIBC_2.1+2628>: jg     0xf7f55783 <pthread_create@@GLIBC_2.1+3651>
   0xf7f5538a <pthread_create@@GLIBC_2.1+2634>: testb  $0x1,0x850(%edi)
   0xf7f55391 <pthread_create@@GLIBC_2.1+2641>: je     0xf7f54c86 <pthread_create@@GLIBC_2.1+838>
   0xf7f55397 <pthread_create@@GLIBC_2.1+2647>: mov    -0x84(%ebp),%ebx
   0xf7f5539d <pthread_create@@GLIBC_2.1+2653>: test   %ebx,%ebx
   0xf7f5539f <pthread_create@@GLIBC_2.1+2655>: jne    0xf7f54c86 <pthread_create@@GLIBC_2.1+838>
rocallahan commented 1 year ago

those symbols don't look right, but I dunno. Might need to pack this trace and upload it somewhere for analysis.