rr-debugger / rr-debugger/rr

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

Open
#3,536 0 comments 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

Dominant language
C++
Stars
10.7k
Forks
662
Avg merge
2d 3h
Merged PRs (30d)
2

Description

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/cbiesinger@chromium.org/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

Contributor guide

Open the contributing guide

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Start by reproducing the supplied Selenium/Bazel command with and without rr record -n, then inspect the divergence reported from src/ReplaySession.cc:793 and the trace tail around global time 242698. Done means determining why normal recording diverges while -n succeeds and resolving that behavior for the supplied trace.

Written by the indexing model from the issue text.

Assessment

Tech stack
cpp
Domain
devtools, reverse-engineering
Issue type
Bug
Difficulty
5/5
Estimated time
Over a week
Activity status
Stale
Clarity
Needs clarification
Newbie friendliness
25/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.