rr
rr copied to clipboard
Published
20 hours ago •
rr-debugger
rr-debugger
[FATAL src/ReplaySession.cc:1180:check_ticks_consistency()]
I just performed an rr recording which can't fully replay due to an assertion-failure. Filing it as a bug, at @khuey's request. CC'ing @rocallahan if he's interested to take a look, too.
System info: Lenovo ThinkPad P15 gen1 Ubuntu 22.04 Intel Core i9-10885H
rr version 5.6.0, built locally from commit 143ebdd4fc754a93f2b8f3b8b24da7f1c216578f (Nov 2 23:24:44 2022), admittedly a bit old. Maybe there's a chance this is something that's already been fixed?
Here's the assertion output:
[FATAL src/ReplaySession.cc:1180:check_ticks_consistency()]
(task 200930 (rec:194109) at time 251843)
-> Assertion `ticks_now == trace_ticks' failed to hold. ticks mismatch for 'SYSCALL: sigaltstack'; expected 1875668, got 1875673
Tail of trace dump:
{
real_time:27720.263680 global_time:251823, event:`SYSCALL: futex' (state:EXITING_SYSCALL) tid:194017, ticks:51928969
rax:0xfffffffffffffff5 rbx:0x7f626c3fafa0 rcx:0xffffffffffffffff rdx:0x3 rsi:0x89 rdi:0x7f627bb48e78 rbp:0x3 rsp:0x7f626c3fad70 r8:0x0 r9:0x7f62ffffffff r10:0x0 r11:0x246 r12:0x7f62af3d7a20 r13:0x7f62af2e3250 r14:0x7f626c3fafa0 r15:0xca rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xca fs_base:0x7f626c5fb640 gs_base:0x0
}
{
real_time:27720.269894 global_time:251824, event:`SYSCALL: epoll_wait' (state:EXITING_SYSCALL) tid:194125, ticks:9793
rax:0x1 rbx:0x0 rcx:0xffffffffffffffff rdx:0x100 rsi:0x7f6275271000 rdi:0x24 rbp:0x38 rsp:0x7f62796ffdf0 r8:0x0 r9:0x7f62879a0e48 r10:0xffffffff r11:0x246 r12:0x7f6271c5bf01 r13:0x7f628764e000 r14:0x7f62796fffa0 r15:0x7f628764e066 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xe8 fs_base:0x7f62879a2640 gs_base:0x0
{ tid:194125, addr:0x7f6275271000, length:0xc00 }
}
{
real_time:27720.270087 global_time:251825, event:`SIGNAL: SIGCHLD(async)' tid:194125, ticks:9793
rax:0x1 rbx:0x0 rcx:0xffffffffffffffff rdx:0x100 rsi:0x7f6275271000 rdi:0x24 rbp:0x38 rsp:0x7f62796ffdf0 r8:0x0 r9:0x7f62879a0e48 r10:0xffffffff r11:0x246 r12:0x7f6271c5bf01 r13:0x7f628764e000 r14:0x7f62796fffa0 r15:0x7f628764e066 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xe8 fs_base:0x7f62879a2640 gs_base:0x0 st0:0x0 st1:0x0 st2:0x0 st3:0x0 st4:0x0 st5:0x0 st6:0x3fff8000000000000000 st7:0x0 ymm0:0x0 ymm1:0x8 ymm2:0x0 ymm3:0x0 ymm4:0x0 ymm5:0x0 ymm6:0x0 ymm7:0x0 ymm8:0x0 ymm9:0x0 ymm10:0x40a0000040a0000040a0000040a00000 ymm11:0x0 ymm12:0x0 ymm13:0x57b057b057b057b0d000d000d000d00 ymm14:0x0 ymm15:0xbff0000000000000
}
{
real_time:27720.270155 global_time:251826, event:`SIGNAL_DELIVERY: SIGCHLD(async)' tid:194125, ticks:9793
rax:0x1 rbx:0x0 rcx:0xffffffffffffffff rdx:0x100 rsi:0x7f6275271000 rdi:0x24 rbp:0x38 rsp:0x7f62796ffdf0 r8:0x0 r9:0x7f62879a0e48 r10:0xffffffff r11:0x246 r12:0x7f6271c5bf01 r13:0x7f628764e000 r14:0x7f62796fffa0 r15:0x7f628764e066 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xe8 fs_base:0x7f62879a2640 gs_base:0x0
{ tid:194125, addr:0x7f62796ffdf0, length:(nil) }
}
{
real_time:27720.270314 global_time:251827, event:`SYSCALLBUF_FLUSH' tid:194125, ticks:10039
{ syscall:'recvmsg', ret:0x0, size:0xa8, desched:1 }
}
{
real_time:27720.270324 global_time:251828, event:`SYSCALL: epoll_ctl' (state:ENTERING_SYSCALL) tid:194125, ticks:10039
rax:0xffffffffffffffda rbx:0x7f62796fffa0 rcx:0xffffffffffffffff rdx:0x3f rsi:0x2 rdi:0x24 rbp:0x7f628799f7f0 rsp:0x7f62796ffdb0 r8:0x50 r9:0x7f62639e60a0 r10:0x0 r11:0x246 r12:0x7f6271c5bf20 r13:0x0 r14:0x7f62796fffa0 r15:0xe9 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xe9 fs_base:0x7f62879a2640 gs_base:0x0
}
{
real_time:27720.270340 global_time:251829, event:`SYSCALLBUF_RESET' tid:194125, ticks:10039
}
{
real_time:27720.270388 global_time:251830, event:`SYSCALL: epoll_ctl' (state:EXITING_SYSCALL) tid:194125, ticks:10039
rax:0x0 rbx:0x7f62796fffa0 rcx:0xffffffffffffffff rdx:0x3f rsi:0x2 rdi:0x24 rbp:0x7f628799f7f0 rsp:0x7f62796ffdb0 r8:0x50 r9:0x7f62639e60a0 r10:0x0 r11:0x246 r12:0x7f6271c5bf20 r13:0x0 r14:0x7f62796fffa0 r15:0xe9 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xe9 fs_base:0x7f62879a2640 gs_base:0x0
}
{
real_time:27720.270622 global_time:251831, event:`PATCH_SYSCALL' tid:194125, ticks:10125
rax:0x30 rbx:0x7f62ac2ee5e0 rcx:0xffffffffffffffff rdx:0xd0 rsi:0x2 rdi:0x3f rbp:0x7f628799fd00 rsp:0x7f628799fcc8 r8:0x7f62ac2f7378 r9:0x7f62639e60a0 r10:0x0 r11:0x246 r12:0x7f6271c5bf20 r13:0x0 r14:0x0 r15:0x7f6275296ec0 rip:0x7f62af3e0cb9 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7f62879a2640 gs_base:0x0
{ tid:194125, addr:0x7f62af88b63e, length:0x5e }
{ tid:194125, addr:0x7f62af3e0cb9, length:0x8 }
}
{
real_time:27720.270714 global_time:251832, event:`SYSCALL: shutdown' (state:ENTERING_SYSCALL) tid:194125, ticks:10132
rax:0xffffffffffffffda rbx:0x7f62796fffa0 rcx:0xffffffffffffffff rdx:0xd0 rsi:0x2 rdi:0x3f rbp:0x7f628799fd00 rsp:0x7f62796ffdb0 r8:0x7f62ac2f7378 r9:0x7f62639e60a0 r10:0x0 r11:0x246 r12:0x7f6271c5bf20 r13:0x0 r14:0x7f62796fffa0 r15:0x30 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x30 fs_base:0x7f62879a2640 gs_base:0x0
}
{
real_time:27720.270762 global_time:251833, event:`SYSCALL: shutdown' (state:EXITING_SYSCALL) tid:194125, ticks:10132
rax:0x0 rbx:0x7f62796fffa0 rcx:0xffffffffffffffff rdx:0xd0 rsi:0x2 rdi:0x3f rbp:0x7f628799fd00 rsp:0x7f62796ffdb0 r8:0x7f62ac2f7378 r9:0x7f62639e60a0 r10:0x0 r11:0x246 r12:0x7f6271c5bf20 r13:0x0 r14:0x7f62796fffa0 r15:0x30 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x30 fs_base:0x7f62879a2640 gs_base:0x0
}
{
real_time:27720.270956 global_time:251834, event:`SYSCALLBUF_FLUSH' tid:194125, ticks:12930
{ syscall:'close', ret:0x0, size:0x10 }
{ syscall:'clock_gettime', ret:0x0, size:0x20 }
{ syscall:'epoll_wait', ret:0x0, size:0x10 }
}
{
real_time:27720.270968 global_time:251835, event:`SYSCALL: epoll_wait' (state:ENTERING_SYSCALL) tid:194125, ticks:12930
rax:0xffffffffffffffda rbx:0x0 rcx:0xffffffffffffffff rdx:0x100 rsi:0x7f6275271000 rdi:0x24 rbp:0x30 rsp:0x7f62796ffdf0 r8:0x0 r9:0x7f62879a0e48 r10:0xffffffff r11:0x246 r12:0x7f6271c5bf01 r13:0x7f628764e000 r14:0x7f62796fffa0 r15:0x7f628764e05e rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xe8 fs_base:0x7f62879a2640 gs_base:0x0
}
{
real_time:27720.270978 global_time:251836, event:`SYSCALLBUF_RESET' tid:194125, ticks:12930
}
{
real_time:27720.271061 global_time:251837, event:`SYSCALL: recvmsg' (state:EXITING_SYSCALL) tid:194109, ticks:1872650
rax:0x0 rbx:0x7f6266200000 rcx:0xffffffffffffffff rdx:0x40000000 rsi:0x7f62662000c6 rdi:0x35 rbp:0x98 rsp:0x7f6264afdd80 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x7f626620011e r13:0x7f62662000c6 r14:0x7f6260ef3fd8 r15:0x7f6264afdfa0 rip:0x7000000e eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x2f fs_base:0x7f6260efa640 gs_base:0x0
{ tid:194109, addr:0x7f62662000b6, length:0x8 }
{ tid:194109, addr:0x7f62662000c6, length:0x2082 }
}
{
real_time:27720.271078 global_time:251838, event:`SYSCALLBUF_ABORT_COMMIT' tid:194109, ticks:1872650
}
{
real_time:27720.271254 global_time:251839, event:`SYSCALL: rrcall_notify_syscall_hook_exit' (state:ENTERING_SYSCALL) tid:194109, ticks:1872665
rax:0xffffffffffffffda rbx:0x0 rcx:0xffffffffffffffff rdx:0x40000000 rsi:0x7f6260ef3fd8 rdi:0x35 rbp:0x7f6260ef4030 rsp:0x7f6264afddf0 r8:0x0 r9:0x6f6d2e30336b74 r10:0x0 r11:0x246 r12:0x7f6260efa640 r13:0x2 r14:0x7f6264afdfa0 r15:0x2f rip:0x70000005 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x3ea fs_base:0x7f6260efa640 gs_base:0x0
}
{
real_time:27720.271265 global_time:251840, event:`SYSCALLBUF_RESET' tid:194109, ticks:1872665
}
{
real_time:27720.271315 global_time:251841, event:`SYSCALL: rrcall_notify_syscall_hook_exit' (state:EXITING_SYSCALL) tid:194109, ticks:1872665
rax:0x0 rbx:0x0 rcx:0xffffffffffffffff rdx:0x40000000 rsi:0x7f6260ef3fd8 rdi:0x35 rbp:0x7f6260ef4030 rsp:0x7f6264afddf0 r8:0x0 r9:0x6f6d2e30336b74 r10:0x0 r11:0x246 r12:0x7f6260efa640 r13:0x2 r14:0x7f6264afdfa0 r15:0x2f rip:0x70000005 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x2f fs_base:0x7f6260efa640 gs_base:0x0
{ tid:194109, addr:0x7f626620000d, length:0x1 }
}
{
real_time:27720.271525 global_time:251842, event:`SYSCALLBUF_FLUSH' tid:194109, ticks:1875668
{ syscall:'gettid', ret:0x2f63d, size:0x10 }
{ syscall:'gettid', ret:0x2f63d, size:0x10 }
{ syscall:'gettid', ret:0x2f63d, size:0x10 }
{ syscall:'gettid', ret:0x2f63d, size:0x10 }
{ syscall:'clock_gettime', ret:0x0, size:0x20 }
{ syscall:'gettid', ret:0x2f63d, size:0x10 }
{ syscall:'gettid', ret:0x2f63d, size:0x10 }
{ syscall:'gettid', ret:0x2f63d, size:0x10 }
{ syscall:'gettid', ret:0x2f63d, size:0x10 }
{ syscall:'gettid', ret:0x2f63d, size:0x10 }
{ syscall:'gettid', ret:0x2f63d, size:0x10 }
{ syscall:'gettid', ret:0x2f63d, size:0x10 }
{ syscall:'gettid', ret:0x2f63d, size:0x10 }
{ syscall:'gettid', ret:0x2f63d, size:0x10 }
{ syscall:'gettid', ret:0x2f63d, size:0x10 }
{ syscall:'gettid', ret:0x2f63d, size:0x10 }
{ syscall:'gettid', ret:0x2f63d, size:0x10 }
{ syscall:'gettid', ret:0x2f63d, size:0x10 }
{ syscall:'gettid', ret:0x2f63d, size:0x10, replay_assist:1 }
{ syscall:'gettid', ret:0x2f63d, size:0x10 }
{ syscall:'gettid', ret:0x2f63d, size:0x10 }
{ syscall:'gettid', ret:0x2f63d, size:0x10, replay_assist:1 }
}
{
real_time:27720.271535 global_time:251843, event:`SYSCALL: sigaltstack' (state:ENTERING_SYSCALL) tid:194109, ticks:1875668
rax:0xffffffffffffffda rbx:0x7f6264afdfa0 rcx:0xffffffffffffffff rdx:0x18 rsi:0x0 rdi:0x7f6260ef9d10 rbp:0x7f6260ef9d30 rsp:0x7f6264afddb0 r8:0x0 r9:0x2f63d r10:0x7f626743ba28 r11:0x246 r12:0x7f6260efa640 r13:0x2 r14:0x7f6264afdfa0 r15:0x83 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x83 fs_base:0x7f6260efa640 gs_base:0x0
}
{
real_time:27720.271545 global_time:251844, event:`SYSCALLBUF_RESET' tid:194109, ticks:1875668
}
=== Start rr backtrace:
rr(_ZN2rr13dump_rr_stackEv+0x32)[0x55c29aa22432]
rr(_ZN2rr9GdbServer15emergency_debugEPNS_4TaskE+0xdb)[0x55c29a81771b]
rr(+0x36d78b)[0x55c29a85178b]
rr(_ZN2rr21EmergencyDebugOstreamD1Ev+0x6b)[0x55c29a85156b]
rr(_ZN2rr13ReplaySession23check_ticks_consistencyEPNS_10ReplayTaskERKNS_5EventE+0x146)[0x55c29a9594e6]
rr(_ZN2rr13ReplaySession11replay_stepERKNS0_15StepConstraintsE+0xacf)[0x55c29a95ddbf]
rr(_ZN2rr13ReplaySession11replay_stepENS_10RunCommandE+0x47)[0x55c29a952657]
rr(+0x46d666)[0x55c29a951666]
rr(+0x46c942)[0x55c29a950942]
rr(_ZN2rr13ReplayCommand3runERSt6vectorINSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEESaIS7_EE+0x52a)[0x55c29a94fb3a]
rr(main+0x36c)[0x55c29aa42e6c]
/lib/x86_64-linux-gnu/libc.so.6(+0x29d90)[0x7f7ad7332d90]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0x80)[0x7f7ad7332e40]
rr(_start+0x25)[0x55c29a75c945]
=== End rr backtrace
Launch gdb with
gdb '-l' '10000' '-ex' 'set sysroot /' '-ex' 'target extended-remote 127.0.0.1:4322' /home/dholbert/.local/share/rr/mach-46/mmap_pack_248_firefox
Also FWIW, I captured the recording (as I usually do for pernosco) with the following command in a local pernosco-record.sh shell script:
#!/bin/bash
# From khuey 2022-05-29
# https://groups.google.com/a/mozilla.org/g/dev-platform/c/-pS3laZBDyg/m/6PAWFcvFAQAJ
unset NSS_DISABLE_HW_SHA # Unlikely to be set; but if it is, it needs unsetting.
rr record --disable-avx-512 "$@"
I was mostly concerned that this might be fallout from the recent changes to buffer sigaltstack but given the age of your rr checkout that would seem to be precluded.
