rr icon indicating copy to clipboard operation
rr copied to clipboard
verified publisher icon rr-debugger

Assertion `ticks_now == trace_ticks' failed to hold. ticks mismatch for 'SYSCALL: futex'

Open jwdev42 opened this issue 2 years ago • 3 comments

When I replay a recording of running the file manager "Thunar", rr 5.6.0 always aborts after a few seconds because an assertion failed. I retried to rerecord a few times, the assertion always fails:

[FATAL src/ReplaySession.cc:1173:check_ticks_consistency()] 
 (task 55826 (rec:71266) at time 292129)
 -> Assertion `ticks_now == trace_ticks' failed to hold. ticks mismatch for 'SYSCALL: futex'; expected 299284, got 298121
Tail of trace dump:
{
  real_time:50352.445675 global_time:292109, event:`SYSCALL: clock_gettime' (state:ENTERING_SYSCALL) tid:71218, ticks:9879590
rax:0xffffffffffffffda rbx:0x5587b3973020 rcx:0xffffffffffffffff rdx:0x1 rsi:0x7fe6e9252930 rdi:0x1 rbp:0x5587b39734a0 rsp:0x7fe6e9252918 r8:0x7fe6dc002450 r9:0x0 r10:0x5587b395fb80 r11:0x246 r12:0x5587b3976e20 r13:0x5587b396f130 r14:0x7fe6eb49c840 r15:0x7fe6dc002470 rip:0x6ffff030 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xe4 fs_base:0x7fe6e92536c0 gs_base:0x0
}
{
  real_time:50352.445692 global_time:292110, event:`SYSCALL: clock_gettime' (state:EXITING_SYSCALL) tid:71218, ticks:9879590
rax:0x0 rbx:0x5587b3973020 rcx:0xffffffffffffffff rdx:0x1 rsi:0x7fe6e9252930 rdi:0x1 rbp:0x5587b39734a0 rsp:0x7fe6e9252918 r8:0x7fe6dc002450 r9:0x0 r10:0x5587b395fb80 r11:0x246 r12:0x5587b3976e20 r13:0x5587b396f130 r14:0x7fe6eb49c840 r15:0x7fe6dc002470 rip:0x6ffff030 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xe4 fs_base:0x7fe6e92536c0 gs_base:0x0
  { tid:71218, addr:0x7fe6e9252930, length:0x10 }
}
{
  real_time:50352.445725 global_time:292111, event:`SYSCALL: poll' (state:ENTERING_SYSCALL) tid:71218, ticks:9879679
rax:0xffffffffffffffda rbx:0x7fe6e9252980 rcx:0xffffffffffffffff rdx:0x0 rsi:0x1 rdi:0x7fe6e9252980 rbp:0x1 rsp:0x7fe6e9252950 r8:0x0 r9:0x7fe6d80097d0 r10:0xc560ead9d4a185fe r11:0x246 r12:0x5587b396f130 r13:0x5587b3c5db40 r14:0x5587b39621a0 r15:0x7fe6dc002470 rip:0x7fe6eb109bcf eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x7 fs_base:0x7fe6e92536c0 gs_base:0x0
}
{
  real_time:50352.445743 global_time:292112, event:`SYSCALL: poll' (state:EXITING_SYSCALL) tid:71218, ticks:9879679
rax:0x0 rbx:0x7fe6e9252980 rcx:0xffffffffffffffff rdx:0x0 rsi:0x1 rdi:0x7fe6e9252980 rbp:0x1 rsp:0x7fe6e9252950 r8:0x0 r9:0x7fe6d80097d0 r10:0xc560ead9d4a185fe r11:0x246 r12:0x5587b396f130 r13:0x5587b3c5db40 r14:0x5587b39621a0 r15:0x7fe6dc002470 rip:0x7fe6eb109bcf eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x7 fs_base:0x7fe6e92536c0 gs_base:0x0
  { tid:71218, addr:0x7fe6e9252980, length:0x8 }
}
{
  real_time:50352.445777 global_time:292113, event:`SYSCALL: write' (state:ENTERING_SYSCALL) tid:71218, ticks:9880363
rax:0xffffffffffffffda rbx:0x5587b3970da0 rcx:0xffffffffffffffff rdx:0x8 rsi:0x7fe6e9252930 rdi:0x6 rbp:0x7fe6e9252930 rsp:0x7fe6e9252900 r8:0x0 r9:0x0 r10:0x5587b3c17650 r11:0x246 r12:0x7fe6dc02a200 r13:0xa8d r14:0x1 r15:0x7fe6dc002470 rip:0x7fe6eb105caf eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x1 fs_base:0x7fe6e92536c0 gs_base:0x0
}
{
  real_time:50352.445792 global_time:292114, event:`SYSCALL: write' (state:EXITING_SYSCALL) tid:71218, ticks:9880363
rax:0x8 rbx:0x5587b3970da0 rcx:0xffffffffffffffff rdx:0x8 rsi:0x7fe6e9252930 rdi:0x6 rbp:0x7fe6e9252930 rsp:0x7fe6e9252900 r8:0x0 r9:0x0 r10:0x5587b3c17650 r11:0x246 r12:0x7fe6dc02a200 r13:0xa8d r14:0x1 r15:0x7fe6dc002470 rip:0x7fe6eb105caf eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x1 fs_base:0x7fe6e92536c0 gs_base:0x0
}
{
  real_time:50352.445827 global_time:292115, event:`SYSCALL: poll' (state:ENTERING_SYSCALL) tid:71218, ticks:9881240
rax:0xffffffffffffffda rbx:0x7fe6eb24a4b0 rcx:0xffffffffffffffff rdx:0xffffffff rsi:0x3 rdi:0x5587b39755a0 rbp:0x5587b39734a0 rsp:0x7fe6e9252b50 r8:0x0 r9:0x0 r10:0xc560ead9d4a185fe r11:0x246 r12:0x3 r13:0x5587b39755a0 r14:0xffffffff r15:0x3 rip:0x7fe6eb109bcf eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x7 fs_base:0x7fe6e92536c0 gs_base:0x0
}
{
  real_time:50352.445846 global_time:292116, event:`SYSCALL: poll' (state:EXITING_SYSCALL) tid:71218, ticks:9881240
rax:0x1 rbx:0x7fe6eb24a4b0 rcx:0xffffffffffffffff rdx:0xffffffff rsi:0x3 rdi:0x5587b39755a0 rbp:0x5587b39734a0 rsp:0x7fe6e9252b50 r8:0x0 r9:0x0 r10:0xc560ead9d4a185fe r11:0x246 r12:0x3 r13:0x5587b39755a0 r14:0xffffffff r15:0x3 rip:0x7fe6eb109bcf eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x7 fs_base:0x7fe6e92536c0 gs_base:0x0
  { tid:71218, addr:0x5587b39755a0, length:0x18 }
}
{
  real_time:50352.445876 global_time:292117, event:`SYSCALL: read' (state:ENTERING_SYSCALL) tid:71218, ticks:9881256
rax:0xffffffffffffffda rbx:0x5587b3970da0 rcx:0xffffffffffffffff rdx:0x10 rsi:0x7fe6e9252ab0 rdi:0x6 rbp:0x7fe6e9252ab0 rsp:0x7fe6e9252a80 r8:0x0 r9:0x0 r10:0xc560ead9d4a185fe r11:0x246 r12:0x0 r13:0x7fffffff r14:0x3 r15:0x3 rip:0x7fe6eb105c0c eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x0 fs_base:0x7fe6e92536c0 gs_base:0x0
}
{
  real_time:50352.445894 global_time:292118, event:`SYSCALL: read' (state:EXITING_SYSCALL) tid:71218, ticks:9881256
rax:0x8 rbx:0x5587b3970da0 rcx:0xffffffffffffffff rdx:0x10 rsi:0x7fe6e9252ab0 rdi:0x6 rbp:0x7fe6e9252ab0 rsp:0x7fe6e9252a80 r8:0x0 r9:0x0 r10:0xc560ead9d4a185fe r11:0x246 r12:0x0 r13:0x7fffffff r14:0x3 r15:0x3 rip:0x7fe6eb105c0c eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x0 fs_base:0x7fe6e92536c0 gs_base:0x0
  { tid:71218, addr:0x7fe6e9252ab0, length:0x8 }
}
{
  real_time:50352.445927 global_time:292119, event:`SYSCALL: poll' (state:ENTERING_SYSCALL) tid:71218, ticks:9881518
rax:0xffffffffffffffda rbx:0x7fe6eb24a4b0 rcx:0xffffffffffffffff rdx:0xffffffff rsi:0x3 rdi:0x5587b39755a0 rbp:0x5587b39734a0 rsp:0x7fe6e9252b50 r8:0x0 r9:0x0 r10:0xc560ead9d4a185fe r11:0x246 r12:0x3 r13:0x5587b39755a0 r14:0xffffffff r15:0x3 rip:0x7fe6eb109bcf eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x7 fs_base:0x7fe6e92536c0 gs_base:0x0
}
{
  real_time:50352.445958 global_time:292120, event:`SYSCALL: poll' (state:EXITING_SYSCALL) tid:71266, ticks:278335
rax:0x1 rbx:0x7fe6eb24a4b0 rcx:0xffffffffffffffff rdx:0x61a8 rsi:0x1 rdi:0x7fe6d81296b0 rbp:0x7fe6d8125a50 rsp:0x7fe6e3ffd210 r8:0x0 r9:0x0 r10:0x5587b3966cf0 r11:0x246 r12:0x1 r13:0x7fe6d81296b0 r14:0x61a8 r15:0x1 rip:0x7fe6eb109bcf eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x7 fs_base:0x7fe6e3fff6c0 gs_base:0x0
  { tid:71266, addr:0x7fe6d81296b0, length:0x8 }
}
{
  real_time:50352.445990 global_time:292121, event:`SYSCALL: read' (state:ENTERING_SYSCALL) tid:71266, ticks:278349
rax:0xffffffffffffffda rbx:0x5587b4148150 rcx:0xffffffffffffffff rdx:0x10 rsi:0x7fe6e3ffd170 rdi:0x13 rbp:0x7fe6e3ffd170 rsp:0x7fe6e3ffd140 r8:0x0 r9:0x0 r10:0x5587b3966cf0 r11:0x246 r12:0x0 r13:0x7fffffff r14:0x1 r15:0x1 rip:0x7fe6eb105c0c eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x0 fs_base:0x7fe6e3fff6c0 gs_base:0x0
}
{
  real_time:50352.446020 global_time:292122, event:`SYSCALL: read' (state:EXITING_SYSCALL) tid:71266, ticks:278349
rax:0x8 rbx:0x5587b4148150 rcx:0xffffffffffffffff rdx:0x10 rsi:0x7fe6e3ffd170 rdi:0x13 rbp:0x7fe6e3ffd170 rsp:0x7fe6e3ffd140 r8:0x0 r9:0x0 r10:0x5587b3966cf0 r11:0x246 r12:0x0 r13:0x7fffffff r14:0x1 r15:0x1 rip:0x7fe6eb105c0c eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x0 fs_base:0x7fe6e3fff6c0 gs_base:0x0
  { tid:71266, addr:0x7fe6e3ffd170, length:0x8 }
}
{
  real_time:50352.446052 global_time:292123, event:`SYSCALL: write' (state:ENTERING_SYSCALL) tid:71266, ticks:278484
rax:0xffffffffffffffda rbx:0x5587b4148150 rcx:0xffffffffffffffff rdx:0x8 rsi:0x7fe6e3ffd160 rdi:0x13 rbp:0x7fe6e3ffd160 rsp:0x7fe6e3ffd130 r8:0x0 r9:0x7fe6eb31ea00 r10:0x7fe6dc0412b0 r11:0x246 r12:0x0 r13:0x0 r14:0x7fe6eb236860 r15:0x7fe6dc043250 rip:0x7fe6eb105caf eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x1 fs_base:0x7fe6e3fff6c0 gs_base:0x0
}
{
  real_time:50352.446074 global_time:292124, event:`SYSCALL: write' (state:EXITING_SYSCALL) tid:71266, ticks:278484
rax:0x8 rbx:0x5587b4148150 rcx:0xffffffffffffffff rdx:0x8 rsi:0x7fe6e3ffd160 rdi:0x13 rbp:0x7fe6e3ffd160 rsp:0x7fe6e3ffd130 r8:0x0 r9:0x7fe6eb31ea00 r10:0x7fe6dc0412b0 r11:0x246 r12:0x0 r13:0x0 r14:0x7fe6eb236860 r15:0x7fe6dc043250 rip:0x7fe6eb105caf eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x1 fs_base:0x7fe6e3fff6c0 gs_base:0x0
}
{
  real_time:50352.446103 global_time:292125, event:`SYSCALL: futex' (state:ENTERING_SYSCALL) tid:71266, ticks:278490
rax:0xffffffffffffffda rbx:0x7fe6d8129650 rcx:0xffffffffffffffff rdx:0x7fffffff rsi:0x81 rdi:0x7fe6d8125a60 rbp:0x5587b3f7c4b0 rsp:0x7fe6e3ffd188 r8:0x7fe6eb31ea00 r9:0x5587b3f7c4b0 r10:0x0 r11:0x246 r12:0x0 r13:0x0 r14:0x7fe6eb236860 r15:0x7fe6dc043250 rip:0x7fe6eb10f029 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xca fs_base:0x7fe6e3fff6c0 gs_base:0x0
}
{
  real_time:50352.446120 global_time:292126, event:`SYSCALL: futex' (state:EXITING_SYSCALL) tid:71266, ticks:278490
rax:0x0 rbx:0x7fe6d8129650 rcx:0xffffffffffffffff rdx:0x7fffffff rsi:0x81 rdi:0x7fe6d8125a60 rbp:0x5587b3f7c4b0 rsp:0x7fe6e3ffd188 r8:0x7fe6eb31ea00 r9:0x5587b3f7c4b0 r10:0x0 r11:0x246 r12:0x0 r13:0x0 r14:0x7fe6eb236860 r15:0x7fe6dc043250 rip:0x7fe6eb10f029 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xca fs_base:0x7fe6e3fff6c0 gs_base:0x0
}
{
  real_time:50352.446152 global_time:292127, event:`SYSCALL: close' (state:ENTERING_SYSCALL) tid:71266, ticks:279264
rax:0xffffffffffffffda rbx:0x7fe6e3ffd218 rcx:0xffffffffffffffff rdx:0x2 rsi:0x2 rdi:0x13 rbp:0x5587b4148150 rsp:0x7fe6e3ffd1e0 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x0 r13:0x0 r14:0x5587b3c4f0c0 r15:0x7fe6e3ffd380 rip:0x7fe6eb10636b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x3 fs_base:0x7fe6e3fff6c0 gs_base:0x0
}
{
  real_time:50352.446172 global_time:292128, event:`SYSCALL: close' (state:EXITING_SYSCALL) tid:71266, ticks:279264
rax:0x0 rbx:0x7fe6e3ffd218 rcx:0xffffffffffffffff rdx:0x2 rsi:0x2 rdi:0x13 rbp:0x5587b4148150 rsp:0x7fe6e3ffd1e0 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x0 r13:0x0 r14:0x5587b3c4f0c0 r15:0x7fe6e3ffd380 rip:0x7fe6eb10636b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x3 fs_base:0x7fe6e3fff6c0 gs_base:0x0
}
{
  real_time:50352.446239 global_time:292129, event:`SYSCALL: futex' (state:ENTERING_SYSCALL) tid:71266, ticks:299284
rax:0xffffffffffffffda rbx:0x1 rcx:0xffffffffffffffff rdx:0x1 rsi:0x81 rdi:0x5587b266b350 rbp:0x5587b41ccc40 rsp:0x7fe6e3ffea78 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x7fe6d812e5a0 r13:0x5587b266b350 r14:0x7fe6d8008160 r15:0x7fe6e3ffead0 rip:0x7fe6eb10f029 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xca fs_base:0x7fe6e3fff6c0 gs_base:0x0
}
{
  real_time:50352.446260 global_time:292130, event:`SYSCALL: futex' (state:EXITING_SYSCALL) tid:71266, ticks:299284
rax:0x1 rbx:0x1 rcx:0xffffffffffffffff rdx:0x1 rsi:0x81 rdi:0x5587b266b350 rbp:0x5587b41ccc40 rsp:0x7fe6e3ffea78 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x7fe6d812e5a0 r13:0x5587b266b350 r14:0x7fe6d8008160 r15:0x7fe6e3ffead0 rip:0x7fe6eb10f029 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xca fs_base:0x7fe6e3fff6c0 gs_base:0x0
}
=== Start rr backtrace:
rr(_ZN2rr13dump_rr_stackEv+0x41)[0x55efdb595b81]
rr(_ZN2rr9GdbServer15emergency_debugEPNS_4TaskE+0x112)[0x55efdb48cc42]
rr(+0xacda2)[0x55efdb49bda2]
rr(+0xad86b)[0x55efdb49c86b]
rr(_ZN2rr13ReplaySession23check_ticks_consistencyEPNS_10ReplayTaskERKNS_5EventE+0x1a8)[0x55efdb51b908]
rr(_ZN2rr13ReplaySession11replay_stepERKNS0_15StepConstraintsE+0x9c6)[0x55efdb528a96]
rr(_ZN2rr14ReplayTimeline19replay_step_forwardENS_10RunCommandE+0xeb)[0x55efdb541e4b]
rr(_ZN2rr9GdbServer14debug_one_stepERNS_10GdbRequestE+0x419)[0x55efdb488ed9]
rr(_ZN2rr9GdbServer12serve_replayERKNS0_15ConnectionFlagsE+0xa33)[0x55efdb48a7c3]
rr(+0x12fa04)[0x55efdb51ea04]
rr(_ZN2rr13ReplayCommand3runERSt6vectorINSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEESaIS7_EE+0x5ef)[0x55efdb51f4bf]
rr(main+0x18e)[0x55efdb436b7e]
/usr/lib64/libc.so.6(+0x2334a)[0x7f31608a734a]
/usr/lib64/libc.so.6(__libc_start_main+0x7c)[0x7f31608a73fc]
rr(_start+0x21)[0x55efdb436cc1]
=== End rr backtrace

jwdev42 avatar Mar 05 '23 12:03 jwdev42

What kernel and CPU are you using?

khuey avatar Mar 06 '23 06:03 khuey

Linux joe 6.1.12-gentoo-x86_64 #1 SMP PREEMPT_DYNAMIC Fri Feb 17 21:23:06 CET 2023 x86_64 Intel(R) Core(TM) i7-6700K CPU @ 4.00GHz GenuineIntel GNU/Linux

jwdev42 avatar Mar 07 '23 18:03 jwdev42

Same problem here, can it be due to running on Zen ? I've had issues enabling Zen workaround.

fenugrec avatar Apr 25 '23 00:04 fenugrec