rr-debugger / rr

Record and Replay Framework
http://rr-project.org/
Other
9.22k stars 588 forks source link

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

Open alehander92 opened 2 years ago

alehander92 commented 2 years ago

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
khuey commented 2 years ago

rr --version # rr version 5.3.0

Step 1 is to retry this on a version of rr that isn't more than 2 years old.

alehander92 commented 2 years ago

nice! I haven't updated since a long time.

However I still hit it with 5.5.0

khuey commented 2 years ago

Alright I can reproduce this.

alehander92 commented 2 years ago

I think I reproduce it on latest source (1c7c7eb840d191bed71f) as well

khuey commented 2 years ago

I suspect the future executor is defeating our "same execution point" heuristic by storing data about the current future somewhere other than the stack.

The ip where things blow up is at 0x000056183e87d08f in core::future::get_context (cx=...) at /rustc/f1edd0429582dd29cccacaf50fd134b05593bd9c/library/core/src/future/mod.rs:97

Disassembly

Dump of assembler code for function _ZN4core6future11get_context17h3b67940abc5c064bE:
   0x000056183e87d080 <+0>:     sub    $0x18,%rsp
   0x000056183e87d084 <+4>:     mov    %rdi,0x8(%rsp)
   0x000056183e87d089 <+9>:     call   *0x137231(%rip)        # 0x56183e9b42c0
=> 0x000056183e87d08f <+15>:    mov    %rax,(%rsp)
   0x000056183e87d093 <+19>:    mov    (%rsp),%rax
   0x000056183e87d097 <+23>:    mov    %rax,0x10(%rsp)
   0x000056183e87d09c <+28>:    mov    (%rsp),%rax
   0x000056183e87d0a0 <+32>:    add    $0x18,%rsp
   0x000056183e87d0a4 <+36>:    ret

There's nothing interesting on the C stack here, it's all futures boilerplate.

(rr) bt
#0  0x000056183e87d08f in core::future::get_context (cx=...) at /rustc/f1edd0429582dd29cccacaf50fd134b05593bd9c/library/core/src/future/mod.rs:97
#1  0x000056183e87b324 in async_executor::{impl#9}::run::{generator#0}<(), async_std::task::builder::SupportTaskLocals<core::future::from_generator::GenFuture<rr_3031::main::{generator#0}>>> () at /home/khuey/.cargo/registry/src/github.com-1ecc6299db9ec823/async-executor-1.4.1/src/lib.rs:447
#2  0x000056183e87e3bb in core::future::from_generator::{impl#1}::poll<async_executor::{impl#9}::run::{generator#0}> (self=..., cx=0x7ffeb6b46b70)
    at /rustc/f1edd0429582dd29cccacaf50fd134b05593bd9c/library/core/src/future/mod.rs:80
#3  0x000056183e87fc94 in async_io::driver::block_on<(), core::future::from_generator::GenFuture<async_executor::{impl#9}::run::{generator#0}>> (future=...)
    at /home/khuey/.cargo/registry/src/github.com-1ecc6299db9ec823/async-io-1.6.0/src/driver.rs:142
#4  0x000056183e879c63 in async_global_executor::reactor::block_on::{closure#0}<core::future::from_generator::GenFuture<async_executor::{impl#9}::run::{generator#0}>, ()> ()
    at /home/khuey/.cargo/registry/src/github.com-1ecc6299db9ec823/async-global-executor-2.0.2/src/reactor.rs:3
#5  0x000056183e879c2d in async_global_executor::reactor::block_on<core::future::from_generator::GenFuture<async_executor::{impl#9}::run::{generator#0}>, ()> (future=...)
    at /home/khuey/.cargo/registry/src/github.com-1ecc6299db9ec823/async-global-executor-2.0.2/src/reactor.rs:12
#6  0x000056183e87bf8d in async_global_executor::executor::block_on::{closure#0}<async_std::task::builder::SupportTaskLocals<core::future::from_generator::GenFuture<rr_3031::main::{generator#0}>>, ()> (executor=0x7fcfb102e7e0) at /home/khuey/.cargo/registry/src/github.com-1ecc6299db9ec823/async-global-executor-2.0.2/src/executor.rs:26
#7  0x000056183e87f633 in std::thread::local::LocalKey<async_executor::LocalExecutor>::try_with<async_executor::LocalExecutor, async_global_executor::executor::block_on::{closure#0}, ()> (
    self=0x56183e9aaa08, f=...) at /rustc/f1edd0429582dd29cccacaf50fd134b05593bd9c/library/std/src/thread/local.rs:399
#8  0x000056183e87ea5a in std::thread::local::LocalKey<async_executor::LocalExecutor>::with<async_executor::LocalExecutor, async_global_executor::executor::block_on::{closure#0}, ()> (
    self=0x56183e9aaa08, f=...) at /rustc/f1edd0429582dd29cccacaf50fd134b05593bd9c/library/std/src/thread/local.rs:375
#9  0x000056183e87bf37 in async_global_executor::executor::block_on<async_std::task::builder::SupportTaskLocals<core::future::from_generator::GenFuture<rr_3031::main::{generator#0}>>, ()>
    (future=...) at /home/khuey/.cargo/registry/src/github.com-1ecc6299db9ec823/async-global-executor-2.0.2/src/executor.rs:26
#10 0x000056183e8799da in async_std::task::builder::{impl#0}::blocking::{closure#0}::{closure#0}<core::future::from_generator::GenFuture<rr_3031::main::{generator#0}>, ()> ()
    at /home/khuey/.cargo/registry/src/github.com-1ecc6299db9ec823/async-std-1.10.0/src/task/builder.rs:171
#11 0x000056183e87c801 in async_std::task::task_locals_wrapper::{impl#0}::set_current::{closure#0}<async_std::task::builder::{impl#0}::blocking::{closure#0}::{closure#0}, ()> (
    current=0x7fcfb102e790) at /home/khuey/.cargo/registry/src/github.com-1ecc6299db9ec823/async-std-1.10.0/src/task/task_locals_wrapper.rs:60
#12 0x000056183e87f79e in std::thread::local::LocalKey<core::cell::Cell<*const async_std::task::task_locals_wrapper::TaskLocalsWrapper>>::try_with<core::cell::Cell<*const async_std::task::task_locals_wrapper::TaskLocalsWrapper>, async_std::task::task_locals_wrapper::{impl#0}::set_current::{closure#0}, ()> (self=0x56183e9aaa28, f=...)
    at /rustc/f1edd0429582dd29cccacaf50fd134b05593bd9c/library/std/src/thread/local.rs:399
#13 0x000056183e87eabc in std::thread::local::LocalKey<core::cell::Cell<*const async_std::task::task_locals_wrapper::TaskLocalsWrapper>>::with<core::cell::Cell<*const async_std::task::task_locals_wrapper::TaskLocalsWrapper>, async_std::task::task_locals_wrapper::{impl#0}::set_current::{closure#0}, ()> (self=0x56183e9aaa28, f=...)
    at /rustc/f1edd0429582dd29cccacaf50fd134b05593bd9c/library/std/src/thread/local.rs:375
#14 0x000056183e87c5e7 in async_std::task::task_locals_wrapper::TaskLocalsWrapper::set_current<async_std::task::builder::{impl#0}::blocking::{closure#0}::{closure#0}, ()> (
    task=0x7ffeb6b47b80, f=...) at /home/khuey/.cargo/registry/src/github.com-1ecc6299db9ec823/async-std-1.10.0/src/task/task_locals_wrapper.rs:55
#15 0x000056183e87994c in async_std::task::builder::{impl#0}::blocking::{closure#0}<core::future::from_generator::GenFuture<rr_3031::main::{generator#0}>, ()> (
    num_nested_blocking=0x7fcfb102e778) at /home/khuey/.cargo/registry/src/github.com-1ecc6299db9ec823/async-std-1.10.0/src/task/builder.rs:168
#16 0x000056183e87eedb in std::thread::local::LocalKey<core::cell::Cell<usize>>::try_with<core::cell::Cell<usize>, async_std::task::builder::{impl#0}::blocking::{closure#0}, ()> (
    self=0x56183e9aa8b8, f=...) at /rustc/f1edd0429582dd29cccacaf50fd134b05593bd9c/library/std/src/thread/local.rs:399
#17 0x000056183e87ebaa in std::thread::local::LocalKey<core::cell::Cell<usize>>::with<core::cell::Cell<usize>, async_std::task::builder::{impl#0}::blocking::{closure#0}, ()> (
    self=0x56183e9aa8b8, f=...) at /rustc/f1edd0429582dd29cccacaf50fd134b05593bd9c/library/std/src/thread/local.rs:375
#18 0x000056183e879660 in async_std::task::builder::Builder::blocking<core::future::from_generator::GenFuture<rr_3031::main::{generator#0}>, ()> (self=..., future=...)
    at /home/khuey/.cargo/registry/src/github.com-1ecc6299db9ec823/async-std-1.10.0/src/task/builder.rs:161
#19 0x000056183e87e8df in async_std::task::block_on::block_on<core::future::from_generator::GenFuture<rr_3031::main::{generator#0}>, ()> (future=...)
    at /home/khuey/.cargo/registry/src/github.com-1ecc6299db9ec823/async-std-1.10.0/src/task/block_on.rs:33
#20 0x000056183e879b37 in rr_3031::main () at src/main.rs:10

The actual state of the future is going to live in the heap somewhere and not on the stack, so multiple polls of the same future probably look identical to us.

@rocallahan any thoughts?

rocallahan commented 2 years ago

I agree with your diagnosis.

This would likely to be hard to fix. It's hard to get motivated about it because Pernosco handles this so much better :-(.

alehander92 commented 2 years ago

what would we need to do if we want to try to contribute a fix? EDIT: what is the direction to go into

rocallahan commented 2 years ago

First verify that you have two different program states where the Registers are the same and the tick count is the same and the ReturnAddressList is the same (but presumably the state of futures on the heap or stack are different).

Then try to figure out how rr could systematically capture the state of those futures and capture them alongside the ReturnAddressList. I have no idea how to do that or if it's possible.

alehander92 commented 2 years ago

i thought each jump increases the tick count, having no jumps between those polls sound strange to me indeed, thanks for the info

rocallahan commented 2 years ago

Only conditional branches increase the tick count.

There is a counter for all branches but it's unreliable on some CPU versions.

alehander92 commented 1 month ago

kinda related to https://github.com/rr-debugger/rr/issues/2263#issuecomment-432035755 and https://github.com/rr-debugger/rr/issues/2284 maybe