rr-debugger / rr-debugger/rr

Replaying a trace that calls mmap causes an assertion failure

Open
#3,635 22 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

Given the following program:

package main

import (
	"os"

	"github.com/edsrzf/mmap-go"
)

func main() {
	f, err := os.CreateTemp("", "")
	must(err)
	defer f.Close()
	must(f.Truncate(1<<12))
	x, err := mmap.Map(f, mmap.RDWR, 0) // <-- break here
	must(err)
	defer x.Unmap()
}

func must(err error) {
	if err != nil {
		panic(err)
	}
}

If I place a breakpoint at the call to mmap.Map and replay the trace, rr fails an assertion when I step.

trace
Detaching and terminating target process
dlv dap (149574) exited with code: 0
Starting: /home/firelizzard/go/bin/dlv dap --listen=127.0.0.1:44051 --log-dest=3 from /tmp/foo
DAP server listening at: 127.0.0.1:44051
Type 'dlv help' for list of commands.
[FATAL src/AutoRemoteSyscalls.cc:734:check_syscall_result()] 
 (task 150151 (rec:150135) at time 443)
 -> Assertion `false' failed to hold. Syscall openat failed with errno EACCES opening /proc/150136/fd/22
Tail of trace dump:
{
  real_time:15653.434285 global_time:423, event:`SYSCALL: fcntl' (state:EXITING_SYSCALL) tid:150135, ticks:1509
rax:0x8002 rbx:0x4 rcx:0xffffffffffffffff rdx:0x0 rsi:0x3 rdi:0x4 rbp:0xc00006c898 rsp:0xc00006c858 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0xc00006c930 r13:0xc000046400 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:0xc000046490 gs_base:0x0
}
{
  real_time:15653.434298 global_time:424, event:`SYSCALL: fcntl' (state:ENTERING_SYSCALL) tid:150135, ticks:1551
rax:0xffffffffffffffda rbx:0x4 rcx:0xffffffffffffffff rdx:0x8802 rsi:0x4 rdi:0x4 rbp:0xc00006c898 rsp:0xc00006c858 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0xc00006c930 r13:0xc000046400 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:0xc000046490 gs_base:0x0
}
{
  real_time:15653.434307 global_time:425, event:`SYSCALL: fcntl' (state:EXITING_SYSCALL) tid:150135, ticks:1551
rax:0x0 rbx:0x4 rcx:0xffffffffffffffff rdx:0x8802 rsi:0x4 rdi:0x4 rbp:0xc00006c898 rsp:0xc00006c858 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0xc00006c930 r13:0xc000046400 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:0xc000046490 gs_base:0x0
}
{
  real_time:15653.434320 global_time:426, event:`SYSCALL: epoll_create1' (state:ENTERING_SYSCALL) tid:150135, ticks:1604
rax:0xffffffffffffffda rbx:0x80000 rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0x80000 rbp:0xc00006c7d0 rsp:0xc00006c790 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0xc00006c8e0 r13:0xc000046400 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:0xc000046490 gs_base:0x0
}
{
  real_time:15653.434336 global_time:427, event:`SYSCALL: epoll_create1' (state:EXITING_SYSCALL) tid:150135, ticks:1604
rax:0x5 rbx:0x80000 rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0x80000 rbp:0xc00006c7d0 rsp:0xc00006c790 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0xc00006c8e0 r13:0xc000046400 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:0xc000046490 gs_base:0x0
}
{
  real_time:15653.434350 global_time:428, event:`SYSCALL: pipe2' (state:ENTERING_SYSCALL) tid:150135, ticks:1607
rax:0xffffffffffffffda rbx:0x0 rcx:0xffffffffffffffff rdx:0x0 rsi:0x80800 rdi:0xc00006c7c0 rbp:0xc00006c7d0 rsp:0xc00006c7b0 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0xc00006c8e0 r13:0xc000046400 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:0xc000046490 gs_base:0x0
}
{
  real_time:15653.434366 global_time:429, event:`SYSCALL: pipe2' (state:EXITING_SYSCALL) tid:150135, ticks:1607
rax:0x0 rbx:0x0 rcx:0xffffffffffffffff rdx:0x0 rsi:0x80800 rdi:0xc00006c7c0 rbp:0xc00006c7d0 rsp:0xc00006c7b0 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0xc00006c8e0 r13:0xc000046400 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:0xc000046490 gs_base:0x0
  { tid:150135, addr:0xc00006c7c0, length:0x8 }
}
{
  real_time:15653.434380 global_time:430, event:`SYSCALL: epoll_ctl' (state:ENTERING_SYSCALL) tid:150135, ticks:1609
rax:0xffffffffffffffda rbx:0x5 rcx:0xffffffffffffffff rdx:0x6 rsi:0x1 rdi:0x5 rbp:0xc00006c7d0 rsp:0xc00006c788 r8:0x0 r9:0x0 r10:0xc00006c814 r11:0x246 r12:0xc00006c8e0 r13:0xc000046400 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:0xc000046490 gs_base:0x0
}
{
  real_time:15653.434391 global_time:431, event:`SYSCALL: epoll_ctl' (state:EXITING_SYSCALL) tid:150135, ticks:1609
rax:0x0 rbx:0x5 rcx:0xffffffffffffffff rdx:0x6 rsi:0x1 rdi:0x5 rbp:0xc00006c7d0 rsp:0xc00006c788 r8:0x0 r9:0x0 r10:0xc00006c814 r11:0x246 r12:0xc00006c8e0 r13:0xc000046400 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:0xc000046490 gs_base:0x0
}
{
  real_time:15653.434407 global_time:432, event:`SYSCALL: epoll_ctl' (state:ENTERING_SYSCALL) tid:150135, ticks:1717
rax:0xffffffffffffffda rbx:0x5 rcx:0xffffffffffffffff rdx:0x4 rsi:0x1 rdi:0x5 rbp:0xc00006c8e0 rsp:0xc00006c898 r8:0x0 r9:0x0 r10:0xc00006c90c r11:0x246 r12:0x0 r13:0xc000046400 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:0xc000046490 gs_base:0x0
}
{
  real_time:15653.434416 global_time:433, event:`SYSCALL: epoll_ctl' (state:EXITING_SYSCALL) tid:150135, ticks:1717
rax:0xffffffffffffffff rbx:0x5 rcx:0xffffffffffffffff rdx:0x4 rsi:0x1 rdi:0x5 rbp:0xc00006c8e0 rsp:0xc00006c898 r8:0x0 r9:0x0 r10:0xc00006c90c r11:0x246 r12:0x0 r13:0xc000046400 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:0xc000046490 gs_base:0x0
}
{
  real_time:15653.434429 global_time:434, event:`SYSCALL: fcntl' (state:ENTERING_SYSCALL) tid:150135, ticks:1777
rax:0xffffffffffffffda rbx:0x4 rcx:0xffffffffffffffff rdx:0x0 rsi:0x3 rdi:0x4 rbp:0xc00006c898 rsp:0xc00006c858 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x0 r13:0xc000046400 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:0xc000046490 gs_base:0x0
}
{
  real_time:15653.434438 global_time:435, event:`SYSCALL: fcntl' (state:EXITING_SYSCALL) tid:150135, ticks:1777
rax:0x8802 rbx:0x4 rcx:0xffffffffffffffff rdx:0x0 rsi:0x3 rdi:0x4 rbp:0xc00006c898 rsp:0xc00006c858 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x0 r13:0xc000046400 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:0xc000046490 gs_base:0x0
}
{
  real_time:15653.434451 global_time:436, event:`SYSCALL: fcntl' (state:ENTERING_SYSCALL) tid:150135, ticks:1824
rax:0xffffffffffffffda rbx:0x4 rcx:0xffffffffffffffff rdx:0x8002 rsi:0x4 rdi:0x4 rbp:0xc00006c898 rsp:0xc00006c858 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x0 r13:0xc000046400 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:0xc000046490 gs_base:0x0
}
{
  real_time:15653.434460 global_time:437, event:`SYSCALL: fcntl' (state:EXITING_SYSCALL) tid:150135, ticks:1824
rax:0x0 rbx:0x4 rcx:0xffffffffffffffff rdx:0x8002 rsi:0x4 rdi:0x4 rbp:0xc00006c898 rsp:0xc00006c858 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x0 r13:0xc000046400 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:0xc000046490 gs_base:0x0
}
{
  real_time:15653.434475 global_time:438, event:`SYSCALL: ftruncate' (state:ENTERING_SYSCALL) tid:150135, ticks:2018
rax:0xffffffffffffffda rbx:0x4 rcx:0xffffffffffffffff rdx:0x0 rsi:0x1000 rdi:0x4 rbp:0xc00006cab0 rsp:0xc00006ca70 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0xc00006ccf8 r13:0xc000046400 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:0xc000046490 gs_base:0x0
}
{
  real_time:15653.434492 global_time:439, event:`SYSCALL: ftruncate' (state:EXITING_SYSCALL) tid:150135, ticks:2018
rax:0x0 rbx:0x4 rcx:0xffffffffffffffff rdx:0x0 rsi:0x1000 rdi:0x4 rbp:0xc00006cab0 rsp:0xc00006ca70 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0xc00006ccf8 r13:0xc000046400 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:0xc000046490 gs_base:0x0
}
{
  real_time:15653.434507 global_time:440, event:`SYSCALL: fstat' (state:ENTERING_SYSCALL) tid:150135, ticks:2159
rax:0xffffffffffffffda rbx:0x4 rcx:0xffffffffffffffff rdx:0x0 rsi:0xc000072518 rdi:0x4 rbp:0xc00006c8c0 rsp:0xc00006c880 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0xc00006cb10 r13:0xc000046400 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:0xc000046490 gs_base:0x0
}
{
  real_time:15653.434518 global_time:441, event:`SYSCALL: fstat' (state:EXITING_SYSCALL) tid:150135, ticks:2159
rax:0x0 rbx:0x4 rcx:0xffffffffffffffff rdx:0x0 rsi:0xc000072518 rdi:0x4 rbp:0xc00006c8c0 rsp:0xc00006c880 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0xc00006cb10 r13:0xc000046400 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:0xc000046490 gs_base:0x0
  { tid:150135, addr:0xc000072518, length:0x90 }
}
{
  real_time:15653.434542 global_time:442, event:`SYSCALL: mmap' (state:ENTERING_SYSCALL) tid:150135, ticks:2276
rax:0xffffffffffffffda rbx:0x0 rcx:0xffffffffffffffff rdx:0x3 rsi:0x1000 rdi:0x0 rbp:0xc00006c718 rsp:0xc00006c6d8 r8:0x4 r9:0x0 r10:0x1 r11:0x246 r12:0xc00006c8b0 r13:0xc000046400 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:0xc000046490 gs_base:0x0
}
{
  real_time:15653.434817 global_time:443, event:`SYSCALL: mmap' (state:EXITING_SYSCALL) tid:150135, ticks:2276
rax:0x7ff22325c000 rbx:0x0 rcx:0xffffffffffffffff rdx:0x3 rsi:0x1000 rdi:0x0 rbp:0xc00006c718 rsp:0xc00006c6d8 r8:0x4 r9:0x0 r10:0x1 r11:0x246 r12:0xc00006c8b0 r13:0xc000046400 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:0xc000046490 gs_base:0x0
  { map_file:"/tmp/1246591439", addr:0x7ff22325c000, length:0x1000, prot_flags:"rw-s", file_offset:0x0, device:2051, inode:275749, data_file:"", data_offset:0x0, file_size:0x1000 }
  { tid:150135, addr:0x7ff22325c000, length:0x1000, holes:[(nil)-0x1000] }
}
{
  real_time:15653.434855 global_time:444, event:`SYSCALL: munmap' (state:ENTERING_SYSCALL) tid:150135, ticks:2612
rax:0xffffffffffffffda rbx:0x7ff22325c000 rcx:0xffffffffffffffff rdx:0x0 rsi:0x1000 rdi:0x7ff22325c000 rbp:0xc00006c9d8 rsp:0xc00006c998 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0xc00006cb58 r13:0xc000046400 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:0xc000046490 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)[0x55a5ff013b61]
rr(_ZN2rr15notifying_abortEv+0xe)[0x55a5ff01509e]
rr(+0x1bdf0f)[0x55a5ff02af0f]
rr(+0xabe43)[0x55a5fef18e43]
rr(+0xac8cb)[0x55a5fef198cb]
rr(_ZN2rr18AutoRemoteSyscalls20check_syscall_resultElib+0x186)[0x55a5feec8896]
rr(_ZN2rr18AutoRemoteSyscalls18finish_direct_mmapENS_10remote_ptrIvEEmiiRKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEEilR4statRS8_+0x1fd)[0x55a5feec98bd]
rr(+0x139e71)[0x55a5fefa6e71]
rr(+0x13b377)[0x55a5fefa8377]
rr(+0x13fe37)[0x55a5feface37]
rr(_ZN2rr13ReplaySession28setup_replay_one_trace_frameEPNS_10ReplayTaskE+0x7b7)[0x55a5fefa4367]
rr(_ZN2rr13ReplaySession11replay_stepERKNS0_15StepConstraintsE+0x9c)[0x55a5fefa454c]
rr(_ZN2rr14ReplayTimeline19replay_step_forwardENS_10RunCommandE+0xc4)[0x55a5fefbdd94]
rr(_ZN2rr9GdbServer14debug_one_stepERNS_10GdbRequestE+0x3c5)[0x55a5fef05e25]
rr(_ZN2rr9GdbServer12serve_replayERKNS0_15ConnectionFlagsE+0x69b)[0x55a5fef0726b]
rr(+0x12c61a)[0x55a5fef9961a]
rr(_ZN2rr13ReplayCommand3runERSt6vectorINSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEESaIS7_EE+0x63f)[0x55a5fef9ae6f]
rr(main+0x1ad)[0x55a5feeb383d]
/usr/lib64/libc.so.6(+0x238ca)[0x7fa43b73f8ca]
/usr/lib64/libc.so.6(__libc_start_main+0x85)[0x7fa43b73f985]
rr(_start+0x21)[0x55a5feeb3a11]
=== End rr backtrace
2023-10-24T14:49:15-05:00 error layer=dap runtime error: EOF
Unable to retrieve goroutines: write tcp 127.0.0.1:42628->127.0.0.1:19064: write: broken pipe
Detaching and terminating target process
2023-10-24T14:51:56-05:00 error layer=dap detach returned error: could not detach process 0: write tcp 127.0.0.1:42628->127.0.0.1:19064: write: broken pipe
dlv dap (149952) exited with code: 0

  • 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

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 with the supplied Go reproducer and replay trace, then inspect src/AutoRemoteSyscalls.cc around check_syscall_result() and finish_direct_mmap(). Trace the mmap/munmap replay path and determine why opening /proc//fd/22 returns EACCES. Done means replaying and stepping through this example no longer triggers the assertion.

Written by the indexing model from the issue text.

Assessment

Tech stack
cpp, go
Domain
devtools, operating-systems
Issue type
Bug
Difficulty
5/5
Estimated time
Over a week
Activity status
Stale
Clarity
Mostly clear
Newbie friendliness
30/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.