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.
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
Replaying a trace that calls mmap causes an assertion failure #3635
Comments
You might want to try with the latest rr version. Try passing -F to rr and then when rr is paused for the emergency debugger, check if the referenced proc file ( Also does recording and replaying simple stuff (e.g. |
It worked fine with |
This file seems to be malformed, gunzip barfs. |
Oops, looks like it's actually XZ encrypted not gzip, I must have used the wrong flag:
The part that actually mattered was the VSCode config which apparently did not get included. The tarball just includes the source, |
Works for me with gdb.
|
Can you run |
Sure, I’ll ping you when I’ve done that |
@rocallahan When I unpack the tarball into a directory and run the following in that directory: $ dlv debug --backend rr . # Start debugging with delve
(dlv) break main.main # Put a breakpoint at the beginning of main
(dlv) continue # Start the program
(dlv) next # Step (repeat 5 more times) It crashes:[FATAL src/AutoRemoteSyscalls.cc:734:check_syscall_result()] (task 238653 (rec:238612) at time 455) -> Assertion `false' failed to hold. Syscall openat failed with errno EACCES opening /proc/238613/fd/21 Tail of trace dump: { real_time:24338.509139 global_time:435, event:`SYSCALL: fcntl' (state:EXITING_SYSCALL) tid:238612, ticks:1534 rax:0x8002 rbx:0x4 rcx:0xffffffffffffffff rdx:0x0 rsi:0x3 rdi:0x4 rbp:0xc00006e898 rsp:0xc00006e858 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0xc00006e930 r13:0xc000048400 r14:0xc0000061a0 r15:0x2031 rip:0x4034ee eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x48 fs_base:0xc000048490 gs_base:0x0 } { real_time:24338.509162 global_time:436, event:`SYSCALL: fcntl' (state:ENTERING_SYSCALL) tid:238612, ticks:1576 rax:0xffffffffffffffda rbx:0x4 rcx:0xffffffffffffffff rdx:0x8802 rsi:0x4 rdi:0x4 rbp:0xc00006e898 rsp:0xc00006e858 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0xc00006e930 r13:0xc000048400 r14:0xc0000061a0 r15:0x2031 rip:0x4034ee eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x48 fs_base:0xc000048490 gs_base:0x0 } { real_time:24338.509182 global_time:437, event:`SYSCALL: fcntl' (state:EXITING_SYSCALL) tid:238612, ticks:1576 rax:0x0 rbx:0x4 rcx:0xffffffffffffffff rdx:0x8802 rsi:0x4 rdi:0x4 rbp:0xc00006e898 rsp:0xc00006e858 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0xc00006e930 r13:0xc000048400 r14:0xc0000061a0 r15:0x2031 rip:0x4034ee eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x48 fs_base:0xc000048490 gs_base:0x0 } { real_time:24338.509204 global_time:438, event:`SYSCALL: epoll_create1' (state:ENTERING_SYSCALL) tid:238612, ticks:1629 rax:0xffffffffffffffda rbx:0x80000 rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0x80000 rbp:0xc00006e7d0 rsp:0xc00006e790 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0xc00006e8e0 r13:0xc000048400 r14:0xc0000061a0 r15:0x2031 rip:0x4034ee eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x123 fs_base:0xc000048490 gs_base:0x0 } { real_time:24338.509222 global_time:439, event:`SYSCALL: epoll_create1' (state:EXITING_SYSCALL) tid:238612, ticks:1629 rax:0x5 rbx:0x80000 rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0x80000 rbp:0xc00006e7d0 rsp:0xc00006e790 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0xc00006e8e0 r13:0xc000048400 r14:0xc0000061a0 r15:0x2031 rip:0x4034ee eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x123 fs_base:0xc000048490 gs_base:0x0 } { real_time:24338.509244 global_time:440, event:`SYSCALL: pipe2' (state:ENTERING_SYSCALL) tid:238612, ticks:1632 rax:0xffffffffffffffda rbx:0x0 rcx:0xffffffffffffffff rdx:0x0 rsi:0x80800 rdi:0xc00006e7c0 rbp:0xc00006e7d0 rsp:0xc00006e7b0 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0xc00006e8e0 r13:0xc000048400 r14:0xc0000061a0 r15:0x2031 rip:0x464770 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x125 fs_base:0xc000048490 gs_base:0x0 } { real_time:24338.509265 global_time:441, event:`SYSCALL: pipe2' (state:EXITING_SYSCALL) tid:238612, ticks:1632 rax:0x0 rbx:0x0 rcx:0xffffffffffffffff rdx:0x0 rsi:0x80800 rdi:0xc00006e7c0 rbp:0xc00006e7d0 rsp:0xc00006e7b0 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0xc00006e8e0 r13:0xc000048400 r14:0xc0000061a0 r15:0x2031 rip:0x464770 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x125 fs_base:0xc000048490 gs_base:0x0 { tid:238612, addr:0xc00006e7c0, length:0x8 } } { real_time:24338.509287 global_time:442, event:`SYSCALL: epoll_ctl' (state:ENTERING_SYSCALL) tid:238612, ticks:1634 rax:0xffffffffffffffda rbx:0x5 rcx:0xffffffffffffffff rdx:0x6 rsi:0x1 rdi:0x5 rbp:0xc00006e7d0 rsp:0xc00006e788 r8:0x0 r9:0x0 r10:0xc00006e814 r11:0x246 r12:0xc00006e8e0 r13:0xc000048400 r14:0xc0000061a0 r15:0x2031 rip:0x4034ee eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xe9 fs_base:0xc000048490 gs_base:0x0 } { real_time:24338.509304 global_time:443, event:`SYSCALL: epoll_ctl' (state:EXITING_SYSCALL) tid:238612, ticks:1634 rax:0x0 rbx:0x5 rcx:0xffffffffffffffff rdx:0x6 rsi:0x1 rdi:0x5 rbp:0xc00006e7d0 rsp:0xc00006e788 r8:0x0 r9:0x0 r10:0xc00006e814 r11:0x246 r12:0xc00006e8e0 r13:0xc000048400 r14:0xc0000061a0 r15:0x2031 rip:0x4034ee eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xe9 fs_base:0xc000048490 gs_base:0x0 } { real_time:24338.509330 global_time:444, event:`SYSCALL: epoll_ctl' (state:ENTERING_SYSCALL) tid:238612, ticks:1742 rax:0xffffffffffffffda rbx:0x5 rcx:0xffffffffffffffff rdx:0x4 rsi:0x1 rdi:0x5 rbp:0xc00006e8e0 rsp:0xc00006e898 r8:0x0 r9:0x0 r10:0xc00006e90c r11:0x246 r12:0x0 r13:0xc000048400 r14:0xc0000061a0 r15:0x2031 rip:0x4034ee eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xe9 fs_base:0xc000048490 gs_base:0x0 } { real_time:24338.509344 global_time:445, event:`SYSCALL: epoll_ctl' (state:EXITING_SYSCALL) tid:238612, ticks:1742 rax:0xffffffffffffffff rbx:0x5 rcx:0xffffffffffffffff rdx:0x4 rsi:0x1 rdi:0x5 rbp:0xc00006e8e0 rsp:0xc00006e898 r8:0x0 r9:0x0 r10:0xc00006e90c r11:0x246 r12:0x0 r13:0xc000048400 r14:0xc0000061a0 r15:0x2031 rip:0x4034ee eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xe9 fs_base:0xc000048490 gs_base:0x0 } { real_time:24338.509366 global_time:446, event:`SYSCALL: fcntl' (state:ENTERING_SYSCALL) tid:238612, ticks:1802 rax:0xffffffffffffffda rbx:0x4 rcx:0xffffffffffffffff rdx:0x0 rsi:0x3 rdi:0x4 rbp:0xc00006e898 rsp:0xc00006e858 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x0 r13:0xc000048400 r14:0xc0000061a0 r15:0x2031 rip:0x4034ee eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x48 fs_base:0xc000048490 gs_base:0x0 } { real_time:24338.509381 global_time:447, event:`SYSCALL: fcntl' (state:EXITING_SYSCALL) tid:238612, ticks:1802 rax:0x8802 rbx:0x4 rcx:0xffffffffffffffff rdx:0x0 rsi:0x3 rdi:0x4 rbp:0xc00006e898 rsp:0xc00006e858 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x0 r13:0xc000048400 r14:0xc0000061a0 r15:0x2031 rip:0x4034ee eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x48 fs_base:0xc000048490 gs_base:0x0 } { real_time:24338.509401 global_time:448, event:`SYSCALL: fcntl' (state:ENTERING_SYSCALL) tid:238612, ticks:1844 rax:0xffffffffffffffda rbx:0x4 rcx:0xffffffffffffffff rdx:0x8002 rsi:0x4 rdi:0x4 rbp:0xc00006e898 rsp:0xc00006e858 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x0 r13:0xc000048400 r14:0xc0000061a0 r15:0x2031 rip:0x4034ee eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x48 fs_base:0xc000048490 gs_base:0x0 } { real_time:24338.509416 global_time:449, event:`SYSCALL: fcntl' (state:EXITING_SYSCALL) tid:238612, ticks:1844 rax:0x0 rbx:0x4 rcx:0xffffffffffffffff rdx:0x8002 rsi:0x4 rdi:0x4 rbp:0xc00006e898 rsp:0xc00006e858 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x0 r13:0xc000048400 r14:0xc0000061a0 r15:0x2031 rip:0x4034ee eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x48 fs_base:0xc000048490 gs_base:0x0 } { real_time:24338.509440 global_time:450, event:`SYSCALL: ftruncate' (state:ENTERING_SYSCALL) tid:238612, ticks:2035 rax:0xffffffffffffffda rbx:0x4 rcx:0xffffffffffffffff rdx:0x0 rsi:0x1000 rdi:0x4 rbp:0xc00006eab0 rsp:0xc00006ea70 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0xc00006ecf8 r13:0xc000048400 r14:0xc0000061a0 r15:0x2031 rip:0x4034ee eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x4d fs_base:0xc000048490 gs_base:0x0 } { real_time:24338.509461 global_time:451, event:`SYSCALL: ftruncate' (state:EXITING_SYSCALL) tid:238612, ticks:2035 rax:0x0 rbx:0x4 rcx:0xffffffffffffffff rdx:0x0 rsi:0x1000 rdi:0x4 rbp:0xc00006eab0 rsp:0xc00006ea70 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0xc00006ecf8 r13:0xc000048400 r14:0xc0000061a0 r15:0x2031 rip:0x4034ee eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x4d fs_base:0xc000048490 gs_base:0x0 } { real_time:24338.509485 global_time:452, event:`SYSCALL: fstat' (state:ENTERING_SYSCALL) tid:238612, ticks:2184 rax:0xffffffffffffffda rbx:0x4 rcx:0xffffffffffffffff rdx:0x0 rsi:0xc000074448 rdi:0x4 rbp:0xc00006e8c0 rsp:0xc00006e880 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0xc00006eb10 r13:0xc000048400 r14:0xc0000061a0 r15:0x2031 rip:0x4034ee eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x5 fs_base:0xc000048490 gs_base:0x0 } { real_time:24338.509501 global_time:453, event:`SYSCALL: fstat' (state:EXITING_SYSCALL) tid:238612, ticks:2184 rax:0x0 rbx:0x4 rcx:0xffffffffffffffff rdx:0x0 rsi:0xc000074448 rdi:0x4 rbp:0xc00006e8c0 rsp:0xc00006e880 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0xc00006eb10 r13:0xc000048400 r14:0xc0000061a0 r15:0x2031 rip:0x4034ee eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x5 fs_base:0xc000048490 gs_base:0x0 { tid:238612, addr:0xc000074448, length:0x90 } } { real_time:24338.509527 global_time:454, event:`SYSCALL: mmap' (state:ENTERING_SYSCALL) tid:238612, ticks:2298 rax:0xffffffffffffffda rbx:0x0 rcx:0xffffffffffffffff rdx:0x3 rsi:0x1000 rdi:0x0 rbp:0xc00006e718 rsp:0xc00006e6d8 r8:0x4 r9:0x0 r10:0x1 r11:0x246 r12:0xc00006e8b0 r13:0xc000048400 r14:0xc0000061a0 r15:0x2031 rip:0x4034ee eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x9 fs_base:0xc000048490 gs_base:0x0 } { real_time:24338.509666 global_time:455, event:`SYSCALL: mmap' (state:EXITING_SYSCALL) tid:238612, ticks:2298 rax:0x7fbe47229000 rbx:0x0 rcx:0xffffffffffffffff rdx:0x3 rsi:0x1000 rdi:0x0 rbp:0xc00006e718 rsp:0xc00006e6d8 r8:0x4 r9:0x0 r10:0x1 r11:0x246 r12:0xc00006e8b0 r13:0xc000048400 r14:0xc0000061a0 r15:0x2031 rip:0x4034ee eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x9 fs_base:0xc000048490 gs_base:0x0 { map_file:"/tmp/911353397", addr:0x7fbe47229000, length:0x1000, prot_flags:"rw-s", file_offset:0x0, device:2051, inode:280516, data_file:"", data_offset:0x0, file_size:0x1000 } { tid:238612, addr:0x7fbe47229000, length:0x1000, holes:[(nil)-0x1000] } } { real_time:24338.509708 global_time:456, event:`SYSCALL: munmap' (state:ENTERING_SYSCALL) tid:238612, ticks:2819 rax:0xffffffffffffffda rbx:0x7fbe47229000 rcx:0xffffffffffffffff rdx:0x0 rsi:0x1000 rdi:0x7fbe47229000 rbp:0xc00006e9d8 rsp:0xc00006e998 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0xc00006eb58 r13:0xffffffffffffffff r14:0xc0000061a0 r15:0x2031 rip:0x4034ee eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xb fs_base:0xc000048490 gs_base:0x0 } [FATAL src/log.cc:444:emergency_debug()] (session doesn't look interactive, aborting emergency debugging) === Start rr backtrace: rr(_ZN2rr13dump_rr_stackEv+0x41)[0x55eca82f3b61] rr(_ZN2rr15notifying_abortEv+0xe)[0x55eca82f509e] rr(+0x1bdf0f)[0x55eca830af0f] rr(+0xabe43)[0x55eca81f8e43] rr(+0xac8cb)[0x55eca81f98cb] rr(_ZN2rr18AutoRemoteSyscalls20check_syscall_resultElib+0x186)[0x55eca81a8896] rr(_ZN2rr18AutoRemoteSyscalls18finish_direct_mmapENS_10remote_ptrIvEEmiiRKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEEilR4statRS8_+0x1fd)[0x55eca81a98bd] rr(+0x139e71)[0x55eca8286e71] rr(+0x13b377)[0x55eca8288377] rr(+0x13fe37)[0x55eca828ce37] rr(_ZN2rr13ReplaySession28setup_replay_one_trace_frameEPNS_10ReplayTaskE+0x7b7)[0x55eca8284367] rr(_ZN2rr13ReplaySession11replay_stepERKNS0_15StepConstraintsE+0x9c)[0x55eca828454c] rr(_ZN2rr14ReplayTimeline19replay_step_forwardENS_10RunCommandE+0xc4)[0x55eca829dd94] rr(_ZN2rr9GdbServer14debug_one_stepERNS_10GdbRequestE+0x3c5)[0x55eca81e5e25] rr(_ZN2rr9GdbServer12serve_replayERKNS0_15ConnectionFlagsE+0x69b)[0x55eca81e726b] rr(+0x12c61a)[0x55eca827961a] rr(_ZN2rr13ReplayCommand3runERSt6vectorINSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEESaIS7_EE+0x63f)[0x55eca827ae6f] rr(main+0x1ad)[0x55eca819383d] /usr/lib64/libc.so.6(+0x238ca)[0x7f7d448ee8ca] /usr/lib64/libc.so.6(__libc_start_main+0x85)[0x7f7d448ee985] rr(_start+0x21)[0x55eca8193a11] === End rr backtrace > main.main() ./main.go:14 (PC: 0x4874fa) Command failed: EOF I get the same result if I: $ go build .
$ rr record foo
$ dlv replay /home/firelizzard/.local/share/rr/foo-0
(dlv) break main.main
(dlv) continue
(dlv) next # 6 times |
@rocallahan Did you step past the mmap syscall? When I execute the same steps as you, using the same gcflags, rr record, and rr replay (gdb), I still get the assertion fail if I step twice: log$ go build -gcflags '-N -l' $ rr record foo rr: Saving execution to trace directory `/home/firelizzard/.local/share/rr/foo-1'. $ rr replay GNU gdb (Gentoo 13.2 vanilla) 13.2 Copyright (C) 2023 Free Software Foundation, Inc. License GPLv3+: GNU GPL version 3 or later This is free software: you are free to change and redistribute it. There is NO WARRANTY, to the extent permitted by law. Type "show copying" and "show warranty" for details. This GDB was configured as "x86_64-pc-linux-gnu". Type "show configuration" for configuration details. For bug reporting instructions, please see: . Find the GDB manual and other documentation resources online at: . |
That's no problem here.
My guess is |
Do you have |
I can run it normally and debug with dlv with no problem. It's only when I debug with RR that things get weird. I did run into some weird issues a while back after a system update. I was using a package that called mlock. It worked perfectly fine for more than a year and then started throwing a fit after the update (go-delve/delve#3490). I think the update must have made some kind of security change. I'm wondering if something similar is happening here. Maybe Gentoo or the Kernel now defaults to some more secure profile that causes problems. I'm not sure how to debug that though, since I hardly even know what could have changed. |
* Closes #3464. Sets the supply to 1M ACME by default to prevent negative supply issues. * Refactors the snapshot indexer to allow mmap to be disabled due to [a bug in rr](rr-debugger/rr#3635). * Panics if batch commit fails, since that is a fatal error and if returned it can be masked. Changelog: fix
I've worked around the mmap issue by using build flags (basically ifdef) to switch out with an implementation that does not use mmap. But now I'm seeing another seemingly similar error on an unrelated project. rr backtrace
|
Does this unrelated project use ptrace? |
Nope, it's just a basic Go project (here). I'm definitely not doing anything with ptrace, and I'm fairly certain neither of the libraries I'm calling do. I suppose it's possible the Go runtime is. I can debug fine, but RR fails when it tries to replay a nil pointer exception. But when I make a trivial program with a nil pointer dereference ( I found this post that talks about profs having non-standard permissions, and references
But when I look for RR processes:
And run
I run into the same issue with procfs with the trivial program (permission denied on the procfs 'symlinks') but it replays fine, so either the permission denied is not the real issue, or there's something different about how RR is handling these two cases. |
I get the same error running |
If you set |
|
Is CONFIG_SECURITY_YAMA not set for your config? |
Correct, it was not set. For the most part I'm using the default config, plus the features I need for my hardware and whatever other features I specifically wanted. I guess Yama defaults to disabled? I set it, rebuilt, and rebooted. ptrace_scope defaulted to 1 so I set it to 0 but that didn't help. I'll probably unset CONFIG_SECURITY_YAMA to avoid changing multiple variables at once. |
@aarzilli Have you by chance run into an issue like this with delve and RR? I don't expect you to provide support for a crash in RR, but I thought you might have seen this before. |
I haven't. If you want to test with the latest version of rr you need to apply a patch to delve that hasn't been merged yet: go-delve/delve#3718 |
Given the following program:
If I place a breakpoint at the call to
mmap.Map
and replay the trace, rr fails an assertion when I step.trace
Complete example, including launch config
My kernel config
uname -a:
Linux MyPC 6.1.38-gentoo #1 SMP PREEMPT_DYNAMIC Thu Aug 3 12:07:10 CDT 2023 x86_64 Intel(R) Core(TM) i9-10850K CPU @ 3.60GHz GenuineIntel GNU/Linux
rr --version:
rr version 5.6.0
go version:
go version go1.20.2 linux/amd64
dlv version:
Version: 1.21.1; Build: $Id: a358c02f24aa7047ecc562b0587dc2d08330b2cf $
VSCode version:
Version: 1.82.2
Commit: abd2f3db4bdb28f9e95536dfa84d8479f1eb312d
Date: 2023-09-14T05:51:20.981Z
Electron: 25.8.1
ElectronBuildId: 23779380
Chromium: 114.0.5735.289
Node.js: 18.15.0
V8: 11.4.183.29-electron.0
OS: Linux x64 6.1.38-gentoo
The text was updated successfully, but these errors were encountered: