FATAL check_ticks_consistency() issue
Open
Nobody has claimed this yet.
- Dominant language
- C++
- Stars
- 10.7k
- Forks
- 662
- Avg merge
- 2d 3h
- Merged PRs (30d)
- 2
Description
On a Ryzen 5950 running NixOS, attempting to replay a trace:
[rr 2247369 14618][32m INFO [0m[rr 2247369 14620][disable_drivers_from_conflicts] [rr 2247369 14622]Disabling vive because we have survive[rr 2247369 14624]
[rr 2247369 23583][31mERROR [0m[rr 2247369 23585][is_json_ok] [rr 2247369 23587]Config file was loaded but JSON is not parsed![rr 2247369 23589]
[rr 2247369 23593][32m INFO [0m[rr 2247369 23595][add_from_devices] [rr 2247369 23597]Skipping disabled driver vive[rr 2247369 23599]
[rr 2247369 23603][32m INFO [0m[rr 2247369 23605][add_from_devices] [rr 2247369 23607]Skipping disabled driver vive[rr 2247369 23609]
[rr 2247369 23613][32m INFO [0m[rr 2247369 23615][add_from_devices] [rr 2247369 23617]Skipping disabled driver vive[rr 2247369 23619]
[rr 2247369 43803][31mERROR [0m[rr 2247369 43805][is_json_ok] [rr 2247369 43807]Config file was loaded but JSON is not parsed![rr 2247369 43809]
[rr 2247369 43813][36mDEBUG [0m[rr 2247369 43815][xrt_gfx_provider_create_system] [rr 2247369 43817]Doing init 0x1bc1e50[rr 2247369 43819]
[rr 2247369 43825][33m WARN [0m[rr 2247369 43827][compositor_check_and_prepare_xdev] [rr 2247369 43829]Had to fill in meshuv on xdev 'Valve Index (libsurvive)', this should be done in the driver.[rr 2247369 43831]
[rr 2247369 45827][36mDEBUG [0m[rr 2247369 45829][vk_select_physical_device] [rr 2247369 45831]Choosing Vulkan device index[rr 2247369 45833]
[rr 2247369 45837][36mDEBUG [0m[rr 2247369 45839][vk_select_physical_device] [rr 2247369 45841]Available GPUs[rr 2247369 45843]
[rr 2247369 45847][36mDEBUG [0m[rr 2247369 45849][vk_print_device_info_debug] [rr 2247369 45851]GPU index 0
name: llvmpipe (LLVM 12.0.1, 256 bits)
vendor: 0x10005
product: 0x0000
apiVersion: 1.1.168
driverVersion: 0.0.1[rr 2247369 45853]
[rr 2247369 45857][36mDEBUG [0m[rr 2247369 45859][vk_print_device_info_debug] [rr 2247369 45861]Selected GPU: 0
name: llvmpipe (LLVM 12.0.1, 256 bits)
vendor: 0x10005
product: 0x0000
apiVersion: 1.1.168
driverVersion: 0.0.1[rr 2247369 45863]
[rr 2247369 45869][31mERROR [0m[rr 2247369 45871][vk_build_device_extensions] [rr 2247369 45873]VkPhysicalDevice does not support required extension VK_KHR_external_memory_fd[rr 2247369 45875]
[rr 2247369 45879][31mERROR [0m[rr 2247369 45881][compositor_check_vulkan_caps] [rr 2247369 45883]vk_create_device: VK_ERROR_EXTENSION_NOT_PRESENT
Failed to create VkDevice.[rr 2247369 45885]
[rr 2247369 45889][31mERROR [0m[rr 2247369 45891][xrt_gfx_provider_create_system] [rr 2247369 45893]Failed to init compositor 0x1bc1e50[rr 2247369 45895]
[rr 2247369 45899][36mDEBUG [0m[rr 2247369 45901][comp_shaders_close] [rr 2247369 45903]Shaders destroyed![rr 2247369 45905]
[FATAL /build/source/src/ReplaySession.cc:1104:check_ticks_consistency()]
(task 2402419 (rec:2247369) at time 46175)
-> Assertion `ticks_now == trace_ticks' failed to hold. ticks mismatch for 'SYSCALL: poll'; expected 123103765, got 123103762
Tail of trace dump:
{
real_time:383992.337218 global_time:46155, event:`SYSCALL: poll' (state:ENTERING_SYSCALL) tid:2247369, ticks:102351062
rax:0xffffffffffffffda rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0xea60 rsi:0x4 rdi:0x1b89350 rbp:0x681ffe60 rsp:0x681ffe10 r8:0x0 r9:0xea60 r10:0x0 r11:0x246 r12:0xea60 r13:0x1b89350 r14:0x1b83800 r15:0x0 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x7 fs_base:0x7fe98aedff40 gs_base:0x0
}
{
real_time:383992.337237 global_time:46156, event:`SYSCALLBUF_RESET' tid:2247369, ticks:102351062
}
{
real_time:383992.337291 global_time:46157, event:`SYSCALL: poll' (state:EXITING_SYSCALL) tid:2247369, ticks:102351062
rax:0x1 rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0xea60 rsi:0x4 rdi:0x1b89350 rbp:0x681ffe60 rsp:0x681ffe10 r8:0x0 r9:0xea60 r10:0x0 r11:0x246 r12:0xea60 r13:0x1b89350 r14:0x1b83800 r15:0x0 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x7 fs_base:0x7fe98aedff40 gs_base:0x0
{ tid:2247369, addr:0x1b89350, length:0x20 }
}
{
real_time:383992.345732 global_time:46158, event:`SYSCALLBUF_FLUSH' tid:2247369, ticks:106501602
{ syscall:'poll', ret:0x1, size:0x30 }
# ..several thousand lines of this repeated..
{ syscall:'poll', ret:0x1, size:0x30 }
}
{
real_time:383992.379297 global_time:46175, event:`SYSCALL: poll' (state:ENTERING_SYSCALL) tid:2247369, ticks:123103765
rax:0xffffffffffffffda rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0xea60 rsi:0x4 rdi:0x1b89350 rbp:0x681ffe60 rsp:0x681ffe10 r8:0x0 r9:0xea60 r10:0x0 r11:0x246 r12:0xea60 r13:0x1b89350 r14:0x1b83800 r15:0x0 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x7 fs_base:0x7fe98aedff40 gs_base:0x0
}
{
real_time:383992.379316 global_time:46176, event:`SYSCALLBUF_RESET' tid:2247369, ticks:123103765
}
[FATAL /build/source/src/log.cc:402:emergency_debug()] (session doesn't look interactive, aborting emergency debugging)
=== Start rr backtrace:
/nix/store/siwpnh29dbm39d1w1ad4qvn9g2i2vdpb-rr-unstable-2020-10-10/bin/rr(_ZN2rr13dump_rr_stackEv+0x44)[0x6a288b]
/nix/store/siwpnh29dbm39d1w1ad4qvn9g2i2vdpb-rr-unstable-2020-10-10/bin/rr(_ZN2rr15notifying_abortEv+0x53)[0x6a2842]
/nix/store/siwpnh29dbm39d1w1ad4qvn9g2i2vdpb-rr-unstable-2020-10-10/bin/rr(_ZN2rr12FatalOstreamD1Ev+0x30)[0x501c4e]
/nix/store/siwpnh29dbm39d1w1ad4qvn9g2i2vdpb-rr-unstable-2020-10-10/bin/rr[0x501f8e]
/nix/store/siwpnh29dbm39d1w1ad4qvn9g2i2vdpb-rr-unstable-2020-10-10/bin/rr(_ZN2rr21EmergencyDebugOstreamD1Ev+0x62)[0x5021fc]
/nix/store/siwpnh29dbm39d1w1ad4qvn9g2i2vdpb-rr-unstable-2020-10-10/bin/rr(_ZN2rr13ReplaySession23check_ticks_consistencyEPNS_10ReplayTaskERKNS_5EventE+0x128)[0x5eb7e0]
/nix/store/siwpnh29dbm39d1w1ad4qvn9g2i2vdpb-rr-unstable-2020-10-10/bin/rr(_ZN2rr13ReplaySession11replay_stepERKNS0_15StepConstraintsE+0x893)[0x5ef715]
/nix/store/siwpnh29dbm39d1w1ad4qvn9g2i2vdpb-rr-unstable-2020-10-10/bin/rr(_ZN2rr14ReplayTimeline19replay_step_forwardENS_10RunCommandEl+0xe9)[0x60d1bf]
/nix/store/siwpnh29dbm39d1w1ad4qvn9g2i2vdpb-rr-unstable-2020-10-10/bin/rr(_ZN2rr9GdbServer14debug_one_stepERNS_10GdbRequestE+0x555)[0x4ceb2d]
/nix/store/siwpnh29dbm39d1w1ad4qvn9g2i2vdpb-rr-unstable-2020-10-10/bin/rr(_ZN2rr9GdbServer12serve_replayERKNS0_15ConnectionFlagsE+0x521)[0x4d0d77]
/nix/store/siwpnh29dbm39d1w1ad4qvn9g2i2vdpb-rr-unstable-2020-10-10/bin/rr[0x5e465f]
/nix/store/siwpnh29dbm39d1w1ad4qvn9g2i2vdpb-rr-unstable-2020-10-10/bin/rr(_ZN2rr13ReplayCommand3runERSt6vectorINSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEESaIS7_EE+0x417)[0x5e5147]
/nix/store/siwpnh29dbm39d1w1ad4qvn9g2i2vdpb-rr-unstable-2020-10-10/bin/rr(main+0x227)[0x6bde3f]
/nix/store/9bh3986bpragfjmr32gay8p95k91q4gy-glibc-2.33-47/lib/libc.so.6(__libc_start_main+0xd0)[0x7f8193de5780]
/nix/store/siwpnh29dbm39d1w1ad4qvn9g2i2vdpb-rr-unstable-2020-10-10/bin/rr(_start+0x2a)[0x43157a]
=== End rr backtrace
Possibly relevant: the program I'm debugging attempts to connect to a Valve Index VR headset (though I believe unsuccessfully).
Contributor guide
First steps
- Read the whole issue, then the project's contributing guide.
- Comment on the issue to say you are picking it up — it saves two people doing the same work.
- Fork the repository and make your change on a branch.
- Open a pull request that references the issue number.
Research direction
Start with src/ReplaySession.cc:1104 and check_ticks_consistency(), then review the replay trace around the SYSCALL: poll tick mismatch. The report also points to src/log.cc:402 and a Ryzen 5950 running NixOS while connecting to a Valve Index. Done should mean the supplied trace can be replayed without the fatal tick-consistency assertion.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- cpp, linux
- Domain
- devtools, operating-systems
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Stale
- Clarity
- Needs clarification
- Newbie friendliness
- 25/100