Should have read 8 bytes from 0x68000000, but only read -1
Nobody has claimed this yet.
- Dominant language
- C++
- Stars
- 10.7k
- Forks
- 662
- Avg merge
- 2d 3h
- Merged PRs (30d)
- 2
Description
I got an assertion failure of read_bytes_helper:
[INFO log_pending_events()] SYSCALL: read
[INFO log_pending_events()] (none)
[RecordSession] EXEC_SYSCALL_DONE: status=0x857f (SYSCALL)
[RecordSession] original_syscallno:0 (read); return val:0xfffffffffffffff2
[record_syscall] 119139: processing: SYSCALL: read -- time: 30937
[FATAL /home/zyh/rr/src/Task.cc:2832:read_bytes_helper() errno: EIO]
(task 119139 (rec:119139) at time 30937)
-> Assertion `false' failed to hold. Should have read 8 bytes from 0x68000000, but only read -1
[INFO log_pending_events()] SYSCALL: read
[INFO log_pending_events()] (none)
Tail of trace dump:
[TraceStream] Reading event for 564: parent=119139 tid=119152
[TraceStream] Reading event for 943: parent=119139 tid=119153
[TraceStream] Reading event for 1282: parent=119139 tid=119157
[TraceStream] Reading event for 2097: parent=119139 tid=119158
[TraceStream] Reading event for 2106: parent=119158 tid=119159
[TraceStream] Reading event for 2652: parent=119139 tid=119173
[TraceStream] Reading event for 3209: parent=119173 tid=119185
{
real_time:113145.025844 global_time:30917, event:`SYSCALL: read' (state:EXITING_SYSCALL) tid:119139, ticks:1910917
rax:0x1 rbx:0x0 rcx:0xffffffffffffffff rdx:0x1 rsi:0x7f8a645dd32b rdi:0x5 rbp:0x7f8a645dd360 rsp:0x7f8a645dd360 r8:0xffffffffffffffff r9:0x0 r10:0x22 r11:0x246 r12:0x11101040 r13:0x7fffffffd8e0 r14:0x0 r15:0x0 rip:0x7f8a625e82df eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x0 fs_base:0x7ffff7d7ab80 gs_base:0x0
{ tid:119139, addr:0x7f8a645dd32b, length:0x1 }
}
{
real_time:113145.026097 global_time:30918, event:`SYSCALL: read' (state:ENTERING_SYSCALL) tid:119139, ticks:1910922
rax:0xffffffffffffffda rbx:0x0 rcx:0xffffffffffffffff rdx:0x1 rsi:0x7f8a645dd32b rdi:0x5 rbp:0x7f8a645dd360 rsp:0x7f8a645dd360 r8:0xffffffffffffffff r9:0x0 r10:0x22 r11:0x246 r12:0x11101040 r13:0x7fffffffd8e0 r14:0x0 r15:0x0 rip:0x7f8a625e82df eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x0 fs_base:0x7ffff7d7ab80 gs_base:0x0
}
{
real_time:113145.026341 global_time:30919, event:`SYSCALL: read' (state:EXITING_SYSCALL) tid:119139, ticks:1910922
rax:0x1 rbx:0x0 rcx:0xffffffffffffffff rdx:0x1 rsi:0x7f8a645dd32b rdi:0x5 rbp:0x7f8a645dd360 rsp:0x7f8a645dd360 r8:0xffffffffffffffff r9:0x0 r10:0x22 r11:0x246 r12:0x11101040 r13:0x7fffffffd8e0 r14:0x0 r15:0x0 rip:0x7f8a625e82df eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x0 fs_base:0x7ffff7d7ab80 gs_base:0x0
{ tid:119139, addr:0x7f8a645dd32b, length:0x1 }
}
{
real_time:113145.026628 global_time:30920, event:`SYSCALL: read' (state:ENTERING_SYSCALL) tid:119139, ticks:1910930
rax:0xffffffffffffffda rbx:0x0 rcx:0xffffffffffffffff rdx:0x1 rsi:0x7f8a645dd32b rdi:0x5 rbp:0x7f8a645dd360 rsp:0x7f8a645dd360 r8:0xffffffffffffffff r9:0x0 r10:0x22 r11:0x246 r12:0x11101040 r13:0x7fffffffd8e0 r14:0x0 r15:0x0 rip:0x7f8a625e82df eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x0 fs_base:0x7ffff7d7ab80 gs_base:0x0
}
{
real_time:113145.026810 global_time:30921, event:`SYSCALL: read' (state:EXITING_SYSCALL) tid:119139, ticks:1910930
rax:0x1 rbx:0x0 rcx:0xffffffffffffffff rdx:0x1 rsi:0x7f8a645dd32b rdi:0x5 rbp:0x7f8a645dd360 rsp:0x7f8a645dd360 r8:0xffffffffffffffff r9:0x0 r10:0x22 r11:0x246 r12:0x11101040 r13:0x7fffffffd8e0 r14:0x0 r15:0x0 rip:0x7f8a625e82df eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x0 fs_base:0x7ffff7d7ab80 gs_base:0x0
{ tid:119139, addr:0x7f8a645dd32b, length:0x1 }
}
{
real_time:113145.027020 global_time:30922, event:`SYSCALL: read' (state:ENTERING_SYSCALL) tid:119139, ticks:1910935
rax:0xffffffffffffffda rbx:0x0 rcx:0xffffffffffffffff rdx:0x1 rsi:0x7f8a645dd32b rdi:0x5 rbp:0x7f8a645dd360 rsp:0x7f8a645dd360 r8:0xffffffffffffffff r9:0x0 r10:0x22 r11:0x246 r12:0x11101040 r13:0x7fffffffd8e0 r14:0x0 r15:0x0 rip:0x7f8a625e82df eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x0 fs_base:0x7ffff7d7ab80 gs_base:0x0
}
{
real_time:113145.027159 global_time:30923, event:`SYSCALL: read' (state:EXITING_SYSCALL) tid:119139, ticks:1910935
rax:0x1 rbx:0x0 rcx:0xffffffffffffffff rdx:0x1 rsi:0x7f8a645dd32b rdi:0x5 rbp:0x7f8a645dd360 rsp:0x7f8a645dd360 r8:0xffffffffffffffff r9:0x0 r10:0x22 r11:0x246 r12:0x11101040 r13:0x7fffffffd8e0 r14:0x0 r15:0x0 rip:0x7f8a625e82df eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x0 fs_base:0x7ffff7d7ab80 gs_base:0x0
{ tid:119139, addr:0x7f8a645dd32b, length:0x1 }
}
{
real_time:113145.027364 global_time:30924, event:`SYSCALL: read' (state:ENTERING_SYSCALL) tid:119139, ticks:1910940
rax:0xffffffffffffffda rbx:0x0 rcx:0xffffffffffffffff rdx:0x1 rsi:0x7f8a645dd32b rdi:0x5 rbp:0x7f8a645dd360 rsp:0x7f8a645dd360 r8:0xffffffffffffffff r9:0x0 r10:0x22 r11:0x246 r12:0x11101040 r13:0x7fffffffd8e0 r14:0x0 r15:0x0 rip:0x7f8a625e82df eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x0 fs_base:0x7ffff7d7ab80 gs_base:0x0
}
{
real_time:113145.027495 global_time:30925, event:`SYSCALL: read' (state:EXITING_SYSCALL) tid:119139, ticks:1910940
rax:0x1 rbx:0x0 rcx:0xffffffffffffffff rdx:0x1 rsi:0x7f8a645dd32b rdi:0x5 rbp:0x7f8a645dd360 rsp:0x7f8a645dd360 r8:0xffffffffffffffff r9:0x0 r10:0x22 r11:0x246 r12:0x11101040 r13:0x7fffffffd8e0 r14:0x0 r15:0x0 rip:0x7f8a625e82df eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x0 fs_base:0x7ffff7d7ab80 gs_base:0x0
{ tid:119139, addr:0x7f8a645dd32b, length:0x1 }
}
{
real_time:113145.027751 global_time:30926, event:`SYSCALL: read' (state:ENTERING_SYSCALL) tid:119139, ticks:1910947
rax:0xffffffffffffffda rbx:0x0 rcx:0xffffffffffffffff rdx:0x1 rsi:0x7f8a645dd32b rdi:0x5 rbp:0x7f8a645dd360 rsp:0x7f8a645dd360 r8:0xffffffffffffffff r9:0x0 r10:0x22 r11:0x246 r12:0x11101040 r13:0x7fffffffd8e0 r14:0x0 r15:0x0 rip:0x7f8a625e82df eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x0 fs_base:0x7ffff7d7ab80 gs_base:0x0
}
{
real_time:113145.027909 global_time:30927, event:`SYSCALL: read' (state:EXITING_SYSCALL) tid:119139, ticks:1910947
rax:0x1 rbx:0x0 rcx:0xffffffffffffffff rdx:0x1 rsi:0x7f8a645dd32b rdi:0x5 rbp:0x7f8a645dd360 rsp:0x7f8a645dd360 r8:0xffffffffffffffff r9:0x0 r10:0x22 r11:0x246 r12:0x11101040 r13:0x7fffffffd8e0 r14:0x0 r15:0x0 rip:0x7f8a625e82df eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x0 fs_base:0x7ffff7d7ab80 gs_base:0x0
{ tid:119139, addr:0x7f8a645dd32b, length:0x1 }
}
{
real_time:113145.028157 global_time:30928, event:`SYSCALL: read' (state:ENTERING_SYSCALL) tid:119139, ticks:1910952
rax:0xffffffffffffffda rbx:0x0 rcx:0xffffffffffffffff rdx:0x1 rsi:0x7f8a645dd32b rdi:0x5 rbp:0x7f8a645dd360 rsp:0x7f8a645dd360 r8:0xffffffffffffffff r9:0x0 r10:0x22 r11:0x246 r12:0x11101040 r13:0x7fffffffd8e0 r14:0x0 r15:0x0 rip:0x7f8a625e82df eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x0 fs_base:0x7ffff7d7ab80 gs_base:0x0
}
{
real_time:113145.028324 global_time:30929, event:`SYSCALL: read' (state:EXITING_SYSCALL) tid:119139, ticks:1910952
rax:0x1 rbx:0x0 rcx:0xffffffffffffffff rdx:0x1 rsi:0x7f8a645dd32b rdi:0x5 rbp:0x7f8a645dd360 rsp:0x7f8a645dd360 r8:0xffffffffffffffff r9:0x0 r10:0x22 r11:0x246 r12:0x11101040 r13:0x7fffffffd8e0 r14:0x0 r15:0x0 rip:0x7f8a625e82df eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x0 fs_base:0x7ffff7d7ab80 gs_base:0x0
{ tid:119139, addr:0x7f8a645dd32b, length:0x1 }
}
{
real_time:113145.028561 global_time:30930, event:`SYSCALL: read' (state:ENTERING_SYSCALL) tid:119139, ticks:1910957
rax:0xffffffffffffffda rbx:0x0 rcx:0xffffffffffffffff rdx:0x1 rsi:0x7f8a645dd35b rdi:0x5 rbp:0x7f8a645dd390 rsp:0x7f8a645dd390 r8:0xffffffffffffffff r9:0x0 r10:0x22 r11:0x246 r12:0x11101040 r13:0x7fffffffd8e0 r14:0x0 r15:0x0 rip:0x7f8a625e82df eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x0 fs_base:0x7ffff7d7ab80 gs_base:0x0
}
{
real_time:113145.028748 global_time:30931, event:`SYSCALL: read' (state:EXITING_SYSCALL) tid:119139, ticks:1910957
rax:0x1 rbx:0x0 rcx:0xffffffffffffffff rdx:0x1 rsi:0x7f8a645dd35b rdi:0x5 rbp:0x7f8a645dd390 rsp:0x7f8a645dd390 r8:0xffffffffffffffff r9:0x0 r10:0x22 r11:0x246 r12:0x11101040 r13:0x7fffffffd8e0 r14:0x0 r15:0x0 rip:0x7f8a625e82df eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x0 fs_base:0x7ffff7d7ab80 gs_base:0x0
{ tid:119139, addr:0x7f8a645dd35b, length:0x1 }
}
{
real_time:113145.028982 global_time:30932, event:`SYSCALL: munmap' (state:ENTERING_SYSCALL) tid:119139, ticks:1911003
rax:0xffffffffffffffda rbx:0x0 rcx:0xffffffffffffffff rdx:0xffffffa5 rsi:0x200000 rdi:0x68000000 rbp:0x7f8a645de590 rsp:0x7f8a645dd400 r8:0xffffffffffffffff r9:0x0 r10:0x22 r11:0x246 r12:0x11101040 r13:0x7fffffffd8e0 r14:0x0 r15:0x0 rip:0x7f8a625e4e7f eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xb fs_base:0x7ffff7d7ab80 gs_base:0x0
}
{
real_time:113145.029126 global_time:30933, event:`SYSCALL: munmap' (state:EXITING_SYSCALL) tid:119139, ticks:1911003
rax:0x0 rbx:0x0 rcx:0xffffffffffffffff rdx:0xffffffa5 rsi:0x200000 rdi:0x68000000 rbp:0x7f8a645de590 rsp:0x7f8a645dd400 r8:0xffffffffffffffff r9:0x0 r10:0x22 r11:0x246 r12:0x11101040 r13:0x7fffffffd8e0 r14:0x0 r15:0x0 rip:0x7f8a625e4e7f eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xb fs_base:0x7ffff7d7ab80 gs_base:0x0
}
{
real_time:113145.029321 global_time:30934, event:`SYSCALL: lseek' (state:ENTERING_SYSCALL) tid:119139, ticks:1911005
rax:0xffffffffffffffda rbx:0x0 rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0x5 rbp:0x7f8a645de590 rsp:0x7f8a645dd400 r8:0xffffffffffffffff r9:0x0 r10:0x22 r11:0x246 r12:0x11101040 r13:0x7fffffffd8e0 r14:0x0 r15:0x0 rip:0x7f8a625e4fb0 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x8 fs_base:0x7ffff7d7ab80 gs_base:0x0
}
{
real_time:113145.029441 global_time:30935, event:`SYSCALL: lseek' (state:EXITING_SYSCALL) tid:119139, ticks:1911005
rax:0x0 rbx:0x0 rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0x5 rbp:0x7f8a645de590 rsp:0x7f8a645dd400 r8:0xffffffffffffffff r9:0x0 r10:0x22 r11:0x246 r12:0x11101040 r13:0x7fffffffd8e0 r14:0x0 r15:0x0 rip:0x7f8a625e4fb0 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x8 fs_base:0x7ffff7d7ab80 gs_base:0x0
}
{
real_time:113145.029632 global_time:30936, event:`SYSCALL: read' (state:ENTERING_SYSCALL) tid:119139, ticks:1911006
rax:0xffffffffffffffda rbx:0x0 rcx:0xffffffffffffffff rdx:0x1 rsi:0x7f8a645dd32b rdi:0x5 rbp:0x7f8a645dd360 rsp:0x7f8a645dd360 r8:0xffffffffffffffff r9:0x0 r10:0x22 r11:0x246 r12:0x11101040 r13:0x7fffffffd8e0 r14:0x0 r15:0x0 rip:0x7f8a625e82df eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x0 fs_base:0x7ffff7d7ab80 gs_base:0x0
}
=== Start rr backtrace:
/home/zyh/rr/build/bin/rr(_ZN2rr13dump_rr_stackEv+0x5d)[0x555555ad820c]
/home/zyh/rr/build/bin/rr(_ZN2rr9GdbServer15emergency_debugEPNS_4TaskE+0x1a6)[0x5555558df01e]
/home/zyh/rr/build/bin/rr(+0x3c3ac4)[0x555555917ac4]
/home/zyh/rr/build/bin/rr(_ZN2rr21EmergencyDebugOstreamD1Ev+0x66)[0x555555917d4c]
/home/zyh/rr/build/bin/rr(_ZN2rr4Task17read_bytes_helperENS_10remote_ptrIvEElPvPb+0x11c)[0x555555a96f60]
/home/zyh/rr/build/bin/rr(_ZN2rr4Task8read_memIhEESt6vectorIT_SaIS3_EENS_10remote_ptrIS3_EEmPb+0x94)[0x55555584a796]
/home/zyh/rr/build/bin/rr(_ZN2rr16TaskSyscallState23process_syscall_resultsEv+0x126)[0x555555977eda]
/home/zyh/rr/build/bin/rr(_ZN2rr19rec_process_syscallEPNS_10RecordTaskE+0xf1)[0x555555982536]
/home/zyh/rr/build/bin/rr(_ZN2rr13RecordSession21syscall_state_changedEPNS_10RecordTaskEPNS0_9StepStateE+0xd2b)[0x55555595ee69]
/home/zyh/rr/build/bin/rr(_ZN2rr13RecordSession11record_stepEv+0x507)[0x555555964c99]
/home/zyh/rr/build/bin/rr(+0x402e11)[0x555555956e11]
/home/zyh/rr/build/bin/rr(_ZN2rr13RecordCommand3runERSt6vectorINSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEESaIS7_EE+0x40f)[0x555555957adf]
/home/zyh/rr/build/bin/rr(main+0x27d)[0x555555af406f]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf3)[0x7ffff750e0b3]
/home/zyh/rr/build/bin/rr(_start+0x2e)[0x5555558346ee]
=== End rr backtrace
The debugged application is dmtcp (restarting a program), kernel is
Linux pc 5.4.0-100-generic #113-Ubuntu SMP Thu Feb 3 18:43:29 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux
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 Task.cc around read_bytes_helper() at line 2832, then follow Task::read_mem(), TaskSyscallState::process_syscall_results(), and rec_process_syscall() in the reported backtrace. Compare the failing read at 0x68000000 with the preceding munmap and lseek events to determine why the recorded syscall results no longer match the task memory. Done means explaining the failure and adding a regression test if the cause can be reproduced.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- cpp, linux
- Domain
- devtools, operating-systems
- Issue type
- Bug
- Difficulty
- 5/5
- Estimated time
- Over a week
- Activity status
- Stale
- Clarity
- Needs clarification
- Newbie friendliness
- 20/100