Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Replay divergence on podman run alpine date #3893

Open
lemmih opened this issue Dec 26, 2024 · 13 comments
Open

Replay divergence on podman run alpine date #3893

lemmih opened this issue Dec 26, 2024 · 13 comments

Comments

@lemmih
Copy link

lemmih commented Dec 26, 2024

Is podman known not to work with rr? If not, where should I begin to debug this issue?

Expected behavior:

$ rr record podman run alpine date
rr: Saving execution to trace directory `/home/lemmih/.local/share/rr/podman-0'.
Thu Dec 26 10:15:43 UTC 2024
$ rr replay --autopilot
Thu Dec 26 10:15:43 UTC 2024

Actual behavior:

$ rr record podman run alpine date
rr: Saving execution to trace directory `/home/lemmih/.local/share/rr/podman-0'.
Thu Dec 26 10:15:43 UTC 2024
$ rr replay --autopilot
[ERROR src/TraceStream.cc:1207:read_mapped_region()] Metadata of /var/log/journal/425d3539e5532bb43e8bcf0f649be0fa/user-1000.journal changed: replay divergence likely, but continuing anyway. inode: 111152202/111152202; mode: 33184/33184; uid: 0/0; gid: 101/101; size: 58720256/58720256; mtime: 1735208143/1735208138
[ERROR src/TraceStream.cc:1207:read_mapped_region()] Metadata of /var/log/journal/425d3539e5532bb43e8bcf0f649be0fa/system.journal changed: replay divergence likely, but continuing anyway. inode: 111152106/111152106; mode: 33184/33184; uid: 0/0; gid: 101/101; size: 41943040/41943040; mtime: 1735208153/1735208138
[FATAL src/ReplaySession.cc:1247:check_ticks_consistency()] 
 (task 149526 (rec:149216) at time 13559)
 -> Assertion `ticks_now == trace_ticks' failed to hold. ticks mismatch for 'SYSCALL: clock_gettime'; expected 571727, got 571762
Tail of trace dump:
{
  real_time:67722.948179 global_time:13539, event:`SYSCALL: getsockopt' (state:ENTERING_SYSCALL) tid:149216, ticks:561614
rax:0xffffffffffffffda rbx:0x7 rcx:0xffffffffffffffff rdx:0x1f rsi:0x1 rdi:0x7 rbp:0x648e8afbe260 rsp:0x7ffe02cd1aa8 r8:0x7ffe02cd1ab4 r9:0x648e8af9f010 r10:0x648e8af9f010 r11:0x246 r12:0x7ffe02cd1ab4 r13:0x648e8af9f010 r14:0x648e8af9f680 r15:0x7ffe02cd1b08 rip:0x76d038f275ee eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x37 fs_base:0x76d0390a57c0 gs_base:0x0
}
{
  real_time:67722.948209 global_time:13540, event:`SYSCALL: getsockopt' (state:EXITING_SYSCALL) tid:149216, ticks:561614
rax:0xffffffffffffffa4 rbx:0x7 rcx:0xffffffffffffffff rdx:0x1f rsi:0x1 rdi:0x7 rbp:0x648e8afbe260 rsp:0x7ffe02cd1aa8 r8:0x7ffe02cd1ab4 r9:0x648e8af9f010 r10:0x648e8af9f010 r11:0x246 r12:0x7ffe02cd1ab4 r13:0x648e8af9f010 r14:0x648e8af9f680 r15:0x7ffe02cd1b08 rip:0x76d038f275ee eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x37 fs_base:0x76d0390a57c0 gs_base:0x0
  { tid:149216, addr:0x7ffe02cd1ab4, length:0x4 }
  { tid:149216, addr:0x648e8af9f010, length:0x40 }
}
{
  real_time:67722.948246 global_time:13541, event:`SYSCALL: getsockopt' (state:ENTERING_SYSCALL) tid:149216, ticks:561646
rax:0xffffffffffffffda rbx:0x7 rcx:0xffffffffffffffff rdx:0x3b rsi:0x1 rdi:0x7 rbp:0x648e8afbe260 rsp:0x7ffe02cd1aa8 r8:0x7ffe02cd1ab4 r9:0x648e8af9f010 r10:0x648e8afab780 r11:0x246 r12:0x648e8afab780 r13:0x7ffe02cd1ab4 r14:0x5c r15:0x7ffe02cd1b08 rip:0x76d038f275ee eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x37 fs_base:0x76d0390a57c0 gs_base:0x0
}
{
  real_time:67722.948275 global_time:13542, event:`SYSCALL: getsockopt' (state:EXITING_SYSCALL) tid:149216, ticks:561646
rax:0x0 rbx:0x7 rcx:0xffffffffffffffff rdx:0x3b rsi:0x1 rdi:0x7 rbp:0x648e8afbe260 rsp:0x7ffe02cd1aa8 r8:0x7ffe02cd1ab4 r9:0x648e8af9f010 r10:0x648e8afab780 r11:0x246 r12:0x648e8afab780 r13:0x7ffe02cd1ab4 r14:0x5c r15:0x7ffe02cd1b08 rip:0x76d038f275ee eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x37 fs_base:0x76d0390a57c0 gs_base:0x0
  { tid:149216, addr:0x7ffe02cd1ab4, length:0x4 }
  { tid:149216, addr:0x648e8afab780, length:0x14 }
}
{
  real_time:67722.948308 global_time:13543, event:`SYSCALL: clock_gettime' (state:ENTERING_SYSCALL) tid:149216, ticks:561653
rax:0xffffffffffffffda rbx:0x7 rcx:0xffffffffffffffff rdx:0x3b rsi:0x7ffe02cd1a80 rdi:0x1 rbp:0x648e8afbe260 rsp:0x7ffe02cd1a68 r8:0x7ffe02cd1ab4 r9:0x648e8af9f010 r10:0x648e8afab780 r11:0x246 r12:0x648e8afab780 r13:0x7ffe02cd1ab4 r14:0x5 r15:0x7ffe02cd1b08 rip:0x6ffff05b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xe4 fs_base:0x76d0390a57c0 gs_base:0x0
}
{
  real_time:67722.948335 global_time:13544, event:`SYSCALL: clock_gettime' (state:EXITING_SYSCALL) tid:149216, ticks:561653
rax:0x0 rbx:0x7 rcx:0xffffffffffffffff rdx:0x3b rsi:0x7ffe02cd1a80 rdi:0x1 rbp:0x648e8afbe260 rsp:0x7ffe02cd1a68 r8:0x7ffe02cd1ab4 r9:0x648e8af9f010 r10:0x648e8afab780 r11:0x246 r12:0x648e8afab780 r13:0x7ffe02cd1ab4 r14:0x5 r15:0x7ffe02cd1b08 rip:0x6ffff05b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xe4 fs_base:0x76d0390a57c0 gs_base:0x0
  { tid:149216, addr:0x7ffe02cd1a80, length:0x10 }
}
{
  real_time:67722.948367 global_time:13545, event:`SYSCALL: fstatat' (state:ENTERING_SYSCALL) tid:149216, ticks:561664
rax:0xffffffffffffffda rbx:0x0 rcx:0xffffffffffffffff rdx:0x7ffe02cd1930 rsi:0x76d038fd844f rdi:0x7 rbp:0x7 rsp:0x7ffe02cd1918 r8:0x7ffe02cd1ab4 r9:0x648e8af9f010 r10:0x1000 r11:0x246 r12:0x0 r13:0x7ffe02cd1ab4 r14:0x5 r15:0x7ffe02cd1b08 rip:0x76d038f13d3e eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x106 fs_base:0x76d0390a57c0 gs_base:0x0
}
{
  real_time:67722.948392 global_time:13546, event:`SYSCALL: fstatat' (state:EXITING_SYSCALL) tid:149216, ticks:561664
rax:0x0 rbx:0x0 rcx:0xffffffffffffffff rdx:0x7ffe02cd1930 rsi:0x76d038fd844f rdi:0x7 rbp:0x7 rsp:0x7ffe02cd1918 r8:0x7ffe02cd1ab4 r9:0x648e8af9f010 r10:0x1000 r11:0x246 r12:0x0 r13:0x7ffe02cd1ab4 r14:0x5 r15:0x7ffe02cd1b08 rip:0x76d038f13d3e eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x106 fs_base:0x76d0390a57c0 gs_base:0x0
  { tid:149216, addr:0x7ffe02cd1930, length:0x90 }
}
{
  real_time:67722.948424 global_time:13547, event:`SYSCALL: getsockopt' (state:ENTERING_SYSCALL) tid:149216, ticks:561669
rax:0xffffffffffffffda rbx:0x0 rcx:0xffffffffffffffff rdx:0x1e rsi:0x1 rdi:0x7 rbp:0x7 rsp:0x7ffe02cd1918 r8:0x7ffe02cd1928 r9:0x648e8af9f010 r10:0x7ffe02cd192c r11:0x246 r12:0x0 r13:0x7ffe02cd1ab4 r14:0x5 r15:0x7ffe02cd1b08 rip:0x76d038f275ee eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x37 fs_base:0x76d0390a57c0 gs_base:0x0
}
{
  real_time:67722.948454 global_time:13548, event:`SYSCALL: getsockopt' (state:EXITING_SYSCALL) tid:149216, ticks:561669
rax:0x0 rbx:0x0 rcx:0xffffffffffffffff rdx:0x1e rsi:0x1 rdi:0x7 rbp:0x7 rsp:0x7ffe02cd1918 r8:0x7ffe02cd1928 r9:0x648e8af9f010 r10:0x7ffe02cd192c r11:0x246 r12:0x0 r13:0x7ffe02cd1ab4 r14:0x5 r15:0x7ffe02cd1b08 rip:0x76d038f275ee eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x37 fs_base:0x76d0390a57c0 gs_base:0x0
  { tid:149216, addr:0x7ffe02cd1928, length:0x4 }
  { tid:149216, addr:0x7ffe02cd192c, length:0x4 }
}
{
  real_time:67722.948488 global_time:13549, event:`SYSCALL: getsockname' (state:ENTERING_SYSCALL) tid:149216, ticks:561675
rax:0xffffffffffffffda rbx:0x1 rcx:0xffffffffffffffff rdx:0x7ffe02cd19fc rsi:0x7ffe02cd1a00 rdi:0x7 rbp:0x7 rsp:0x7ffe02cd19e8 r8:0x7ffe02cd1928 r9:0x648e8af9f010 r10:0x7ffe02cd192c r11:0x246 r12:0x648e8afab780 r13:0x7ffe02cd1ab4 r14:0x5 r15:0x7ffe02cd1b08 rip:0x76d038f275bb eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x33 fs_base:0x76d0390a57c0 gs_base:0x0
}
{
  real_time:67722.948518 global_time:13550, event:`SYSCALL: getsockname' (state:EXITING_SYSCALL) tid:149216, ticks:561675
rax:0x0 rbx:0x1 rcx:0xffffffffffffffff rdx:0x7ffe02cd19fc rsi:0x7ffe02cd1a00 rdi:0x7 rbp:0x7 rsp:0x7ffe02cd19e8 r8:0x7ffe02cd1928 r9:0x648e8af9f010 r10:0x7ffe02cd192c r11:0x246 r12:0x648e8afab780 r13:0x7ffe02cd1ab4 r14:0x5 r15:0x7ffe02cd1b08 rip:0x76d038f275bb eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x33 fs_base:0x76d0390a57c0 gs_base:0x0
  { tid:149216, addr:0x7ffe02cd19fc, length:0x4 }
  { tid:149216, addr:0x7ffe02cd1a00, length:0x2 }
}
{
  real_time:67722.948550 global_time:13551, event:`SYSCALL: sendmsg' (state:ENTERING_SYSCALL) tid:149216, ticks:561690
rax:0xffffffffffffffda rbx:0x76d0391ea64a rcx:0xffffffffffffffff rdx:0x4040 rsi:0x7ffe02cd1a90 rdi:0x7 rbp:0x648e8afbe260 rsp:0x7ffe02cd1a88 r8:0x7 r9:0x648e8af9f010 r10:0x7ffe02cd192c r11:0x246 r12:0x648e8afbe3f8 r13:0x0 r14:0x648e8af9f680 r15:0x7ffe02cd1b08 rip:0x76d038f27967 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x2e fs_base:0x76d0390a57c0 gs_base:0x0
}
{
  real_time:67722.948579 global_time:13552, event:`SYSCALL: sendmsg' (state:EXITING_SYSCALL) tid:149216, ticks:561690
rax:0x30 rbx:0x76d0391ea64a rcx:0xffffffffffffffff rdx:0x4040 rsi:0x7ffe02cd1a90 rdi:0x7 rbp:0x648e8afbe260 rsp:0x7ffe02cd1a88 r8:0x7 r9:0x648e8af9f010 r10:0x7ffe02cd192c r11:0x246 r12:0x648e8afbe3f8 r13:0x0 r14:0x648e8af9f680 r15:0x7ffe02cd1b08 rip:0x76d038f27967 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x2e fs_base:0x76d0390a57c0 gs_base:0x0
}
{
  real_time:67722.948619 global_time:13553, event:`SYSCALL: gettid' (state:ENTERING_SYSCALL) tid:149216, ticks:562336
rax:0xffffffffffffffda rbx:0x76d039210700 rcx:0xffffffffffffffff rdx:0xffffffff rsi:0x1 rdi:0x76d039214f90 rbp:0x1 rsp:0x7ffe02cd1c68 r8:0x0 r9:0x0 r10:0x5 r11:0x246 r12:0x76d0390a5740 r13:0x246e0 r14:0x648e8afbeac0 r15:0x246e0 rip:0x76d038f26fcb eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xba fs_base:0x76d0390a57c0 gs_base:0x0
}
{
  real_time:67722.948643 global_time:13554, event:`SYSCALL: gettid' (state:EXITING_SYSCALL) tid:149216, ticks:562336
rax:0x246e0 rbx:0x76d039210700 rcx:0xffffffffffffffff rdx:0xffffffff rsi:0x1 rdi:0x76d039214f90 rbp:0x1 rsp:0x7ffe02cd1c68 r8:0x0 r9:0x0 r10:0x5 r11:0x246 r12:0x76d0390a5740 r13:0x246e0 r14:0x648e8afbeac0 r15:0x246e0 rip:0x76d038f26fcb eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xba fs_base:0x76d0390a57c0 gs_base:0x0
}
{
  real_time:67722.948682 global_time:13555, event:`SYSCALL: futex' (state:ENTERING_SYSCALL) tid:149216, ticks:562427
rax:0xffffffffffffffda rbx:0x76d0391c6900 rcx:0xffffffffffffffff rdx:0x7fffffff rsi:0x81 rdi:0x76d039216500 rbp:0x76d039216500 rsp:0x7ffe02cd1c10 r8:0xca r9:0x7ffe02cd1bc8 r10:0x0 r11:0x246 r12:0x7ffe02cd1c28 r13:0x246e0 r14:0x648e8afbeac0 r15:0x246e0 rip:0x76d038e99f10 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xca fs_base:0x76d0390a57c0 gs_base:0x0
}
{
  real_time:67722.948707 global_time:13556, event:`SYSCALL: futex' (state:EXITING_SYSCALL) tid:149216, ticks:562427
rax:0x0 rbx:0x76d0391c6900 rcx:0xffffffffffffffff rdx:0x7fffffff rsi:0x81 rdi:0x76d039216500 rbp:0x76d039216500 rsp:0x7ffe02cd1c10 r8:0xca r9:0x7ffe02cd1bc8 r10:0x0 r11:0x246 r12:0x7ffe02cd1c28 r13:0x246e0 r14:0x648e8afbeac0 r15:0x246e0 rip:0x76d038e99f10 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xca fs_base:0x76d0390a57c0 gs_base:0x0
}
{
  real_time:67722.948747 global_time:13557, event:`SYSCALL: gettid' (state:ENTERING_SYSCALL) tid:149216, ticks:562738
rax:0xffffffffffffffda rbx:0x76d0390a5740 rcx:0xffffffffffffffff rdx:0x6c rsi:0x1 rdi:0x648e8afbe260 rbp:0x7ffe02cd1ee0 rsp:0x7ffe02cd1e28 r8:0x648e8afa7f10 r9:0x648e8af9f4b0 r10:0x76d03901ad80 r11:0x246 r12:0x76d0390a5758 r13:0x648e8afbe260 r14:0xffffffff r15:0x8 rip:0x76d038f26fcb eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xba fs_base:0x76d0390a57c0 gs_base:0x0
}
{
  real_time:67722.948771 global_time:13558, event:`SYSCALL: gettid' (state:EXITING_SYSCALL) tid:149216, ticks:562738
rax:0x246e0 rbx:0x76d0390a5740 rcx:0xffffffffffffffff rdx:0x6c rsi:0x1 rdi:0x648e8afbe260 rbp:0x7ffe02cd1ee0 rsp:0x7ffe02cd1e28 r8:0x648e8afa7f10 r9:0x648e8af9f4b0 r10:0x76d03901ad80 r11:0x246 r12:0x76d0390a5758 r13:0x648e8afbe260 r14:0xffffffff r15:0x8 rip:0x76d038f26fcb eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xba fs_base:0x76d0390a57c0 gs_base:0x0
}
{
  real_time:67722.948845 global_time:13559, event:`SYSCALL: clock_gettime' (state:ENTERING_SYSCALL) tid:149216, ticks:571727
rax:0xffffffffffffffda rbx:0x0 rcx:0xffffffffffffffff rdx:0x76d0391e90c8 rsi:0x7ffe02cd1cd0 rdi:0x1 rbp:0x648e8afbe260 rsp:0x7ffe02cd1cb8 r8:0x7ffe02cd1ef0 r9:0x0 r10:0x104 r11:0x246 r12:0x648e8afbe260 r13:0x0 r14:0x246e0 r15:0x648e8afbf4d0 rip:0x6ffff05b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xe4 fs_base:0x76d0390a57c0 gs_base:0x0
}
{
  real_time:67722.948872 global_time:13560, event:`SYSCALL: clock_gettime' (state:EXITING_SYSCALL) tid:149216, ticks:571727
rax:0x0 rbx:0x0 rcx:0xffffffffffffffff rdx:0x76d0391e90c8 rsi:0x7ffe02cd1cd0 rdi:0x1 rbp:0x648e8afbe260 rsp:0x7ffe02cd1cb8 r8:0x7ffe02cd1ef0 r9:0x0 r10:0x104 r11:0x246 r12:0x648e8afbe260 r13:0x0 r14:0x246e0 r15:0x648e8afbf4d0 rip:0x6ffff05b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xe4 fs_base:0x76d0390a57c0 gs_base:0x0
  { tid:149216, addr:0x7ffe02cd1cd0, length:0x10 }
}
=== Start rr backtrace:
rr(_ZN2rr13dump_rr_stackERNS_8ScopedFdE+0x5b)[0x5f73de36177b]
rr(_ZN2rr15emergency_debugEPNS_4TaskE+0x142)[0x5f73de231422]
rr(+0xe277a)[0x5f73de23a77a]
rr(+0xe297f)[0x5f73de23a97f]
rr(_ZN2rr13ReplaySession23check_ticks_consistencyEPNS_10ReplayTaskERKNS_5EventE+0x1ed)[0x5f73de2d1d7d]
rr(_ZN2rr13ReplaySession11replay_stepERKNS0_15StepConstraintsE+0x86f)[0x5f73de2d803f]
rr(_ZN2rr13ReplayCommand3runERSt6vectorINSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEESaIS7_EE+0x158c)[0x5f73de2caccc]
rr(main+0x1a1)[0x5f73de1ad931]
/lib/x86_64-linux-gnu/libc.so.6(+0x29d90)[0x777dee629d90]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0x80)[0x777dee629e40]
rr(_start+0x25)[0x5f73de1b03c5]
=== End rr backtrace
Launch debugger with
  'gdb' '-l' '10000' '-ex' 'set sysroot /' '-ex' 'target extended-remote 127.0.0.1:18454' '/usr/bin/crun'
@khuey
Copy link
Collaborator

khuey commented Dec 26, 2024

Can you try running RR_COPY_ALL_FILES=1 rr record ... and seeing if this still reproduces?

@lemmih
Copy link
Author

lemmih commented Dec 26, 2024

Interesting. Around 10% of the time, it works with RR_COPY_ALL_FILES=1. The rest of the time, it does print out the right date but then fails.

Success

$ RR_COPY_ALL_FILES=1 rr record podman run alpine date
rr: Saving execution to trace directory `/home/lemmih/.local/share/rr/podman-0'.
Thu Dec 26 12:36:19 UTC 2024
$ rr replay --autopilot
Thu Dec 26 12:36:19 UTC 2024

Failure 1

$ RR_COPY_ALL_FILES=1 rr record podman run alpine date
rr: Saving execution to trace directory `/home/lemmih/.local/share/rr/podman-0'.
Thu Dec 26 12:31:56 UTC 2024
$ rr replay --autopilot
Thu Dec 26 12:31:56 UTC 2024
[FATAL src/ReplaySession.cc:1247:check_ticks_consistency()] 
 (task 284212 (rec:284166) at time 17818)
 -> Assertion `ticks_now == trace_ticks' failed to hold. ticks mismatch for 'SYSCALL: getdents64'; expected 4169847, got 4170051
Tail of trace dump:
{
  real_time:75896.924438 global_time:17798, event:`SYSCALLBUF_RESET' tid:284130, ticks:46075
}
{
  real_time:75896.924463 global_time:17799, event:`SYSCALL: epoll_pwait' (state:EXITING_SYSCALL) tid:284167, ticks:3534
rax:0x0 rbx:0x266eca8 rcx:0xffffffffffffffff rdx:0x80 rsi:0x7adc143ff630 rdi:0x4 rbp:0x7adc143ffc30 rsp:0x7adc143ff5d8 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x7adc143ff660 r13:0x16 r14:0xc0000029c0 r15:0x7fff2f48b820 rip:0x474c20 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x119 fs_base:0x7adc14400640 gs_base:0x0
  { tid:284167, addr:0x7adc143ff630, length:(nil) }
}
{
  real_time:75896.924506 global_time:17800, event:`SYSCALL: futex' (state:ENTERING_SYSCALL) tid:284167, ticks:3601
rax:0xffffffffffffffda rbx:0x1 rcx:0xffffffffffffffff rdx:0x1 rsi:0x81 rdi:0xc000060948 rbp:0x7adc143ffb58 rsp:0x7adc143ffb08 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x7adc143ff660 r13:0x16 r14:0xc0000029c0 r15:0x7fff2f48b820 rip:0x474a03 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xca fs_base:0x7adc14400640 gs_base:0x0
}
{
  real_time:75896.924535 global_time:17801, event:`SYSCALL: futex' (state:EXITING_SYSCALL) tid:284167, ticks:3601
rax:0x1 rbx:0x1 rcx:0xffffffffffffffff rdx:0x1 rsi:0x81 rdi:0xc000060948 rbp:0x7adc143ffb58 rsp:0x7adc143ffb08 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x7adc143ff660 r13:0x16 r14:0xc0000029c0 r15:0x7fff2f48b820 rip:0x474a03 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xca fs_base:0x7adc14400640 gs_base:0x0
}
{
  real_time:75896.924584 global_time:17802, event:`SYSCALL: nanosleep' (state:ENTERING_SYSCALL) tid:284167, ticks:3642
rax:0xffffffffffffffda rbx:0x14 rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0x7adc143ffc20 rbp:0x7adc143ffc30 rsp:0x7adc143ffc20 r8:0x2 r9:0x0 r10:0x0 r11:0x246 r12:0x7adc143ff660 r13:0x16 r14:0xc0000029c0 r15:0x7fff2f48b820 rip:0x4743fd eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x23 fs_base:0x7adc14400640 gs_base:0x0
}
{
  real_time:75896.924616 global_time:17803, event:`SYSCALL: nanosleep' (state:EXITING_SYSCALL) tid:284130, ticks:46075
rax:0x0 rbx:0x14 rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0x71a9715ffc20 rbp:0x71a9715ffc30 rsp:0x71a9715ffc20 r8:0x0 r9:0x0 r10:0x71a9715ffbc0 r11:0x246 r12:0x71a9715ffc20 r13:0x178 r14:0xc0000029c0 r15:0x71a971824841 rip:0x4743fd eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x23 fs_base:0x71a971600640 gs_base:0x0
}
{
  real_time:75896.924648 global_time:17804, event:`SYSCALLBUF_FLUSH' tid:284130, ticks:46191
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
}
{
  real_time:75896.924654 global_time:17805, event:`SYSCALL: nanosleep' (state:ENTERING_SYSCALL) tid:284130, ticks:46191
rax:0xffffffffffffffda rbx:0x14 rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0x71a9715ffc20 rbp:0x71a9715ffc30 rsp:0x71a9715ffc20 r8:0x0 r9:0x0 r10:0x71a9715ffbc0 r11:0x246 r12:0x71a9715ffc20 r13:0x178 r14:0xc0000029c0 r15:0x71a971824841 rip:0x4743fd eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x23 fs_base:0x71a971600640 gs_base:0x0
}
{
  real_time:75896.924661 global_time:17806, event:`SYSCALLBUF_RESET' tid:284130, ticks:46191
}
{
  real_time:75896.924703 global_time:17807, event:`SYSCALL: nanosleep' (state:EXITING_SYSCALL) tid:284167, ticks:3642
rax:0x0 rbx:0x14 rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0x7adc143ffc20 rbp:0x7adc143ffc30 rsp:0x7adc143ffc20 r8:0x2 r9:0x0 r10:0x0 r11:0x246 r12:0x7adc143ff660 r13:0x16 r14:0xc0000029c0 r15:0x7fff2f48b820 rip:0x4743fd eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x23 fs_base:0x7adc14400640 gs_base:0x0
}
{
  real_time:75896.924740 global_time:17808, event:`SYSCALL: clock_gettime' (state:ENTERING_SYSCALL) tid:284167, ticks:3644
rax:0xffffffffffffffda rbx:0xc000060400 rcx:0xffffffffffffffff rdx:0x7adc143ffc40 rsi:0x7adc143ffc10 rdi:0x1 rbp:0x7adc143ffc30 rsp:0x7adc143ffc08 r8:0x2 r9:0x0 r10:0x0 r11:0x246 r12:0x7adc143ffc20 r13:0x16 r14:0xc0000029c0 r15:0x7fff2f48b820 rip:0x6ffff05b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xe4 fs_base:0x7adc14400640 gs_base:0x0
}
{
  real_time:75896.924774 global_time:17809, event:`SYSCALL: clock_gettime' (state:EXITING_SYSCALL) tid:284167, ticks:3644
rax:0x0 rbx:0xc000060400 rcx:0xffffffffffffffff rdx:0x7adc143ffc40 rsi:0x7adc143ffc10 rdi:0x1 rbp:0x7adc143ffc30 rsp:0x7adc143ffc08 r8:0x2 r9:0x0 r10:0x0 r11:0x246 r12:0x7adc143ffc20 r13:0x16 r14:0xc0000029c0 r15:0x7fff2f48b820 rip:0x6ffff05b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xe4 fs_base:0x7adc14400640 gs_base:0x0
  { tid:284167, addr:0x7adc143ffc10, length:0x10 }
}
{
  real_time:75896.924813 global_time:17810, event:`SYSCALL: clock_gettime' (state:ENTERING_SYSCALL) tid:284167, ticks:3652
rax:0xffffffffffffffda rbx:0xc000060400 rcx:0xffffffffffffffff rdx:0x7adc143ffc40 rsi:0x7adc143ffc10 rdi:0x1 rbp:0x7adc143ffc30 rsp:0x7adc143ffc08 r8:0x2 r9:0x0 r10:0x0 r11:0x246 r12:0x7adc143ffc20 r13:0x16 r14:0xc0000029c0 r15:0x7fff2f48b820 rip:0x6ffff05b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xe4 fs_base:0x7adc14400640 gs_base:0x0
}
{
  real_time:75896.924843 global_time:17811, event:`SYSCALL: clock_gettime' (state:EXITING_SYSCALL) tid:284167, ticks:3652
rax:0x0 rbx:0xc000060400 rcx:0xffffffffffffffff rdx:0x7adc143ffc40 rsi:0x7adc143ffc10 rdi:0x1 rbp:0x7adc143ffc30 rsp:0x7adc143ffc08 r8:0x2 r9:0x0 r10:0x0 r11:0x246 r12:0x7adc143ffc20 r13:0x16 r14:0xc0000029c0 r15:0x7fff2f48b820 rip:0x6ffff05b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xe4 fs_base:0x7adc14400640 gs_base:0x0
  { tid:284167, addr:0x7adc143ffc10, length:0x10 }
}
{
  real_time:75896.924878 global_time:17812, event:`SYSCALL: nanosleep' (state:ENTERING_SYSCALL) tid:284167, ticks:3686
rax:0xffffffffffffffda rbx:0x14 rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0x7adc143ffc20 rbp:0x7adc143ffc30 rsp:0x7adc143ffc20 r8:0x2 r9:0x0 r10:0x0 r11:0x246 r12:0x7adc143ffc20 r13:0x16 r14:0xc0000029c0 r15:0x7fff2f48b820 rip:0x4743fd eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x23 fs_base:0x7adc14400640 gs_base:0x0
}
{
  real_time:75896.924902 global_time:17813, event:`SYSCALL: futex' (state:EXITING_SYSCALL) tid:284168, ticks:6057
rax:0x0 rbx:0x0 rcx:0xffffffffffffffff rdx:0x0 rsi:0x80 rdi:0xc000060948 rbp:0x7adc137ffae8 rsp:0x7adc137ffaa0 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0xc00004a000 r13:0x0 r14:0xc0000031e0 r15:0x7adc14604133 rip:0x474a03 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xca fs_base:0x7adc13800640 gs_base:0x0
}
{
  real_time:75896.924940 global_time:17814, event:`SYSCALL: futex' (state:ENTERING_SYSCALL) tid:284168, ticks:6214
rax:0xffffffffffffffda rbx:0x0 rcx:0xffffffffffffffff rdx:0x0 rsi:0x80 rdi:0xc000060948 rbp:0x7adc137ffae8 rsp:0x7adc137ffaa0 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0xc00004a000 r13:0x0 r14:0xc0000031e0 r15:0x7adc14604133 rip:0x474a03 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xca fs_base:0x7adc13800640 gs_base:0x0
}
{
  real_time:75896.925020 global_time:17815, event:`SYSCALL: openat' (state:EXITING_SYSCALL) tid:284166, ticks:4169333
rax:0x3 rbx:0x7fff2f48bad0 rcx:0xffffffffffffffff rdx:0x90800 rsi:0x7adc145dd291 rdi:0xffffff9c rbp:0x7fff2f48bb10 rsp:0x7fff2f48b990 r8:0x90800 r9:0x7adc145dd291 r10:0x0 r11:0x246 r12:0x29d46c0 r13:0x7adc145dd291 r14:0x7adc145dd291 r15:0x0 rip:0x7adc3b719a1c eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x101 fs_base:0x7adc3b898840 gs_base:0x0
}
{
  real_time:75896.925060 global_time:17816, event:`SYSCALL: fstatat' (state:ENTERING_SYSCALL) tid:284166, ticks:4169337
rax:0xffffffffffffffda rbx:0x7fff2f48bad0 rcx:0xffffffffffffffff rdx:0x7fff2f48b9f0 rsi:0x7adc3b7d844f rdi:0x3 rbp:0x3 rsp:0x7fff2f48b9e8 r8:0x90800 r9:0x7adc145dd291 r10:0x1000 r11:0x246 r12:0x29d46c0 r13:0x7adc145dd291 r14:0x7adc145dd291 r15:0x0 rip:0x7adc3b713d3e eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x106 fs_base:0x7adc3b898840 gs_base:0x0
}
{
  real_time:75896.925091 global_time:17817, event:`SYSCALL: fstatat' (state:EXITING_SYSCALL) tid:284166, ticks:4169337
rax:0x0 rbx:0x7fff2f48bad0 rcx:0xffffffffffffffff rdx:0x7fff2f48b9f0 rsi:0x7adc3b7d844f rdi:0x3 rbp:0x3 rsp:0x7fff2f48b9e8 r8:0x90800 r9:0x7adc145dd291 r10:0x1000 r11:0x246 r12:0x29d46c0 r13:0x7adc145dd291 r14:0x7adc145dd291 r15:0x0 rip:0x7adc3b713d3e eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x106 fs_base:0x7adc3b898840 gs_base:0x0
  { tid:284166, addr:0x7fff2f48b9f0, length:0x90 }
}
{
  real_time:75896.925128 global_time:17818, event:`SYSCALL: getdents64' (state:ENTERING_SYSCALL) tid:284166, ticks:4169847
rax:0xffffffffffffffda rbx:0x29d4a40 rcx:0xffffffffffffffff rdx:0x8000 rsi:0x29d4a40 rdi:0x3 rbp:0x29d4a14 rsp:0x7fff2f48b988 r8:0x0 r9:0x7adc145f9720 r10:0x29d4888 r11:0x246 r12:0xffffffffffffff70 r13:0x0 r14:0x29d4a10 r15:0x0 rip:0x7adc3b6e6647 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xd9 fs_base:0x7adc3b898840 gs_base:0x0
}
{
  real_time:75896.925165 global_time:17819, event:`SYSCALL: getdents64' (state:EXITING_SYSCALL) tid:284166, ticks:4169847
rax:0x68 rbx:0x29d4a40 rcx:0xffffffffffffffff rdx:0x8000 rsi:0x29d4a40 rdi:0x3 rbp:0x29d4a14 rsp:0x7fff2f48b988 r8:0x0 r9:0x7adc145f9720 r10:0x29d4888 r11:0x246 r12:0xffffffffffffff70 r13:0x0 r14:0x29d4a10 r15:0x0 rip:0x7adc3b6e6647 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xd9 fs_base:0x7adc3b898840 gs_base:0x0
  { tid:284166, addr:0x29d4a40, length:0x68 }
}
=== Start rr backtrace:
rr(_ZN2rr13dump_rr_stackERNS_8ScopedFdE+0x5b)[0x5f79cc41866b]
rr(_ZN2rr15emergency_debugEPNS_4TaskE+0x142)[0x5f79cc2e8412]
rr(+0xe276a)[0x5f79cc2f176a]
rr(+0xe296f)[0x5f79cc2f196f]
rr(_ZN2rr13ReplaySession23check_ticks_consistencyEPNS_10ReplayTaskERKNS_5EventE+0x1ed)[0x5f79cc388dfd]
rr(_ZN2rr13ReplaySession11replay_stepERKNS0_15StepConstraintsE+0x86f)[0x5f79cc38f0bf]
rr(_ZN2rr13ReplayCommand3runERSt6vectorINSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEESaIS7_EE+0x158c)[0x5f79cc381d4c]
rr(main+0x1a1)[0x5f79cc264941]
/lib/x86_64-linux-gnu/libc.so.6(+0x29d90)[0x7a1069629d90]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0x80)[0x7a1069629e40]
rr(_start+0x25)[0x5f79cc2673d5]
=== End rr backtrace
Launch debugger with
  'gdb' '-l' '10000' '-ex' 'set sysroot /' '-ex' 'target extended-remote 127.0.0.1:22068' '/home/lemmih/.local/share/rr/podman-0/mmap_copy_1075_podman'

Failure 2

$ RR_COPY_ALL_FILES=1 rr record podman run alpine date
rr: Saving execution to trace directory `/home/lemmih/.local/share/rr/podman-0'.
Thu Dec 26 12:34:00 UTC 2024
$ rr replay --autopilot
Thu Dec 26 12:34:00 UTC 2024
[FATAL src/ReplayTask.cc:130:validate_regs()] 
 (task 284852 (rec:284807) at time 17925)
 -> Assertion `!comparison.mismatch_count' failed to hold. Mismatched registers, replay vs rec: r9 0xfa4a7a71e01afda9 != 0x1d86d428019e9044
Tail of trace dump:
{
  real_time:76020.665586 global_time:17905, event:`SYSCALL: fstatat' (state:ENTERING_SYSCALL) tid:284807, ticks:4166462
rax:0xffffffffffffffda rbx:0x7ffc36657200 rcx:0xffffffffffffffff rdx:0x7ffc36657120 rsi:0x7a477c3d844f rdi:0x3 rbp:0x3 rsp:0x7ffc36657118 r8:0x90800 r9:0x7a47545dd291 r10:0x1000 r11:0x246 r12:0x383b6c0 r13:0x7a47545dd291 r14:0x7a47545dd291 r15:0x0 rip:0x7a477c313d3e eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x106 fs_base:0x7a477c003840 gs_base:0x0
}
{
  real_time:76020.665617 global_time:17906, event:`SYSCALL: fstatat' (state:EXITING_SYSCALL) tid:284807, ticks:4166462
rax:0x0 rbx:0x7ffc36657200 rcx:0xffffffffffffffff rdx:0x7ffc36657120 rsi:0x7a477c3d844f rdi:0x3 rbp:0x3 rsp:0x7ffc36657118 r8:0x90800 r9:0x7a47545dd291 r10:0x1000 r11:0x246 r12:0x383b6c0 r13:0x7a47545dd291 r14:0x7a47545dd291 r15:0x0 rip:0x7a477c313d3e eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x106 fs_base:0x7a477c003840 gs_base:0x0
  { tid:284807, addr:0x7ffc36657120, length:0x90 }
}
{
  real_time:76020.665653 global_time:17907, event:`SYSCALL: getdents64' (state:ENTERING_SYSCALL) tid:284807, ticks:4166972
rax:0xffffffffffffffda rbx:0x383ba40 rcx:0xffffffffffffffff rdx:0x8000 rsi:0x383ba40 rdi:0x3 rbp:0x383ba14 rsp:0x7ffc366570b8 r8:0x0 r9:0x7a47545f9720 r10:0x383b888 r11:0x246 r12:0xffffffffffffff70 r13:0x0 r14:0x383ba10 r15:0x0 rip:0x7a477c2e6647 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xd9 fs_base:0x7a477c003840 gs_base:0x0
}
{
  real_time:76020.665688 global_time:17908, event:`SYSCALL: getdents64' (state:EXITING_SYSCALL) tid:284807, ticks:4166972
rax:0x68 rbx:0x383ba40 rcx:0xffffffffffffffff rdx:0x8000 rsi:0x383ba40 rdi:0x3 rbp:0x383ba14 rsp:0x7ffc366570b8 r8:0x0 r9:0x7a47545f9720 r10:0x383b888 r11:0x246 r12:0xffffffffffffff70 r13:0x0 r14:0x383ba10 r15:0x0 rip:0x7a477c2e6647 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xd9 fs_base:0x7a477c003840 gs_base:0x0
  { tid:284807, addr:0x383ba40, length:0x68 }
}
{
  real_time:76020.665726 global_time:17909, event:`SYSCALL: openat' (state:ENTERING_SYSCALL) tid:284807, ticks:4167187
rax:0xffffffffffffffda rbx:0x1 rcx:0xffffffffffffffff rdx:0x80100 rsi:0x7a47545dc758 rdi:0xffffff9c rbp:0x7a47545dc758 rsp:0x7ffc36657010 r8:0x0 r9:0x7a47545f9720 r10:0x0 r11:0x246 r12:0x80100 r13:0x3837ca0 r14:0x3833f50 r15:0x383ba53 rip:0x7a477c3145b4 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x101 fs_base:0x7a477c003840 gs_base:0x0
}
{
  real_time:76020.665749 global_time:17910, event:`SYSCALL: futex' (state:EXITING_SYSCALL) tid:284808, ticks:2634
rax:0x0 rbx:0x0 rcx:0xffffffffffffffff rdx:0x0 rsi:0x80 rdi:0x266ed98 rbp:0x7a4754fffbd0 rsp:0x7a4754fffb88 r8:0x0 r9:0x0 r10:0x7a4754fffbc0 r11:0x246 r12:0x7a4754fffbc0 r13:0x16 r14:0xc0000029c0 r15:0x7ffc36656f50 rip:0x474a03 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xca fs_base:0x7a4755000640 gs_base:0x0
}
{
  real_time:76020.665791 global_time:17911, event:`SYSCALL: clock_gettime' (state:ENTERING_SYSCALL) tid:284808, ticks:2651
rax:0xffffffffffffffda rbx:0xc000060400 rcx:0xffffffffffffffff rdx:0x7a4754fffc40 rsi:0x7a4754fffc10 rdi:0x1 rbp:0x7a4754fffc30 rsp:0x7a4754fffc08 r8:0x0 r9:0x0 r10:0x7a4754fffbc0 r11:0x246 r12:0x7a4754fffc20 r13:0x16 r14:0xc0000029c0 r15:0x7ffc36656f50 rip:0x6ffff05b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xe4 fs_base:0x7a4755000640 gs_base:0x0
}
{
  real_time:76020.665818 global_time:17912, event:`SYSCALL: clock_gettime' (state:EXITING_SYSCALL) tid:284808, ticks:2651
rax:0x0 rbx:0xc000060400 rcx:0xffffffffffffffff rdx:0x7a4754fffc40 rsi:0x7a4754fffc10 rdi:0x1 rbp:0x7a4754fffc30 rsp:0x7a4754fffc08 r8:0x0 r9:0x0 r10:0x7a4754fffbc0 r11:0x246 r12:0x7a4754fffc20 r13:0x16 r14:0xc0000029c0 r15:0x7ffc36656f50 rip:0x6ffff05b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xe4 fs_base:0x7a4755000640 gs_base:0x0
  { tid:284808, addr:0x7a4754fffc10, length:0x10 }
}
{
  real_time:76020.665850 global_time:17913, event:`SYSCALL: epoll_pwait' (state:ENTERING_SYSCALL) tid:284808, ticks:2659
rax:0xffffffffffffffda rbx:0x266eca8 rcx:0xffffffffffffffff rdx:0x80 rsi:0x7a4754fff630 rdi:0x4 rbp:0x7a4754fffc30 rsp:0x7a4754fff5d8 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x7a4754fff660 r13:0x16 r14:0xc0000029c0 r15:0x7ffc36656f50 rip:0x474c20 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x119 fs_base:0x7a4755000640 gs_base:0x0
}
{
  real_time:76020.665906 global_time:17914, event:`SYSCALL: openat' (state:EXITING_SYSCALL) tid:284807, ticks:4167187
rax:0x8 rbx:0x1 rcx:0xffffffffffffffff rdx:0x80100 rsi:0x7a47545dc758 rdi:0xffffff9c rbp:0x7a47545dc758 rsp:0x7ffc36657010 r8:0x0 r9:0x7a47545f9720 r10:0x0 r11:0x246 r12:0x80100 r13:0x3837ca0 r14:0x3833f50 r15:0x383ba53 rip:0x7a477c3145b4 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x101 fs_base:0x7a477c003840 gs_base:0x0
}
{
  real_time:76020.665949 global_time:17915, event:`SYSCALL: read' (state:ENTERING_SYSCALL) tid:284807, ticks:4167197
rax:0xffffffffffffffda rbx:0x8 rcx:0xffffffffffffffff rdx:0x26 rsi:0x7ffc36657090 rdi:0x8 rbp:0x0 rsp:0x7ffc36657010 r8:0x0 r9:0x7a47545f9720 r10:0x0 r11:0x246 r12:0x0 r13:0x7ffc36657040 r14:0x26 r15:0x7ffc36657090 rip:0x7a477c31481c eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x0 fs_base:0x7a477c003840 gs_base:0x0
}
{
  real_time:76020.665981 global_time:17916, event:`SYSCALL: read' (state:EXITING_SYSCALL) tid:284807, ticks:4167197
rax:0x21 rbx:0x8 rcx:0xffffffffffffffff rdx:0x26 rsi:0x7ffc36657090 rdi:0x8 rbp:0x0 rsp:0x7ffc36657010 r8:0x0 r9:0x7a47545f9720 r10:0x0 r11:0x246 r12:0x0 r13:0x7ffc36657040 r14:0x26 r15:0x7ffc36657090 rip:0x7a477c31481c eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x0 fs_base:0x7a477c003840 gs_base:0x0
  { tid:284807, addr:0x7ffc36657090, length:0x21 }
}
{
  real_time:76020.666015 global_time:17917, event:`SYSCALL: read' (state:ENTERING_SYSCALL) tid:284807, ticks:4167206
rax:0xffffffffffffffda rbx:0x8 rcx:0xffffffffffffffff rdx:0x5 rsi:0x7ffc366570b1 rdi:0x8 rbp:0x0 rsp:0x7ffc36657010 r8:0x0 r9:0x7a47545f9720 r10:0x0 r11:0x246 r12:0x21 r13:0x7ffc36657040 r14:0x5 r15:0x7ffc366570b1 rip:0x7a477c31481c eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x0 fs_base:0x7a477c003840 gs_base:0x0
}
{
  real_time:76020.666043 global_time:17918, event:`SYSCALL: read' (state:EXITING_SYSCALL) tid:284807, ticks:4167206
rax:0x0 rbx:0x8 rcx:0xffffffffffffffff rdx:0x5 rsi:0x7ffc366570b1 rdi:0x8 rbp:0x0 rsp:0x7ffc36657010 r8:0x0 r9:0x7a47545f9720 r10:0x0 r11:0x246 r12:0x21 r13:0x7ffc36657040 r14:0x5 r15:0x7ffc366570b1 rip:0x7a477c31481c eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x0 fs_base:0x7a477c003840 gs_base:0x0
  { tid:284807, addr:0x7ffc366570b1, length:(nil) }
}
{
  real_time:76020.666077 global_time:17919, event:`SYSCALL: close' (state:ENTERING_SYSCALL) tid:284807, ticks:4167338
rax:0xffffffffffffffda rbx:0x7a477c0037b0 rcx:0xffffffffffffffff rdx:0x0 rsi:0xf rdi:0x8 rbp:0x8 rsp:0x7ffc36657040 r8:0x0 r9:0x0 r10:0x3837a08 r11:0x246 r12:0x0 r13:0x7ffc36657090 r14:0x3833f50 r15:0x383ba53 rip:0x7a477c314f8b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x3 fs_base:0x7a477c003840 gs_base:0x0
}
{
  real_time:76020.666104 global_time:17920, event:`SYSCALL: close' (state:EXITING_SYSCALL) tid:284807, ticks:4167338
rax:0x0 rbx:0x7a477c0037b0 rcx:0xffffffffffffffff rdx:0x0 rsi:0xf rdi:0x8 rbp:0x8 rsp:0x7ffc36657040 r8:0x0 r9:0x0 r10:0x3837a08 r11:0x246 r12:0x0 r13:0x7ffc36657090 r14:0x3833f50 r15:0x383ba53 rip:0x7a477c314f8b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x3 fs_base:0x7a477c003840 gs_base:0x0
}
{
  real_time:76020.666137 global_time:17921, event:`SYSCALL: openat' (state:ENTERING_SYSCALL) tid:284807, ticks:4167568
rax:0xffffffffffffffda rbx:0x7ffc36657180 rcx:0xffffffffffffffff rdx:0x90800 rsi:0x3837ca0 rdi:0xffffff9c rbp:0x383b6c0 rsp:0x7ffc36657040 r8:0x90800 r9:0x3837ca0 r10:0x0 r11:0x246 r12:0x1 r13:0x3837ca0 r14:0x3833f50 r15:0x383ba53 rip:0x7a477c319a1c eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x101 fs_base:0x7a477c003840 gs_base:0x0
}
{
  real_time:76020.666195 global_time:17922, event:`SYSCALL: openat' (state:EXITING_SYSCALL) tid:284807, ticks:4167568
rax:0x8 rbx:0x7ffc36657180 rcx:0xffffffffffffffff rdx:0x90800 rsi:0x3837ca0 rdi:0xffffff9c rbp:0x383b6c0 rsp:0x7ffc36657040 r8:0x90800 r9:0x3837ca0 r10:0x0 r11:0x246 r12:0x1 r13:0x3837ca0 r14:0x3833f50 r15:0x383ba53 rip:0x7a477c319a1c eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x101 fs_base:0x7a477c003840 gs_base:0x0
}
{
  real_time:76020.666229 global_time:17923, event:`SYSCALL: fstatat' (state:ENTERING_SYSCALL) tid:284807, ticks:4167572
rax:0xffffffffffffffda rbx:0x7ffc36657180 rcx:0xffffffffffffffff rdx:0x7ffc366570a0 rsi:0x7a477c3d844f rdi:0x8 rbp:0x8 rsp:0x7ffc36657098 r8:0x90800 r9:0x3837ca0 r10:0x1000 r11:0x246 r12:0x1 r13:0x3837ca0 r14:0x3833f50 r15:0x383ba53 rip:0x7a477c313d3e eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x106 fs_base:0x7a477c003840 gs_base:0x0
}
{
  real_time:76020.666259 global_time:17924, event:`SYSCALL: fstatat' (state:EXITING_SYSCALL) tid:284807, ticks:4167572
rax:0x0 rbx:0x7ffc36657180 rcx:0xffffffffffffffff rdx:0x7ffc366570a0 rsi:0x7a477c3d844f rdi:0x8 rbp:0x8 rsp:0x7ffc36657098 r8:0x90800 r9:0x3837ca0 r10:0x1000 r11:0x246 r12:0x1 r13:0x3837ca0 r14:0x3833f50 r15:0x383ba53 rip:0x7a477c313d3e eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x106 fs_base:0x7a477c003840 gs_base:0x0
  { tid:284807, addr:0x7ffc366570a0, length:0x90 }
}
{
  real_time:76020.666303 global_time:17925, event:`SYSCALL: getdents64' (state:ENTERING_SYSCALL) tid:284807, ticks:4169280
rax:0xffffffffffffffda rbx:0x3843a80 rcx:0xffffffffffffffff rdx:0x8000 rsi:0x3843a80 rdi:0x8 rbp:0x3843a54 rsp:0x7ffc36657038 r8:0x0 r9:0x1d86d428019e9044 r10:0x384ba90 r11:0x246 r12:0xffffffffffffff70 r13:0x0 r14:0x3843a50 r15:0x383ba53 rip:0x7a477c2e6647 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xd9 fs_base:0x7a477c003840 gs_base:0x0
}
{
  real_time:76020.666373 global_time:17926, event:`SYSCALL: getdents64' (state:EXITING_SYSCALL) tid:284807, ticks:4169280
rax:0x11b8 rbx:0x3843a80 rcx:0xffffffffffffffff rdx:0x8000 rsi:0x3843a80 rdi:0x8 rbp:0x3843a54 rsp:0x7ffc36657038 r8:0x0 r9:0x1d86d428019e9044 r10:0x384ba90 r11:0x246 r12:0xffffffffffffff70 r13:0x0 r14:0x3843a50 r15:0x383ba53 rip:0x7a477c2e6647 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xd9 fs_base:0x7a477c003840 gs_base:0x0
  { tid:284807, addr:0x3843a80, length:0x11b8 }
}
=== Start rr backtrace:
rr(_ZN2rr13dump_rr_stackERNS_8ScopedFdE+0x5b)[0x5cf53b3fc66b]
rr(_ZN2rr15emergency_debugEPNS_4TaskE+0x142)[0x5cf53b2cc412]
rr(+0xe276a)[0x5cf53b2d576a]
rr(+0xe296f)[0x5cf53b2d596f]
rr(+0xe29a9)[0x5cf53b2d59a9]
rr(_ZN2rr10ReplayTask13validate_regsEj+0x1ed)[0x5cf53b37ec1d]
rr(_ZN2rr13ReplaySession13enter_syscallEPNS_10ReplayTaskERKNS0_15StepConstraintsE+0x3da)[0x5cf53b36916a]
rr(_ZN2rr13ReplaySession18try_one_trace_stepEPNS_10ReplayTaskERKNS0_15StepConstraintsE+0xe3)[0x5cf53b370b23]
rr(_ZN2rr13ReplaySession11replay_stepERKNS0_15StepConstraintsE+0x21d)[0x5cf53b372a6d]
rr(_ZN2rr13ReplayCommand3runERSt6vectorINSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEESaIS7_EE+0x158c)[0x5cf53b365d4c]
rr(main+0x1a1)[0x5cf53b248941]
/lib/x86_64-linux-gnu/libc.so.6(+0x29d90)[0x718c36229d90]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0x80)[0x718c36229e40]
rr(_start+0x25)[0x5cf53b24b3d5]
=== End rr backtrace
Launch debugger with
  'gdb' '-l' '10000' '-ex' 'set sysroot /' '-ex' 'target extended-remote 127.0.0.1:22708' '/home/lemmih/.local/share/rr/podman-4/mmap_copy_1076_podman'

@khuey
Copy link
Collaborator

khuey commented Dec 26, 2024

Interesting. What distro and version of podman are you testing with? When I try running it locally rr just makes podman crash.

@lemmih
Copy link
Author

lemmih commented Dec 26, 2024

POP_os and podman version 3.4.4.

$ uname -a
Linux pop-os 6.8.0-76060800daily20240311-generic #202403110203~1710198088~22.04~1a3dbc7 SMP PREEMPT_DYNAMIC Mon M x86_64 x86_64 x86_64 GNU/Linux

@rocallahan
Copy link
Collaborator

I get

roc@localhost:~/rr/rr/src/test$ rr record podman run registry.fedoraproject.org/fedora:latest echo hello
rr: Saving execution to trace directory `/home/roc/.local/share/rr/podman-0'.
[FATAL src/record_syscall.cc:6677:rec_process_syscall_arch()] 
 (task 1932911 (rec:1932911) at time 8360)
 -> Assertion `t->regs().syscall_result_signed() == -syscall_state.expect_errno' failed to hold. Expected ENOSYS for 'open_tree' but got result 3 (errno errno(-3)); execution of syscall unsupported by rr

@rocallahan
Copy link
Collaborator

After supporting a couple of mount-related syscalls:

roc@localhost:~/rr/rr/src/test$ rr record podman run registry.fedoraproject.org/fedora:latest echo hello
rr: Saving execution to trace directory `/home/roc/.local/share/rr/podman-3'.
[FATAL src/AutoRemoteSyscalls.cc:630:child_recvmsg()] 
 (task 1974290 (rec:1974290) at time 11092)
 -> Assertion `!(msghdr.msg_flags & MSG_CTRUNC)' failed to hold. Control message was truncated; error in receiving fd in AutoRemoteSyscalls::child_recvmsg(). msghdr.msg_flags: 0x8

@rocallahan
Copy link
Collaborator

OK, that error is due to SELinux blocking receiving of file descriptors over IPC. With rr record podman run --security-opt label=disable registry.fedoraproject.org/fedora:latest echo hello, recording works.

@rocallahan
Copy link
Collaborator

And rr replay -a works reliably so that doesn't help me reproduce this bug at all :-).

What is the failing task with tid 149526 in your example? Run rr ps to get the process list.

@lemmih
Copy link
Author

lemmih commented Jan 1, 2025

I'll try installing a newer version of podman.

@lemmih
Copy link
Author

lemmih commented Jan 1, 2025

And rr replay -a works reliably so that doesn't help me reproduce this bug at all :-).

What is the failing task with tid 149526 in your example? Run rr ps to get the process list.

$ rr replay -a
[FATAL src/ReplaySession.cc:1247:check_ticks_consistency()] 
 (task 6906 (rec:6858) at time 11889)
 -> Assertion `ticks_now == trace_ticks' failed to hold. ticks mismatch for 'SYSCALL: clock_gettime'; expected 565727, got 565758
Tail of trace dump:
[SNIP]
=== Start rr backtrace:
rr(_ZN2rr13dump_rr_stackERNS_8ScopedFdE+0x5b)[0x5f68e6e6766b]
rr(_ZN2rr15emergency_debugEPNS_4TaskE+0x142)[0x5f68e6d37412]
rr(+0xe276a)[0x5f68e6d4076a]
rr(+0xe296f)[0x5f68e6d4096f]
rr(_ZN2rr13ReplaySession23check_ticks_consistencyEPNS_10ReplayTaskERKNS_5EventE+0x1ed)[0x5f68e6dd7dfd]
rr(_ZN2rr13ReplaySession11replay_stepERKNS0_15StepConstraintsE+0x86f)[0x5f68e6dde0bf]
rr(_ZN2rr13ReplayCommand3runERSt6vectorINSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEESaIS7_EE+0x158c)[0x5f68e6dd0d4c]
rr(main+0x1a1)[0x5f68e6cb3941]
/lib/x86_64-linux-gnu/libc.so.6(+0x29d90)[0x7f6502029d90]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0x80)[0x7f6502029e40]
rr(_start+0x25)[0x5f68e6cb63d5]
=== End rr backtrace
Launch debugger with
  'gdb' '-l' '10000' '-ex' 'set sysroot /' '-ex' 'target extended-remote 127.0.0.1:6906' '/' 

$ rr ps
PID	PPID	EXIT	CMD
6823	--	0	podman run --security-opt label=disable registry.fedoraproject.org/fedora:latest echo hello
6828	6823	0	/usr/bin/conmon --version
6830	6823	0	/usr/lib/cni/bridge
6834	6823	0	/usr/lib/cni/portmap
6838	6823	0	/usr/lib/cni/firewall
6842	6823	0	/usr/lib/cni/tuning
6847	6823	0	/usr/bin/slirp4netns --help
6849	6823	-9	/usr/bin/slirp4netns --disable-host-loopback --mtu=65520 --enable-sandbox --enable-seccomp -c -e 3 -r 4 --netns-type=path /run/user/1000/netns/cni-10739a2e-203b-46b4-54df-a740f31a85e7 tap0
6851	6849	0	(forked without exec)
6852	6823	0	/usr/bin/conmon --api-version 1 -c 176d2aed9c22b1384d5e1a65ce6f7cf944b12161a21a5bd92065472caaa4073e -u 176d2aed9c22b1384d5e1a65ce6f7cf944b12161a21a5bd92065472caaa4073e -r /usr/bin/crun -b /home/lemmih/.local/share/containers/storage/overlay-containers/176d2aed9c22b1384d5e1a65ce6f7cf944b12161a21a5bd92065472caaa4073e/userdata -p /run/user/1000/containers/overlay-containers/176d2aed9c22b1384d5e1a65ce6f7cf944b12161a21a5bd92065472caaa4073e/userdata/pidfile -n kind_almeida --exit-dir /run/user/1000/libpod/tmp/exits --full-attach -s -l journald --log-level warning --runtime-arg --log-format=json --runtime-arg --log --runtime-arg=/run/user/1000/containers/overlay-containers/176d2aed9c22b1384d5e1a65ce6f7cf944b12161a21a5bd92065472caaa4073e/userdata/oci-log --conmon-pidfile /run/user/1000/containers/overlay-containers/176d2aed9c22b1384d5e1a65ce6f7cf944b12161a21a5bd92065472caaa4073e/userdata/conmon.pid --exit-command /usr/bin/podman --exit-command-arg --root --exit-command-arg /home/lemmih/.local/share/containers/storage --exit-command-arg --runroot --exit-command-arg /run/user/1000/containers --exit-command-arg --log-level --exit-command-arg warning --exit-command-arg --cgroup-manager --exit-command-arg systemd --exit-command-arg --tmpdir --exit-command-arg /run/user/1000/libpod/tmp --exit-command-arg --runtime --exit-command-arg crun --exit-command-arg --storage-driver --exit-command-arg overlay --exit-command-arg --events-backend --exit-command-arg journald --exit-command-arg container --exit-command-arg cleanup --exit-command-arg 176d2aed9c22b1384d5e1a65ce6f7cf944b12161a21a5bd92065472caaa4073e
6856	6852	-9	(forked without exec)
6858	6856	0	/usr/bin/crun --systemd-cgroup --log-format=json --log /run/user/1000/containers/overlay-containers/176d2aed9c22b1384d5e1a65ce6f7cf944b12161a21a5bd92065472caaa4073e/userdata/oci-log create --bundle /home/lemmih/.local/share/containers/storage/overlay-containers/176d2aed9c22b1384d5e1a65ce6f7cf944b12161a21a5bd92065472caaa4073e/userdata --pid-file /run/user/1000/containers/overlay-containers/176d2aed9c22b1384d5e1a65ce6f7cf944b12161a21a5bd92065472caaa4073e/userdata/pidfile 176d2aed9c22b1384d5e1a65ce6f7cf944b12161a21a5bd92065472caaa4073e
6860 (1)	6858	0	echo hello
6861	6823	0	/usr/bin/crun start 176d2aed9c22b1384d5e1a65ce6f7cf944b12161a21a5bd92065472caaa4073e
6862	6856	-9	/usr/bin/podman --root /home/lemmih/.local/share/containers/storage --runroot /run/user/1000/containers --log-level warning --cgroup-manager systemd --tmpdir /run/user/1000/libpod/tmp --runtime crun --storage-driver overlay --events-backend journald container cleanup 176d2aed9c22b1384d5e1a65ce6f7cf944b12161a21a5bd92065472caaa4073e

@rocallahan
Copy link
Collaborator

Thanks! Can you following the "emergency debugger" instructions that are printed when rr dies, and in gdb run bt? You may need to install debuginfo packages to get useful results.

@lemmih
Copy link
Author

lemmih commented Jan 1, 2025 •
edited
Loading

Thanks! Can you following the "emergency debugger" instructions that are printed when rr dies, and in gdb run bt? You may need to install debuginfo packages to get useful results.

I'll try.

Btw, I cannot replicate the issue on my Intel machine (i7-8705G). It only happens on my AMD box (3950X).

@rocallahan
Copy link
Collaborator

If those machines are running the exact same software configuration then it sounds like the problem is probably something to do with Zen.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@rocallahan @khuey @lemmih