rr-debugger / rr-debugger/rr

reverse-next in an async function in rust leads to an error `Probable previous-to-duplicated-state ..`

Open
#3,031 11 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 build this program (I use a project where this is src/main.rs)

async fn a() {
    println!("a");
}

async fn b() {
    a().await;
    println!("next");
}

#[async_std::main]
async fn main() {
    b().await;
}

cargo file is

[package]
name = "async_rs"
version = "0.1.0"
authors = ["Alexander Ivanov <alehander42@gmail.com>"]
edition = "2018"

# See more keys and their definitions at https://doc.rust-lang.org/cargo/reference/manifest.html

[dependencies]
futures = "0.3.15"
async-std = {version = "1.9.0", features = ["attributes"] }

I build, record and replay:

cargo build
rr record target/debug/async_rs
rr replay

in rr I do

b async_rs::b::{{closure}}
# > Breakpoint 1 at 0x5570a6f99311: file src/main.rs, line 5.
c
# > Continuing.
# > [New Thread 347318.347319]
# > [New Thread 347318.347320]
# > 
# > Thread 1 hit Breakpoint 1, async_rs::b::{{closure}} () at src/main.rs:5
# > 5	async fn b() {
n
# > 6	    a().await;
rn # here i expect to go back normally
# but i get
Probable previous-to-duplicated-state at 313:{time:397,ticks:147361,st:7,regs:Printing register file:
rax:0x7ffebfb3a330
rbx:0x7ffebfb3b6e0
rcx:0x7ffebfb3a330
rdx:0x7ffebfb30000
rsi:0x7ffebfb3a330
rdi:0x7ffebfb3a330
rbp:0x0
rsp:0x7ffebfb39770
r8:0x5570a73d6210
r9:0x0
r10:0x5570a73d5010
r11:0x7f2cfe7f0be0
r12:0x5570a6f99080
r13:0x7ffebfb3b800
r14:0x5570a70ccb18
r15:0x0
rip:0x5570a6f9ba3f
eflags:0x202
cs:0x33
ss:0x2b
ds:0x0
es:0x0
fs:0x0
gs:0x0
orig_rax:0xffffffffffffffff
fs_base:0x7f2cfe600880
gs_base:0x0

,return_addresses=[0x1,0x7ffebfb3a330,(nil),(nil),(nil),(nil),(nil),(nil)]}Probable previous-to-duplicated-state at 461:{time:397,ticks:147361,st:7,regs:Printing register file:
rax:0x7ffebfb3a330
rbx:0x7ffebfb3b6e0
rcx:0x7ffebfb3a330
rdx:0x7ffebfb30000
rsi:0x7ffebfb3a330
rdi:0x7ffebfb3a330
rbp:0x0
rsp:0x7ffebfb39670
r8:0x5570a73d6210
r9:0x0
r10:0x5570a73d5010
r11:0x7f2cfe7f0be0
r12:0x5570a6f99080
r13:0x7ffebfb3b800
r14:0x5570a70ccb18
r15:0x0
rip:0x5570a6f9ba3f
eflags:0x202
cs:0x33
ss:0x2b
ds:0x0
es:0x0
fs:0x0
gs:0x0
orig_rax:0xffffffffffffffff
fs_base:0x7f2cfe600880
gs_base:0x0

,return_addresses=[0x20,0x7ffebfb3a330,(nil),(nil),(nil),(nil),(nil),(nil)]}Probable duplicated state at 314:{time:397,ticks:147361,st:7,regs:Printing register file:
rax:0x7ffebfb3a330
rbx:0x7ffebfb3b6e0
rcx:0x7ffebfb3a330
rdx:0x7ffebfb30000
rsi:0x7ffebfb3a330
rdi:0x7ffebfb3a330
rbp:0x0
rsp:0x7ffebfb39770
r8:0x5570a73d6210
r9:0x0
r10:0x5570a73d5010
r11:0x7f2cfe7f0be0
r12:0x5570a6f99080
r13:0x7ffebfb3b800
r14:0x5570a70ccb18
r15:0x0
rip:0x5570a6f9ba43
eflags:0x202
cs:0x33
ss:0x2b
ds:0x0
es:0x0
fs:0x0
gs:0x0
orig_rax:0xffffffffffffffff
fs_base:0x7f2cfe600880
gs_base:0x0

,return_addresses=[0x7ffebfb3a330,0x7ffebfb3a330,(nil),(nil),(nil),(nil),(nil),(nil)]}[FATAL /build/rr-S0CLEN/rr-5.3.0/src/ReplayTimeline.cc:246:mark_after_singlestep() errno: EIO] 
 (task 347368 (rec:347318) at time 397)
 -> Assertion `false' failed to hold.  Probable duplicated states leading to {time:397,ticks:147361,st:7,regs_ip:0x5570a6f9ba43} at index 462
Tail of trace dump:
{
  real_time:220191.444248 global_time:377, event:`SYSCALL: sigaltstack' (state:EXITING_SYSCALL) tid:347320, ticks:24
rax:0x0 rbx:0x83 rcx:0xffffffffffffffff rdx:0x2118710e25b8b069 rsi:0x7f2cfe0fdd00 rdi:0x0 rbp:0x7f2cfdefdfa0 rsp:0x7f2cfdefde10 r8:0x7f2cfe0fe700 r9:0x7f2cfe0fe700 r10:0x7f2cfe0fe9d0 r11:0x246 r12:0x7f2cfdefdef0 r13:0x54cb8 r14:0x3 r15:0x5570a73d5e20 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x83 fs_base:0x7f2cfe0fe700 gs_base:0x0
  { tid:347320, addr:0x7f2cfe0fdd00, length:0x18 }
}
{
  real_time:220191.444291 global_time:378, event:`SYSCALL: mmap' (state:ENTERING_SYSCALL) tid:347320, ticks:47
rax:0xffffffffffffffda rbx:0x9 rcx:0xffffffffffffffff rdx:0x3 rsi:0x3000 rdi:0x0 rbp:0x7f2cfdefdfa0 rsp:0x7f2cfdefde10 r8:0xffffffff r9:0x0 r10:0x20022 r11:0x246 r12:0x7ffebfb39b3e r13:0x7ffebfb39b3f r14:0x7ffebfb39c00 r15:0x5570a73d5e20 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x9 fs_base:0x7f2cfe0fe700 gs_base:0x0
}
{
  real_time:220191.444329 global_time:379, event:`SYSCALL: mmap' (state:EXITING_SYSCALL) tid:347320, ticks:47
rax:0x7f2cfe99a000 rbx:0x9 rcx:0xffffffffffffffff rdx:0x3 rsi:0x3000 rdi:0x0 rbp:0x7f2cfdefdfa0 rsp:0x7f2cfdefde10 r8:0xffffffff r9:0x0 r10:0x20022 r11:0x246 r12:0x7ffebfb39b3e r13:0x7ffebfb39b3f r14:0x7ffebfb39c00 r15:0x5570a73d5e20 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x9 fs_base:0x7f2cfe0fe700 gs_base:0x0
  { map_file:"<ZERO>", addr:0x7f2cfe99a000, length:0x3000, prot_flags:"rw-p", file_offset:0x0, device:0, inode:0, data_file:"", data_offset:0x0, file_size:0x3000 }
}
{
  real_time:220191.444382 global_time:380, event:`SYSCALLBUF_FLUSH' tid:347320, ticks:98
  { syscall:'mprotect', ret:0x0, size:0x10 }
}
{
  real_time:220191.444386 global_time:381, event:`SYSCALL: sigaltstack' (state:ENTERING_SYSCALL) tid:347320, ticks:98
rax:0xffffffffffffffda rbx:0x83 rcx:0xffffffffffffffff rdx:0x7f2cfe7b87f4 rsi:0x0 rdi:0x7f2cfe0fdd00 rbp:0x7f2cfdefdfa0 rsp:0x7f2cfdefde10 r8:0xffffffff r9:0x0 r10:0x20022 r11:0x246 r12:0x7ffebfb39b3e r13:0x7ffebfb39b3f r14:0x7ffebfb39c00 r15:0x5570a73d5e20 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x83 fs_base:0x7f2cfe0fe700 gs_base:0x0
}
{
  real_time:220191.444388 global_time:382, event:`SYSCALLBUF_RESET' tid:347320, ticks:98
}
{
  real_time:220191.444417 global_time:383, event:`SYSCALL: sigaltstack' (state:EXITING_SYSCALL) tid:347320, ticks:98
rax:0x0 rbx:0x83 rcx:0xffffffffffffffff rdx:0x7f2cfe7b87f4 rsi:0x0 rdi:0x7f2cfe0fdd00 rbp:0x7f2cfdefdfa0 rsp:0x7f2cfdefde10 r8:0xffffffff r9:0x0 r10:0x20022 r11:0x246 r12:0x7ffebfb39b3e r13:0x7ffebfb39b3f r14:0x7ffebfb39c00 r15:0x5570a73d5e20 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x83 fs_base:0x7f2cfe0fe700 gs_base:0x0
}
{
  real_time:220191.444460 global_time:384, event:`SYSCALL: prctl' (state:ENTERING_SYSCALL) tid:347320, ticks:110
rax:0xffffffffffffffda rbx:0x9d rcx:0xffffffffffffffff rdx:0x0 rsi:0x5570a73d5b40 rdi:0xf rbp:0x7f2cfdefdfa0 rsp:0x7f2cfdefde10 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x5570a73d5df0 r13:0x7ffebfb39b3f r14:0x7f2cfe99b000 r15:0x5570a73d5e20 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x9d fs_base:0x7f2cfe0fe700 gs_base:0x0
}
{
  real_time:220191.444494 global_time:385, event:`SYSCALL: prctl' (state:EXITING_SYSCALL) tid:347320, ticks:110
rax:0x0 rbx:0x9d rcx:0xffffffffffffffff rdx:0x0 rsi:0x5570a73d5b40 rdi:0xf rbp:0x7f2cfdefdfa0 rsp:0x7f2cfdefde10 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x5570a73d5df0 r13:0x7ffebfb39b3f r14:0x7f2cfe99b000 r15:0x5570a73d5e20 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x9d fs_base:0x7f2cfe0fe700 gs_base:0x0
}
{
  real_time:220191.444537 global_time:386, event:`SYSCALL: mmap' (state:ENTERING_SYSCALL) tid:347320, ticks:149
rax:0xffffffffffffffda rbx:0x9 rcx:0xffffffffffffffff rdx:0x0 rsi:0x8000000 rdi:0x0 rbp:0x7f2cfdefdfa0 rsp:0x7f2cfdefde10 r8:0xffffffff r9:0x0 r10:0x4022 r11:0x246 r12:0xfffffffffffffe70 r13:0x0 r14:0x20 r15:0x0 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x9 fs_base:0x7f2cfe0fe700 gs_base:0x0
}
{
  real_time:220191.444575 global_time:387, event:`SYSCALL: mmap' (state:EXITING_SYSCALL) tid:347320, ticks:149
rax:0x7f2cf0000000 rbx:0x9 rcx:0xffffffffffffffff rdx:0x0 rsi:0x8000000 rdi:0x0 rbp:0x7f2cfdefdfa0 rsp:0x7f2cfdefde10 r8:0xffffffff r9:0x0 r10:0x4022 r11:0x246 r12:0xfffffffffffffe70 r13:0x0 r14:0x20 r15:0x0 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x9 fs_base:0x7f2cfe0fe700 gs_base:0x0
  { map_file:"<ZERO>", addr:0x7f2cf0000000, length:0x8000000, prot_flags:"---p", file_offset:0x0, device:0, inode:0, data_file:"", data_offset:0x0, file_size:0x8000000 }
}
{
  real_time:220191.444616 global_time:388, event:`SYSCALL: munmap' (state:ENTERING_SYSCALL) tid:347320, ticks:161
rax:0xffffffffffffffda rbx:0xb rcx:0xffffffffffffffff rdx:0x0 rsi:0x4000000 rdi:0x7f2cf4000000 rbp:0x7f2cfdefdfa0 rsp:0x7f2cfdefde10 r8:0xffffffff r9:0x0 r10:0x4022 r11:0x246 r12:0x7f2cf0000000 r13:0x0 r14:0x20 r15:0x0 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xb fs_base:0x7f2cfe0fe700 gs_base:0x0
}
{
  real_time:220191.444654 global_time:389, event:`SYSCALL: munmap' (state:EXITING_SYSCALL) tid:347320, ticks:161
rax:0x0 rbx:0xb rcx:0xffffffffffffffff rdx:0x0 rsi:0x4000000 rdi:0x7f2cf4000000 rbp:0x7f2cfdefdfa0 rsp:0x7f2cfdefde10 r8:0xffffffff r9:0x0 r10:0x4022 r11:0x246 r12:0x7f2cf0000000 r13:0x0 r14:0x20 r15:0x0 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xb fs_base:0x7f2cfe0fe700 gs_base:0x0
}
{
  real_time:220191.444711 global_time:390, event:`SYSCALLBUF_FLUSH' tid:347320, ticks:385
  { syscall:'mprotect', ret:0x0, size:0x10 }
}
{
  real_time:220191.444715 global_time:391, event:`SYSCALL: sched_getaffinity' (state:ENTERING_SYSCALL) tid:347320, ticks:385
rax:0xffffffffffffffda rbx:0x7f2cfe0fe700 rcx:0xffffffffffffffff rdx:0x7f2cf0000b60 rsi:0x20 rdi:0x54cb8 rbp:0x7f2cfe0fdc00 rsp:0x7f2cfe0fdb28 r8:0x20 r9:0x0 r10:0x4022 r11:0x246 r12:0x7f2cfe0fed18 r13:0x7f2cf0000b60 r14:0x20 r15:0x0 rip:0x7f2cfe961684 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xcc fs_base:0x7f2cfe0fe700 gs_base:0x0
}
{
  real_time:220191.444717 global_time:392, event:`SYSCALLBUF_RESET' tid:347320, ticks:385
}
{
  real_time:220191.444753 global_time:393, event:`SYSCALL: sched_getaffinity' (state:EXITING_SYSCALL) tid:347320, ticks:385
rax:0x8 rbx:0x7f2cfe0fe700 rcx:0xffffffffffffffff rdx:0x7f2cf0000b60 rsi:0x20 rdi:0x54cb8 rbp:0x7f2cfe0fdc00 rsp:0x7f2cfe0fdb28 r8:0x20 r9:0x0 r10:0x4022 r11:0x246 r12:0x7f2cfe0fed18 r13:0x7f2cf0000b60 r14:0x20 r15:0x0 rip:0x7f2cfe961684 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xcc fs_base:0x7f2cfe0fe700 gs_base:0x0
  { tid:347320, addr:0x7f2cf0000b60, length:0x8 }
}
{
  real_time:220191.444799 global_time:394, event:`SYSCALL: futex' (state:ENTERING_SYSCALL) tid:347320, ticks:531
rax:0xffffffffffffffda rbx:0xca rcx:0xffffffffffffffff rdx:0xffffffff rsi:0x80 rdi:0x5570a73d5dd8 rbp:0x7f2cfdefdfa0 rsp:0x7f2cfdefde10 r8:0x0 r9:0x5570a705e650 r10:0x0 r11:0x246 r12:0x7f2cfe720880 r13:0x7ffebfb39b3f r14:0x5570a73d5db0 r15:0x0 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xca fs_base:0x7f2cfe0fe700 gs_base:0x0
}
{
  real_time:220191.444815 global_time:395, event:`SYSCALL: clone' (state:EXITING_SYSCALL) tid:347318, ticks:144530
rax:0x54cb8 rbx:0x7f2cfe0fe700 rcx:0xffffffffffffffff rdx:0x7f2cfe0fe9d0 rsi:0x7f2cfe0fde70 rdi:0x3d0f00 rbp:0x7ffebfb39c00 rsp:0x7ffebfb39a88 r8:0x7f2cfe0fe700 r9:0x7f2cfe0fe700 r10:0x7f2cfe0fe9d0 r11:0x246 r12:0x7ffebfb39b3e r13:0x7ffebfb39b3f r14:0x7ffebfb39c00 r15:0x7f2cfe0fde80 rip:0x7f2cfe727285 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x38 fs_base:0x7f2cfe600880 gs_base:0x0
}
{
  real_time:220191.444922 global_time:396, event:`SYSCALLBUF_FLUSH' tid:347318, ticks:147418
  { syscall:'futex', ret:0x1, size:0x14 }
}
{
  real_time:220191.444966 global_time:397, event:`PATCH_SYSCALL' tid:347318, ticks:147418
rax:0x1 rbx:0x5570a70d06 rcx:0xffffffffffffffff rdx:0x2 rsi:0x5570a7084093 rdi:0x1 rbp:0x2 rsp:0x7ffebfb391c0 r8:0x0 r9:0x0 r10:0x5570a73d5010 r11:0x246 r12:0x7ffebfb39340 r13:0x5570a70d94c8 r14:0x2 r15:0x5570a7084093 rip:0x7f2cfe9602cd eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7f2cfe600880 gs_base:0x0
  { tid:347318, addr:0x7f2cfe98b6ca, length:0x4f }
  { tid:347318, addr:0x7f2cfe9602cd, length:0x5 }
  { tid:347318, addr:0x7f2cfe9602d2, length:0x3 }
}
{
  real_time:220191.444969 global_time:398, event:`SYSCALLBUF_RESET' tid:347318, ticks:147418
}
=== Start rr backtrace:
rr(_ZN2rr13dump_rr_stackEv+0x5a)[0x5648ab7c165a]
rr(_ZN2rr9GdbServer15emergency_debugEPNS_4TaskE+0x635)[0x5648ab6d8795]
rr(+0xb33e1)[0x5648ab6e93e1]
rr(_ZN2rr21EmergencyDebugOstreamD2Ev+0x75)[0x5648ab6e95b5]
rr(_ZN2rr14ReplayTimeline21mark_after_singlestepERKNS0_4MarkERKNS_12ReplayResultE+0x310)[0x5648ab77af30]
rr(_ZN2rr14ReplayTimeline18reverse_singlestepERKNS0_4MarkERKNS_10TaskishUidINS_4TaskEEElRKSt8functionIFbPNS_10ReplayTaskEEERKS9_IFbvEE+0x1f9a)[0x5648ab78053a]
rr(_ZN2rr14ReplayTimeline18reverse_singlestepERKNS_10TaskishUidINS_4TaskEEElRKSt8functionIFbPNS_10ReplayTaskEEERKS6_IFbvEE+0x66)[0x5648ab783056]
rr(_ZN2rr9GdbServer14debug_one_stepERNS_10GdbRequestE+0xd4c)[0x5648ab6daeec]
rr(_ZN2rr9GdbServer12serve_replayERKNS0_15ConnectionFlagsE+0x6fb)[0x5648ab6dc17b]
rr(+0x124dff)[0x5648ab75adff]
rr(_ZN2rr13ReplayCommand3runERSt6vectorINSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEESaIS7_EE+0x4ca)[0x5648ab75be1a]
rr(main+0x282)[0x5648ab68c8a2]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf3)[0x7ff4537b50b3]
rr(_start+0x2e)[0x5648ab68c9ee]
=== End rr backtrace
Launch gdb with
  gdb '-l' '10000' '-ex' 'set sysroot /' '-ex' 'target extended-remote 127.0.0.1:19688' /home/al/.local/share/rr/async_rs-2/mmap_hardlink_3_async_rs
rr --version # rr version 5.3.0

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

Reproduce the issue using the provided src/main.rs and Cargo dependencies: run cargo build, rr record target/debug/async_rs, then rr replay. Start at the GDB breakpoint on async_rs:🅱️:{{closure}} and test reverse-next across a().await. Done means reverse stepping no longer triggers the duplicated-state assertion and fatal ReplayTimeline error.

Written by the indexing model from the issue text.

Assessment

Tech stack
cpp, linux, rust
Domain
devtools, operating-systems
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Mostly clear
Newbie friendliness
35/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.