Skip to content
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

handle plain exit for tasks #2939

Draft
wants to merge 2 commits into
base: master
Choose a base branch
from
Draft

Conversation

GitMensch
Copy link
Contributor

@GitMensch GitMensch commented Jul 22, 2021

fixes #2627, fixes #2640

Note: this definitely should get a code review (seeing the file's history I guess goes to @rocallahan), and likely also an adjustment of the comment in the code.

I've just tested a bit and found in the simple tests I've done (single thread, all child processes of the "inferior" are already finished) pass and that the "hang" is fixed, the record works and the replay is possible, too.

... but other programs (multiple shared objects loaded) do fail with (is that #2929 ?):

[FATAL /tmp/rr-master/src/RecordSession.cc:347:handle_seccomp_traced_syscall()]
 (task 13911 (rec:13911) at time 960)
 -> Assertion `patch_ok' failed to hold. The tracee issues a vsyscall to 0xffffffffff600400 but we failed to moneypatch the caller (return address 0x7fe28deb1ca5, sp=0x7ffc38c6b4b8). Recording will not succeed. Exiting.
Tail of trace dump:
{
  real_time:507685.886496 global_time:940, event:`SYSCALLBUF_FLUSH' tid:13911, ticks:4964637
  { syscall:'read', ret:0x63c, size:0x64c, desched:1 }
  { syscall:'read', ret:0x0, size:0x10, desched:1 }
  { syscall:'close', ret:0x0, size:0x10 }
}
{
  real_time:507685.886512 global_time:941, event:`SYSCALL: munmap' (state:ENTERING_SYSCALL) tid:13911, ticks:4964637
rax:0xffffffffffffffda rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0x0 rsi:0x1000 rdi:0x7fe29f896000 rbp:0xb rsp:0x681ffde0 r8:0x222cd00 r9:0x7fe29f884740 r10:0x0 r11:0x246 r12:0x0 r13:0x400 r14:0x7fe29f8846b0 r15:0x308b rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xb fs_base:0x7fe29f884740 gs_base:0x0
}
{
  real_time:507685.886521 global_time:942, event:`SYSCALLBUF_RESET' tid:13911, ticks:4964637
}
{
  real_time:507685.886590 global_time:943, event:`SYSCALL: munmap' (state:EXITING_SYSCALL) tid:13911, ticks:4964637
rax:0x0 rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0x0 rsi:0x1000 rdi:0x7fe29f896000 rbp:0xb rsp:0x681ffde0 r8:0x222cd00 r9:0x7fe29f884740 r10:0x0 r11:0x246 r12:0x0 r13:0x400 r14:0x7fe29f8846b0 r15:0x308b rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xb fs_base:0x7fe29f884740 gs_base:0x0
}
{
  real_time:507685.887015 global_time:944, event:`SYSCALLBUF_FLUSH' tid:13911, ticks:4966826
  { syscall:'open', ret:0xfffffffffffffffe, size:0x10, desched:1 }
  { syscall:'open', ret:0xfffffffffffffffe, size:0x10, desched:1 }
  { syscall:'open', ret:0xfffffffffffffffe, size:0x10, desched:1 }
  { syscall:'open', ret:0xfffffffffffffffe, size:0x10, desched:1 }
  { syscall:'open', ret:0xfffffffffffffffe, size:0x10, desched:1 }
  { syscall:'open', ret:0xfffffffffffffffe, size:0x10, desched:1 }
  { syscall:'open', ret:0xfffffffffffffffe, size:0x10, desched:1 }
  { syscall:'open', ret:0xfffffffffffffffe, size:0x10, desched:1 }
  { syscall:'open', ret:0xfffffffffffffffe, size:0x10, desched:1 }
  { syscall:'open', ret:0xfffffffffffffffe, size:0x10, desched:1 }
  { syscall:'open', ret:0x3, size:0x10, desched:1 }
  { syscall:'readlinkat', ret:0x10, size:0x20 }
  { syscall:'fstat', ret:0x0, size:0xa0 }
}
{
  real_time:507685.887033 global_time:945, event:`SYSCALL: mmap' (state:ENTERING_SYSCALL) tid:13911, ticks:4966826
rax:0xffffffffffffffda rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0x1 rsi:0xc6dd rdi:0x0 rbp:0x9 rsp:0x681ffde0 r8:0x3 r9:0x0 r10:0x2 r11:0x246 r12:0x2 r13:0x0 r14:0x3 r15:0x1 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x9 fs_base:0x7fe29f884740 gs_base:0x0
}
{
  real_time:507685.887042 global_time:946, event:`SYSCALLBUF_RESET' tid:13911, ticks:4966826
}
{
  real_time:507685.888248 global_time:947, event:`SYSCALL: mmap' (state:EXITING_SYSCALL) tid:13911, ticks:4966826
rax:0x7fe29f88a000 rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0x1 rsi:0xc6dd rdi:0x0 rbp:0x9 rsp:0x681ffde0 r8:0x3 r9:0x0 r10:0x2 r11:0x246 r12:0x2 r13:0x0 r14:0x3 r15:0x1 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x9 fs_base:0x7fe29f884740 gs_base:0x0
  { map_file:"/etc/ld.so.cache", addr:0x7fe29f88a000, length:0xd000, prot_flags:"r--p", file_offset:0x0, device:64768, inode:35678126, data_file:"", data_offset:0x0, file_size:0xc6dd }
  { tid:13911, addr:0x7fe29f88a000, length:0xc6dd }
}
{
  real_time:507685.888570 global_time:948, event:`SYSCALLBUF_FLUSH' tid:13911, ticks:4968050
  { syscall:'close', ret:0x0, size:0x10 }
  { syscall:'open', ret:0x3, size:0x10, desched:1 }
  { syscall:'readlinkat', ret:0x1a, size:0x2a }
  { syscall:'read', ret:0x340, size:0x350, desched:1 }
  { syscall:'fstat', ret:0x0, size:0xa0 }
}
{
  real_time:507685.888587 global_time:949, event:`SYSCALL: mmap' (state:ENTERING_SYSCALL) tid:13911, ticks:4968050
rax:0xffffffffffffffda rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0x5 rsi:0x208490 rdi:0x0 rbp:0x9 rsp:0x681ffde0 r8:0x3 r9:0x0 r10:0x802 r11:0x246 r12:0x802 r13:0x0 r14:0x3 r15:0x5 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x9 fs_base:0x7fe29f884740 gs_base:0x0
}
{
  real_time:507685.888597 global_time:950, event:`SYSCALLBUF_RESET' tid:13911, ticks:4968050
}
{
  real_time:507685.890664 global_time:951, event:`SYSCALL: mmap' (state:EXITING_SYSCALL) tid:13911, ticks:4968050
rax:0x7fe28deb0000 rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0x5 rsi:0x208490 rdi:0x0 rbp:0x9 rsp:0x681ffde0 r8:0x3 r9:0x0 r10:0x802 r11:0x246 r12:0x802 r13:0x0 r14:0x3 r15:0x5 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x9 fs_base:0x7fe29f884740 gs_base:0x0
  { map_file:"/usr/lib64/libnss_sss.so.2", addr:0x7fe28deb0000, length:0x209000, prot_flags:"r-xp", file_offset:0x0, device:64768, inode:588541, data_file:"/usr/lib64/libnss_sss.so.2", data_offset:0x0, file_size:0x9130 }
}
{
  real_time:507685.890926 global_time:952, event:`SYSCALLBUF_FLUSH' tid:13911, ticks:4968091
  { syscall:'mprotect', ret:0x0, size:0x10 }
}
{
  real_time:507685.890939 global_time:953, event:`SYSCALL: mmap' (state:ENTERING_SYSCALL) tid:13911, ticks:4968091
rax:0xffffffffffffffda rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0x3 rsi:0x2000 rdi:0x7fe28e0b7000 rbp:0x9 rsp:0x681ffde0 r8:0x3 r9:0x7000 r10:0x812 r11:0x246 r12:0x812 r13:0x7000 r14:0x3 r15:0x3 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x9 fs_base:0x7fe29f884740 gs_base:0x0
}
{
  real_time:507685.890947 global_time:954, event:`SYSCALLBUF_RESET' tid:13911, ticks:4968091
}
{
  real_time:507685.891034 global_time:955, event:`SYSCALL: mmap' (state:EXITING_SYSCALL) tid:13911, ticks:4968091
rax:0x7fe28e0b7000 rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0x3 rsi:0x2000 rdi:0x7fe28e0b7000 rbp:0x9 rsp:0x681ffde0 r8:0x3 r9:0x7000 r10:0x812 r11:0x246 r12:0x812 r13:0x7000 r14:0x3 r15:0x3 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x9 fs_base:0x7fe29f884740 gs_base:0x0
  { map_file:"/usr/lib64/libnss_sss.so.2", addr:0x7fe28e0b7000, length:0x2000, prot_flags:"rw-p", file_offset:0x7000, device:64768, inode:588541, data_file:"/usr/lib64/libnss_sss.so.2", data_offset:0x7000, file_size:0x9130 }
}
{
  real_time:507685.891284 global_time:956, event:`SYSCALLBUF_FLUSH' tid:13911, ticks:4973307
  { syscall:'close', ret:0x0, size:0x10 }
  { syscall:'mprotect', ret:0x0, size:0x10 }
}
{
  real_time:507685.891296 global_time:957, event:`SYSCALL: munmap' (state:ENTERING_SYSCALL) tid:13911, ticks:4973307
rax:0xffffffffffffffda rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0x0 rsi:0xc6dd rdi:0x7fe29f88a000 rbp:0xb rsp:0x681ffde0 r8:0x7fe29f8884c8 r9:0x7fe29f8884c8 r10:0x0 r11:0x246 r12:0x80000001 r13:0x7ffc38c6b6a0 r14:0x7ffc38c6e508 r15:0x2 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xb fs_base:0x7fe29f884740 gs_base:0x0
}
{
  real_time:507685.891303 global_time:958, event:`SYSCALLBUF_RESET' tid:13911, ticks:4973307
}
{
  real_time:507685.891357 global_time:959, event:`SYSCALL: munmap' (state:EXITING_SYSCALL) tid:13911, ticks:4973307
rax:0x0 rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0x0 rsi:0xc6dd rdi:0x7fe29f88a000 rbp:0xb rsp:0x681ffde0 r8:0x7fe29f8884c8 r9:0x7fe29f8884c8 r10:0x0 r11:0x246 r12:0x80000001 r13:0x7ffc38c6b6a0 r14:0x7ffc38c6e508 r15:0x2 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xb fs_base:0x7fe29f884740 gs_base:0x0
}
=== Start rr backtrace:
rr(_ZN2rr13dump_rr_stackEv+0x36)[0x9698ad]
rr(_ZN2rr9GdbServer15emergency_debugEPNS_4TaskE+0x168)[0x7bc696]
rr[0x7eadc9]
rr(_ZN2rr21EmergencyDebugOstreamD2Ev+0x5a)[0x7eafb4]
rr(_ZN2rr13RecordSession29handle_seccomp_traced_syscallEPNS_10RecordTaskEPNS0_9StepStateEPNS0_12RecordResultEPb+0x48c)[0x8264f0]
rr(_ZN2rr13RecordSession19handle_ptrace_eventEPPNS_10RecordTaskEPNS0_9StepStateEPNS0_12RecordResultEPb+0x324)[0x827558]
rr(_ZN2rr13RecordSession11record_stepEv+0x3a0)[0x82f126]
rr[0x822950]
rr(_ZN2rr13RecordCommand3runERSt6vectorINSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEESaIS7_EE+0x37d)[0x823493]
rr(main+0x22a)[0x982c7e]
/usr/lib64/libc.so.6(__libc_start_main+0xf5)[0x7f4b2a237555]
rr[0x725f39]
=== End rr backtrace

I have no clue if this is because of my change in this PR (then they shouldn't be merged) or if this is another issue (the please merge and let others test/fix on top of that)...

@khuey
Copy link
Collaborator

khuey commented Jul 22, 2021

Can you reproduce that? Can you attach gdb using the emergency debugger and disassemble the instructions around 0xffffffffff600400 ?

@GitMensch

This comment has been minimized.

@khuey
Copy link
Collaborator

khuey commented Jul 22, 2021

With gdb '-l' '10000' '-ex' 'set sysroot /' '-ex' 'target extended-remote 127.0.0.1:1155' /usr/local/bin/cobcrun:

(gdb) disassemble *0xffffffffff600400
Cannot access memory at address 0xffffffffff600400
(gdb) bt 6
#0  0x00007fa9c6b9a506 in _nc_first_db () from /usr/lib64/libtinfo.so.5
#1  0x00007fa9c6ba28fd in _nc_read_entry () from /usr/lib64/libtinfo.so.5
#2  0x00007fa9c6b9c829 in _nc_setup_tinfo () from /usr/lib64/libtinfo.so.5
#3  0x00007fa9c6b9cb72 in _nc_setupterm () from /usr/lib64/libtinfo.so.5
#4  0x00007fa9c6dc9dba in newterm () from /usr/lib64/libncursesw.so.5
#5  0x00007fa9c6dc6353 in initscr () from /usr/lib64/libncursesw.so.5
(More stack frames follow...)

Can you disassemble the first frame (_nc_first_db) here?

@GitMensch

This comment has been minimized.

@khuey
Copy link
Collaborator

khuey commented Jul 22, 2021

Ok ... I don't see what in there would make a vsyscall (at least not directly). What does x/50r $rsp-0x80 show?

@khuey
Copy link
Collaborator

khuey commented Jul 22, 2021

Hrm, sorry, actually x/1xg $rsp and then x/50r <whatever that printed> - 0x80

@GitMensch

This comment has been minimized.

@GitMensch

This comment has been minimized.

@khuey
Copy link
Collaborator

khuey commented Jul 22, 2021

Ok it looks like it's 0x00007fd3c8c98500 <+1040>: callq 0x7fd3c8c95b50 <time@plt> that's triggering the vsyscall, which makes some amount of sense. Can you disassemble time?

@GitMensch

This comment has been minimized.

@khuey
Copy link
Collaborator

khuey commented Jul 22, 2021

That sounds like a poem.

Or maybe a Christopher Nolan movie.

(gdb) disassemble time
Dump of assembler code for function time:
   0x00007fa5c9e0c5e0 <+0>:     sub    $0x28,%rsp
   0x00007fa5c9e0c5e4 <+4>:     lea    0xd23fd(%rip),%rax        # 0x7fa5c9ede9e8
   0x00007fa5c9e0c5eb <+11>:    lea    0xd38c1(%rip),%rdi        # 0x7fa5c9edfeb3
   0x00007fa5c9e0c5f2 <+18>:    mov    %rsp,%rsi
   0x00007fa5c9e0c5f5 <+21>:    movl   $0x1,0xc(%rsp)
   0x00007fa5c9e0c5fd <+29>:    movl   $0x3ae75f6,0x8(%rsp)
   0x00007fa5c9e0c605 <+37>:    mov    %rax,(%rsp)
   0x00007fa5c9e0c609 <+41>:    movq   $0x0,0x10(%rsp)
   0x00007fa5c9e0c612 <+50>:    callq  0x7fa5c9e950f0 <_dl_vdso_vsym>
   0x00007fa5c9e0c617 <+55>:    mov    $0xffffffffff600400,%rdx
   0x00007fa5c9e0c61e <+62>:    test   %rax,%rax
   0x00007fa5c9e0c621 <+65>:    cmovne %rax,%rdx
   0x00007fa5c9e0c625 <+69>:    add    $0x28,%rsp
   0x00007fa5c9e0c629 <+73>:    mov    %rdx,%rax
   0x00007fa5c9e0c62c <+76>:    retq
End of assembler dump.

This doesn't make a lot of sense to me. The vsyscall address (0xffffffffff600400) is here but we don't ever call it?

@GitMensch
Copy link
Contributor Author

Or maybe a Christopher Nolan movie.

Totally!

This doesn't make a lot of sense to me. The vsyscall address (0xffffffffff600400) is here but we don't ever call it?

Now we're both on the same page... and now? [side note: that still doesn't seem related to the PR ;-) ]

@khuey
Copy link
Collaborator

khuey commented Jul 22, 2021

No this has nothing to do with your PR but I'd still like to get to the bottom of it, because this is the third report we've had of it in a week and you're the most responsive reporter so far :)

If you readelf -s <your libc> | grep time, is the time symbol an IFUNC symbol? that would explain this.

@GitMensch

This comment has been minimized.

@khuey
Copy link
Collaborator

khuey commented Jul 22, 2021

Very last question! What is the output of disassemble time@plt?

@GitMensch

This comment has been minimized.

@rocallahan
Copy link
Collaborator

Looks like there is no VDSO present on this system, hence the vsyscall was selected. That is very old stuff that I don't want to worry about supporting ... though it could be done if we really wanted to or someone wanted to contribute it. Basically if we can't monkeypatch the vsyscall and restart it, instead we would emulate the vsyscalls in rr via AutoRemoteSyscall.

@rocallahan
Copy link
Collaborator

As for the actual patch here, this is very tricky code. What is supposed to happen if the task is already exited, is that waitpid will return ECHILD, in which case wait_exit just ends without doing anything and that should be fine.

So I don't want to accept this patch, at least not without a very clear explanation of why the current code doesn't work and how the new code fixes it.

@GitMensch
Copy link
Contributor Author

So I don't want to accept this patch, at least not without a very clear explanation of why the current code doesn't work and how the new code fixes it.

I don't know more about why it works that way, just have recognized that with the old code the actual process stood at "defunc" and rr waiting "forever" (I waited only 4 minutes) to return from waitid, without ever coming back.
Changing it to include WEXITED lead to the process coming back with the status 0 (I'd have checked for the, "correct" code value, but that event code is replaced by zero); and in the zero/exit state there is no more cleanup to do.

@GitMensch

This comment has been minimized.

@rocallahan
Copy link
Collaborator

I don't know more about why it works that way, just have recognized that with the old code the actual process stood at "defunc" and rr waiting "forever" (I waited only 4 minutes) to return from waitid, without ever coming back.

Is this with the 3.10 kernel? Possibly the kernel behavior changed at some point.

@GitMensch
Copy link
Contributor Author

Is this with the 3.10 kernel? Possibly the kernel behavior changed at some point.

Yes. Should we query the kernel version and make that conditional?

@rocallahan
Copy link
Collaborator

Where can I read more about "monkeypatch"?

Monkeypatcher.cc

Do you mean instead of the assert a plain check should be done and then a different code be executed (code to emulate( - or would this be just deferred to the runtime)?

A check with different code to be executed if we can't patch the site.

Is there an example for this otherwise I can copy and adjust? In this case I could give it a try.

Not really no. Like a lot of rr, this is not easy at all. Whoever fixes this will need to understand exactly how vsyscalls work, and learn to understand AutoRemoteSyscall and other rr machinery.

@rocallahan
Copy link
Collaborator

rocallahan commented Jul 22, 2021

Yes. Should we query the kernel version and make that conditional?

No, I don't want to add stuff for a kernel version we don't officially support. I mean, maybe we could hack around this, but missing PTRACE_SETSIGMASK means things are still pretty broken, so what's the point.

@GitMensch
Copy link
Contributor Author

Not really no. Like a lot of rr, this is not easy at all. Whoever fixes this will need to understand exactly how vsyscalls work, and learn to understand AutoRemoteSyscall and other rr machinery.

Can you please create a reasonable issue with enough information about that (the one above should be fine) so that we have it in one place - and can close the others that are related as duplicate?

@rocallahan
Copy link
Collaborator

I'll add info to #2929.

@GitMensch
Copy link
Contributor Author

I mean, maybe we could hack around this, but missing PTRACE_SETSIGMASK means things are still pretty broken, so what's the point.

PTRACE_SETSIGMASK is available with kernel 3.11 - are you sure that the current task tearddown code would work without the suggested changes with a 3.11 kernel? If not, then this would still be useful.

... and after the patch different simple programs actually work fine for record and replay on kernel 3.10.

@rocallahan
Copy link
Collaborator

rocallahan commented Jul 22, 2021

PTRACE_SETSIGMASK is available with kernel 3.11 - are you sure that the current task tearddown code would work without the suggested changes with a 3.11 kernel? If not, then this would still be useful.

It would only be useful if there are actual users using 3.11 and hitting this bug. (And if this patch is actually correct, which is not clear yet.)

@GitMensch
Copy link
Contributor Author

if this patch is actually correct, which is not clear yet

I totally agree on this part, the only thing I can say is: works here better than the current version (which always lead to "inferior hang" at its process exit, while this version exits cleanly and seems to also record correct as the replay is possible - but because of the vsyscall issue only simple tests are covered so far). Is there anything else I can do or should we handle this as a "stale PR"?

@GitMensch

This comment has been minimized.

@GitMensch
Copy link
Contributor Author

GitMensch commented Jul 23, 2021

Looks like there is no VDSO present on this system, hence the vsyscall was selected.

@rocallahan How did you get to this conclusion?

(gdb) !ldd  /usr/lib64/libtinfo.so.5
        linux-vdso.so.1 =>  (0x00007ffc54bf7000)
        libc.so.6 => /usr/lib64/libc.so.6 (0x00007f4529bb1000)
        /lib64/ld-linux-x86-64.so.2 (0x00007f452a1a9000)
(gdb) !ldd /usr/lib64/libnss_sss.so.2
        linux-vdso.so.1 =>  (0x00007fff634f6000)
        libdl.so.2 => /usr/lib64/libdl.so.2 (0x00007f665f4e7000)
        libc.so.6 => /usr/lib64/libc.so.6 (0x00007f665f119000)
        /lib64/ld-linux-x86-64.so.2 (0x00007f665f8f4000)

So vDSO "in general" is available in both cases from above.

If something is missing in this area would a libc preload be useful or "nothing but a kernel update" (I guess at least at the minor version number, so nothing that will happen for the LTS RHEL7/CentOS7)?

@rocallahan
Copy link
Collaborator

@khuey identified the vsyscall bug and fixed it here: 8a15f2a
So pull that and rerun the tests if you like.

works here better than the current version (which always lead to "inferior hang" at its process exit, while this version exits cleanly and seems to also record correct as the replay is possible - but because of the vsyscall issue only simple tests are covered so far)

This isn't enough to land a patch. We need to understand the problem we're fixing, why the patch fixes it, and why it makes rr's invariants stronger or at least not weaker. And even than, adding complexity to fix one testcase on a distro release where rr mostly doesn't work for other reasons is probably not worthwhile.

@GitMensch
Copy link
Contributor Author

@khuey identified the vsyscall bug and fixed it here: 8a15f2a
So pull that and rerun the tests if you like.

Did that and recording works like a charm now, even with a much more complex scenario. Replay of the simple and medium tests now work fine; the complex one fails on replay, I'll create an issue for that later.

@GitMensch
Copy link
Contributor Author

GitMensch commented Dec 29, 2021

The original point of this issue got a bit "hijacked", I've cleaned the post unrelated to the main issue - the actual pr - as those are resolved with later versions of RR. It may be reasonable if others could do the same.

I've also checked again and found 4e10088 to be the origin of this code, coming from @Keno - but I have no idea if there's something he can do here (possibly share some wisdom outside of the comment).

A small recap of the state of this PR:

  • the original code added by Keno does not do what the comment says with the old, now unsupported kernel 3.10 - because WSTOPPED actually does wait forever in every case, while this does not happen with WEXITED.
  • when both are used (and the ptrace exit event is checked later, which is what this PR uses) it works both with the old kernel and the new one for most cases
  • when running the test cases on the old kernel (new not tested yet) there are a bunch of tests that again hang at the "last" call of wait_exit() -> waitid()

"last" means:

PID   PPID CMD
873   872  rr --suppress-environment-warnings --check-cached-mmaps --fatal-errors --resource-path=/
879   873  ./fd_cleanup-YIdUBAHVE
881   879  [fd_cleanup-YIdU] <defunct>

--> attached to rr into wait_exit(), tid == 881, waitid()returns immediately, then going into the new code of "already exited", with continue in gdb landing in wait_exit() again, as expected now with tid == 879, ps shows that the PID 881 does not exist any more and there are no PIDs below 879 which is now defunc

PID   PPID CMD
873   872  rr --suppress-environment-warnings --check-cached-mmaps --fatal-errors --resource-path=/
879   873  [./fd_cleanup-YIdUBAHVE] <defunct>

but this time the call to waitid() does not return (or only returns when WNOHANG is added, which is wrong for all other cases).

Any insights or ideas appreciated.

@Keno
Copy link
Member

Keno commented Dec 29, 2021

The comment seems pretty clear that this will hang in a particular situation. Have you validated that it does not for a particular reason? I don't remember all the details, but I do remember thinking this through pretty carefully and this being the only option. I may have overlooked something, but I'd need to see some evidence that the problem in the comment is resolved. This kind of code you really need to develop while staring at the kernel wait code at the same time.

@GitMensch
Copy link
Contributor Author

GitMensch commented Dec 29, 2021

The issue with the old kernel and old ode is that it always hangs. With the new code it hangs sometimes with the old kernel.

@Keno
Copy link
Member

Keno commented Dec 29, 2021

Right, I'm suggesting with the new code it will sometimes hang in the new kernel also.

@GitMensch
Copy link
Contributor Author

GitMensch commented Dec 29, 2021

Rechecked: the "some still hanging" tests after the patch and the old kernel also hang with the new kernel.

I've already tested a bit more than I planned, the only thing that seems to work in this case with the old (and new) kernel is to use WNOHANG instead of WEXITED, check for the si_pid == 0 (= no return) and then query "something" afterwards - I just didn't find that something...

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

rr hangs on RHEL7 rr record is stuck and doesnt proceed
4 participants