rr icon indicating copy to clipboard operation
rr copied to clipboard

Published 20 hours ago • verified publisher icon rr-debugger

Recording diverges when recorded normally but succeeds with `rr record -n`

Open cbiesinger opened this issue 1 year ago • 0 comments

I am running bazel test --run_under=rr for a test in Selenium.

Exact commandline: PATH=$HOME/chromium/src/out/Release:$PATH bazel test //java/test/org/openqa/selenium/federatedcredentialmanagement/... --run_under="$HOME/bin/runrr -n"

runrr is: exec rr record --disable-avx-512 "$@"

rr version 6424ba4c3a0d03cf2a76a4be37d6d891fd0a1d0b

Failed trace on pernosco: Your submission 'chromium/user/[email protected]/1686668658/DVzkKS-UTWo' could not be processed.

Error message:

SLF4J: See https://www.slf4j.org/codes.html#noProviders for further details.
[ERROR src/ReplaySession.cc:793:guard_overshoot()] Replay diverged;
target registers mismatched:
[FATAL src/ReplaySession.cc:797:guard_overshoot()]
 (task 2438558 (rec:2435488) at time 242698)
 -> Assertion `false' failed to hold. overshot target ticks=381545307 by 73
Tail of trace dump:
{
  real_time:516922.671879 global_time:242678, event:`SYSCALL: munmap'
(state:ENTERING_SYSCALL) tid:2435659, ticks:347828546
rax:0xffffffffffffffda rbx:0x7f1d371fffa0 rcx:0xffffffffffffffff
rdx:0x7f1d2d7c0000 rsi:0x40000 rdi:0x7f1d2d7c0000 rbp:0x7ffef4d0a900
rsp:0x7f1d371ffdb0 r8:0x3ffffffff r9:0x20b00240c000 r10:0x55d8d186c000
r11:0x246 r12:0x20b00254c140 r13:0x7f1d2d7c0000 r14:0x7f1d371fffa0
r15:0xb rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0
fs:0x0 gs:0x0 orig_rax:0xb fs_base:0x7f1d38f9a100 gs_base:0x0
}
{
  real_time:516922.671882 global_time:242679, event:`SYSCALLBUF_RESET'
tid:2435659, ticks:347828546
}
{
  real_time:516922.672015 global_time:242680, event:`SYSCALL: munmap'
(state:EXITING_SYSCALL) tid:2435659, ticks:347828546
rax:0x0 rbx:0x7f1d371fffa0 rcx:0xffffffffffffffff rdx:0x7f1d2d7c0000
rsi:0x40000 rdi:0x7f1d2d7c0000 rbp:0x7ffef4d0a900 rsp:0x7f1d371ffdb0
r8:0x3ffffffff r9:0x20b00240c000 r10:0x55d8d186c000 r11:0x246
r12:0x20b00254c140 r13:0x7f1d2d7c0000 r14:0x7f1d371fffa0 r15:0xb
rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0
gs:0x0 orig_rax:0xb fs_base:0x7f1d38f9a100 gs_base:0x0
}
{
  real_time:516922.672095 global_time:242681, event:`SYSCALLBUF_FLUSH'
tid:2435659, ticks:347841947
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
}
{
  real_time:516922.672099 global_time:242682, event:`SYSCALL: munmap'
(state:ENTERING_SYSCALL) tid:2435659, ticks:347841947
rax:0xffffffffffffffda rbx:0x7f1d371fffa0 rcx:0xffffffffffffffff
rdx:0x7f1d2da50000 rsi:0x4000 rdi:0x7f1d2da50000 rbp:0x7ffef4d0aa90
rsp:0x7f1d371ffdb0 r8:0x3ffffffff r9:0x20b00980c000 r10:0x55d8d186c000
r11:0x246 r12:0x20b002550ac0 r13:0x7f1d2da50000 r14:0x7f1d371fffa0
r15:0xb rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0
fs:0x0 gs:0x0 orig_rax:0xb fs_base:0x7f1d38f9a100 gs_base:0x0
}
{
  real_time:516922.672102 global_time:242683, event:`SYSCALLBUF_RESET'
tid:2435659, ticks:347841947
}
{
  real_time:516922.672172 global_time:242684, event:`SYSCALL: munmap'
(state:EXITING_SYSCALL) tid:2435659, ticks:347841947
rax:0x0 rbx:0x7f1d371fffa0 rcx:0xffffffffffffffff rdx:0x7f1d2da50000
rsi:0x4000 rdi:0x7f1d2da50000 rbp:0x7ffef4d0aa90 rsp:0x7f1d371ffdb0
r8:0x3ffffffff r9:0x20b00980c000 r10:0x55d8d186c000 r11:0x246
r12:0x20b002550ac0 r13:0x7f1d2da50000 r14:0x7f1d371fffa0 r15:0xb
rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0
gs:0x0 orig_rax:0xb fs_base:0x7f1d38f9a100 gs_base:0x0
}
{
  real_time:516922.672253 global_time:242685, event:`SYSCALLBUF_FLUSH'
tid:2435659, ticks:347857017
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
  { syscall:'poll', ret:0x0, size:0x28 }
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
}
{
  real_time:516922.672257 global_time:242686, event:`SYSCALL: munmap'
(state:ENTERING_SYSCALL) tid:2435659, ticks:347857017
rax:0xffffffffffffffda rbx:0x7f1d371fffa0 rcx:0xffffffffffffffff
rdx:0x7f1d350c0000 rsi:0x20000 rdi:0x7f1d350c0000 rbp:0x7ffef4d0a900
rsp:0x7f1d371ffdb0 r8:0x3ffffffff r9:0x20b00980c000 r10:0x55d8d186c000
r11:0x246 r12:0x20b00254c4c0 r13:0x7f1d350c0000 r14:0x7f1d371fffa0
r15:0xb rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0
fs:0x0 gs:0x0 orig_rax:0xb fs_base:0x7f1d38f9a100 gs_base:0x0
}
{
  real_time:516922.672260 global_time:242687, event:`SYSCALLBUF_RESET'
tid:2435659, ticks:347857017
}
{
  real_time:516922.672354 global_time:242688, event:`SYSCALL: munmap'
(state:EXITING_SYSCALL) tid:2435659, ticks:347857017
rax:0x0 rbx:0x7f1d371fffa0 rcx:0xffffffffffffffff rdx:0x7f1d350c0000
rsi:0x20000 rdi:0x7f1d350c0000 rbp:0x7ffef4d0a900 rsp:0x7f1d371ffdb0
r8:0x3ffffffff r9:0x20b00980c000 r10:0x55d8d186c000 r11:0x246
r12:0x20b00254c4c0 r13:0x7f1d350c0000 r14:0x7f1d371fffa0 r15:0xb
rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0
gs:0x0 orig_rax:0xb fs_base:0x7f1d38f9a100 gs_base:0x0
}
{
  real_time:516922.672567 global_time:242689, event:`SYSCALLBUF_FLUSH'
tid:2435659, ticks:347865906
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
}
{
  real_time:516922.672571 global_time:242690, event:`SCHED'
tid:2435659, ticks:347865906
rax:0x55d8cae9f3b0 rbx:0x20b000034000 rcx:0x7f1d3a2b1a80 rdx:0x1
rsi:0x1 rdi:0x20b000034000 rbp:0x0 rsp:0x7ffef4d0b9e8 r8:0x3ffffffff
r9:0x20b00000c000 r10:0x55d8d186c000 r11:0x0 r12:0x7ffef4d0ba10
r13:0x7ffef4d0ba08 r14:0x7fffffff r15:0x20b00002cbe0
rip:0x7f1d3aea52b4 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0
gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7f1d38f9a100 gs_base:0x0
}
{
  real_time:516922.672574 global_time:242691, event:`SYSCALLBUF_RESET'
tid:2435659, ticks:347865906
}
{
  real_time:516922.672582 global_time:242692, event:`SYSCALL: futex'
(state:EXITING_SYSCALL) tid:2435645, ticks:16572947
rax:0x0 rbx:0x7f48915fcfa0 rcx:0xffffffffffffffff rdx:0x0 rsi:0x89
rdi:0x7f4891dfc170 rbp:0x0 rsp:0x7f48915fcd70 r8:0x0 r9:0xffffffff
r10:0x7f4891dfc050 r11:0x246 r12:0x0 r13:0x7f4891dfc120
r14:0x7f48915fcfa0 r15:0xca rip:0x70000002 eflags:0x246 cs:0x33
ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xca
fs_base:0x7f4891dfd6c0 gs_base:0x0
}
{
  real_time:516922.672697 global_time:242693, event:`SYSCALLBUF_FLUSH'
tid:2435645, ticks:16586217
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
  { syscall:'futex', ret:0x0, size:0x14 }
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
}
{
  real_time:516922.672701 global_time:242694, event:`SYSCALL: futex'
(state:ENTERING_SYSCALL) tid:2435645, ticks:16586217
rax:0xffffffffffffffda rbx:0x7f48915fcfa0 rcx:0xffffffffffffffff
rdx:0x0 rsi:0x89 rdi:0x7f4891dfc170 rbp:0x0 rsp:0x7f48915fcd70 r8:0x0
r9:0xffffffff r10:0x7f4891dfc050 r11:0x246 r12:0x0 r13:0x7f4891dfc120
r14:0x7f48915fcfa0 r15:0xca rip:0x70000002 eflags:0x246 cs:0x33
ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xca
fs_base:0x7f4891dfd6c0 gs_base:0x0
}
{
  real_time:516922.672705 global_time:242695, event:`SYSCALLBUF_RESET'
tid:2435645, ticks:16586217
}
{
  real_time:516922.672863 global_time:242696, event:`SYSCALL: futex'
(state:EXITING_SYSCALL) tid:2435488, ticks:381007346
rax:0x0 rbx:0x0 rcx:0xffffffffffffffff rdx:0x0 rsi:0x89
rdi:0x7f10240c547c rbp:0x0 rsp:0x7f1005ffea30 r8:0x0 r9:0xffffffff
r10:0x7f1005ffeb40 r11:0x246 r12:0x1 r13:0x7f10240c5428
r14:0x7f10240c547c r15:0x0 rip:0x7f102b874d36 eflags:0x246 cs:0x33
ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xca
fs_base:0x7f1005fff6c0 gs_base:0x0
}
{
  real_time:516922.674784 global_time:242697, event:`SYSCALLBUF_FLUSH'
tid:2435488, ticks:381545307
  { syscall:'futex', ret:0x0, size:0x14 }
  { syscall:'gettimeofday', ret:0x0, size:0x20 }
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
  { syscall:'gettid', ret:0x2529a0, size:0x10 }
}
{
  real_time:516922.674792 global_time:242698, event:`SCHED'
tid:2435488, ticks:381545307
rax:0x0 rbx:0x7f10240292f0 rcx:0x0 rdx:0x1 rsi:0x0 rdi:0x7f102b6cbfe0
rbp:0x7f1005ffdfc0 rsp:0x7f1005ffdf60 r8:0x0 r9:0x0 r10:0xc6d00b
r11:0x39 r12:0x7f0fe8320cd0 r13:0x7f1005ffdf60 r14:0x7fe8 r15:0x0
rip:0x7f102a843369 eflags:0x206 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0
gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7f1005fff6c0 gs_base:0x0
}
{
  real_time:516922.674796 global_time:242699, event:`SYSCALLBUF_RESET'
tid:2435488, ticks:381545307
}
=== Start rr backtrace:
rr(_ZN2rr9GdbServer15emergency_debugEPNS_4TaskE+0x1c6)[0x561b6128a756]
rr(_ZN2rr21EmergencyDebugOstreamD1Ev+0x1ed)[0x561b6129a16d]
rr(+0x14edfb)[0x561b61337dfb]
rr(_ZN2rr13ReplaySession20emulate_async_signalEPNS_10ReplayTaskERKNS0_15StepConstraintsElNS_15remote_code_ptrE+0x1a05)[0x561b613370b5]
rr(_ZN2rr13ReplaySession18try_one_trace_stepEPNS_10ReplayTaskERKNS0_15StepConstraintsE+0x23b)[0x561b6133bb9b]
rr(_ZN2rr13ReplaySession11replay_stepERKNS0_15StepConstraintsE+0x25e)[0x561b6133d0ae]
rr(_ZN2rr13ReplayCommand3runERSt6vectorINSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEESaIS7_EE+0x1198)[0x561b6132f0d8]
rr(main+0x527)[0x561b612a23b7]
/lib/x86_64-linux-gnu/libc.so.6(+0x2718a)[0x7f5505d6718a]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0x85)[0x7f5505d67245]
rr(_start+0x21)[0x561b61222171]
=== End rr backtrace
Launch gdb with
  gdb '-l' '10000' '-ex' 'set sysroot /' '-ex' 'target extended-remote
[127.0.0.1:13726](http://127.0.0.1:13726/)'
/usr/local/google/home/cbiesinger/.local/share/rr/FederatedCredentialManagementTest-0/mmap_pack_212_java

cbiesinger avatar Jun 13 '23 15:06 cbiesinger