Re: [PATCH] Tighten gdb.base/disp-step-syscall.exp

[Pedro Alves <palves at redhat dot com>]

On 03/03/2015 06:20 AM, Breazeal, Don wrote:

> infrun: target_wait (-1, status) =^M
> infrun:   6486 [process 6486],^M
> infrun:   status->kind = vforked^M
> infrun: TARGET_WAITKIND_VFORKED^M
> Detaching after vfork from child process 6837.^M
> sigchld^M
> LCFF: waiting for VFORK_DONE on 6486^M
> infrun: resume : clear step^M
> infrun: resume (step=0, signal=GDB_SIGNAL_0), trap_expected=0, current
> thread [process 6486] at 0x2aaaaaffcf04^M
> LLR: Preparing to resume process 6486, 0, inferior_ptid process 6486^M
> LLR: PTRACE_CONT process 6486, 0 (resume event thread)^M
> infrun: prepare_to_wait^M
> linux_nat_wait: [process -1], [TARGET_WNOHANG]^M
> LLW: enter^M
> LNW: waitpid(-1, ...) returned 0, No child processes^M
> LLW: exit (ignore)^M
> infrun: target_wait (-1, status) =^M
> infrun:   -1 [process -1],^M
> infrun:   status->kind = ignore^M
> infrun: TARGET_WAITKIND_IGNORE^M
> infrun: prepare_to_wait^M
> FAIL: gdb.base/disp-step-syscall.exp: vfork: stepi vfork insn (timeout)
> testcase
> /scratch/dbreazea/sandbox/gdb-with-exec-6/binutils-gdb/gdb/testsuite/gdb.base/disp-step-syscall.exp
> completed in 21 seconds
> 

Odd.  Quite possibly a kernel bug.  Looks like ptrace never
reports the VFORK_DONE, or it does but SIGCHLD was never generated
and thus we got stuck in the event loop.

>>
>> Unfortunately, with your full series applied, I get this:
>>
>>  (gdb) PASS: gdb.base/disp-step-syscall.exp: vfork: get hexadecimal valueof "$pc"
>>  stepi
>>  Detaching from process 29944
>>  Killing process(es): 29942 29944
>>  /home/pedro/gdb/mygit/src/gdb/gdbserver/linux-low.c:998: A problem internal to GDBserver has been detected.
>>  kill_wait_lwp: Assertion `res > 0' failed.
>>  /home/pedro/gdb/mygit/src/gdb/thread.c:1182: internal-error: switch_to_thread: Assertion `inf != NULL' failed.
>>  A problem internal to GDB has been detected,
>>  further debugging may prove unreliable.
>>  Quit this debugging session? (y or n) FAIL: gdb.base/disp-step-syscall.exp: vfork: stepi vfork insn (GDB internal error)
>>  Resyncing due to internal error.
>>  n
> 
> With the two patches below applied, disp-step-syscall.exp passes
> consistently for me using native-extended-gdbserver on x86_64 Ubuntu
> 10.04 and Ubuntu 14.04.  I haven't looked (yet) at how your patches
> might have caused this change in behavior, or at how I might be able to
> reproduce the failure you are seeing.

TBC, I get the internal errors (F20, x86_64) without my patches too.
The only difference is that without my patches the FAIL is following by
slow timeouts:

 Running /home/pedro/gdb/mygit/src/gdb/testsuite/gdb.base/disp-step-syscall.exp ...
 FAIL: gdb.base/disp-step-syscall.exp: vfork: stepi vfork insn (GDB internal error)
 FAIL: gdb.base/disp-step-syscall.exp: vfork: get hexadecimal valueof "$pc" (timeout)
 FAIL: gdb.base/disp-step-syscall.exp: vfork: continue to vfork (3rd time) (GDB internal error)
 FAIL: gdb.base/disp-step-syscall.exp: vfork: continue to syscall insn vfork (the program is no longer running)

> 
> I have seen the "inf != NULL" assertion before, when stopped at a remote
> fork/vfork catchpoint and executing "info threads".  In that case
> gdbserver was reporting the new thread created by the fork.  It was
> added to the host-side thread list, but the new inferior had not been
> created yet on the host side.  That specific scenario should be
> prevented now in the remote follow fork patch series by not reporting
> the forked child's thread until the follow_fork has been completed. (If
> I am remembering that right.)

Adding infrun/remote logging, I see:

infrun: target_wait (-1, status) =
infrun:   26217 [Thread 26217.26217],
infrun:   status->kind = vforked
infrun: TARGET_WAITKIND_VFORKED
Sending packet: $z0,400624,1#63...Packet received: OK
Sending packet: $z0,3b36603966,1#6f...Packet received: OK
Sending packet: $z0,3b36613970,1#6b...Packet received: OK
Sending packet: $z0,3b36614891,1#6e...Packet received: OK
Sending packet: $z0,3b36abc9c0,1#23...Packet received: OK
Detaching after vfork from child process 26219.
Sending packet: $D;666b#83...Detaching from process 26219
Killing process(es): 26217 26219
/home/pedro/gdb/mygit/src/gdb/gdbserver/linux-low.c:998: A problem internal to GDBserver has been detected.
kill_wait_lwp: Assertion `res > 0' failed.
Packet received: E01
/home/pedro/gdb/mygit/src/gdb/thread.c:1182: internal-error: switch_to_thread: Assertion `inf != NULL' failed.
A problem internal to GDB has been detected,
further debugging may prove unreliable.
Quit this debugging session? (y or n) FAIL: gdb.base/disp-step-syscall.exp: vfork: stepi vfork insn (GDB internal error)
Resyncing due to internal error.


The backtrace:

...
#2  0x000000000041451e in internal_verror (file=0x456008 "/home/pedro/gdb/mygit/src/gdb/gdbserver/linux-low.c", line=998, fmt=0x455fe6 "%s: Assertion `%s' failed.",
    args=0x7fff7b828258) at /home/pedro/gdb/mygit/src/gdb/gdbserver/utils.c:106
#3  0x0000000000426ea8 in internal_error (file=0x456008 "/home/pedro/gdb/mygit/src/gdb/gdbserver/linux-low.c", line=998, fmt=0x455fe6 "%s: Assertion `%s' failed.")
    at /home/pedro/gdb/mygit/src/gdb/gdbserver/../common/errors.c:55
#4  0x00000000004293cb in kill_wait_lwp (lwp=0x14a38b0) at /home/pedro/gdb/mygit/src/gdb/gdbserver/linux-low.c:998
#5  0x0000000000429543 in linux_kill (pid=26624) at /home/pedro/gdb/mygit/src/gdb/gdbserver/linux-low.c:1050
#6  0x00000000004140ea in kill_inferior (pid=26624) at /home/pedro/gdb/mygit/src/gdb/gdbserver/target.c:219
#7  0x00000000004110e1 in detach_or_kill_inferior_callback (entry=0x14a2ad0) at /home/pedro/gdb/mygit/src/gdb/gdbserver/server.c:3087
#8  0x00000000004064da in for_each_inferior (list=0x670110 <all_processes>, action=0x41107f <detach_or_kill_inferior_callback>)
    at /home/pedro/gdb/mygit/src/gdb/gdbserver/inferiors.c:55
#9  0x0000000000411258 in detach_or_kill_for_exit () at /home/pedro/gdb/mygit/src/gdb/gdbserver/server.c:3148
#10 0x0000000000411295 in detach_or_kill_for_exit_cleanup (ignore=0x0) at /home/pedro/gdb/mygit/src/gdb/gdbserver/server.c:3163
#11 0x0000000000427178 in do_my_cleanups (pmy_chain=0x668938 <cleanup_chain>, old_chain=0x44c440 <sentinel_cleanup>)
    at /home/pedro/gdb/mygit/src/gdb/gdbserver/../common/cleanups.c:155
#12 0x00000000004271e5 in do_cleanups (old_chain=0x44c440 <sentinel_cleanup>) at /home/pedro/gdb/mygit/src/gdb/gdbserver/../common/cleanups.c:177
#13 0x00000000004276bf in throw_exception (exception=...) at /home/pedro/gdb/mygit/src/gdb/gdbserver/../common/common-exceptions.c:215
#14 0x0000000000427843 in throw_it (reason=RETURN_ERROR, error=GENERIC_ERROR, fmt=0x4480e7 "%s.", ap=0x7fff7b828648)
    at /home/pedro/gdb/mygit/src/gdb/gdbserver/../common/common-exceptions.c:274
#15 0x000000000042786d in throw_verror (error=GENERIC_ERROR, fmt=0x4480e7 "%s.", ap=0x7fff7b828648)
    at /home/pedro/gdb/mygit/src/gdb/gdbserver/../common/common-exceptions.c:280
#16 0x0000000000414456 in verror (string=0x4480e7 "%s.", args=0x7fff7b828648) at /home/pedro/gdb/mygit/src/gdb/gdbserver/utils.c:85
#17 0x0000000000426e00 in error (fmt=0x4480e7 "%s.") at /home/pedro/gdb/mygit/src/gdb/gdbserver/../common/errors.c:43
#18 0x0000000000414431 in perror_with_name (string=0x4435a6 "Can't determine port") at /home/pedro/gdb/mygit/src/gdb/gdbserver/utils.c:71
#19 0x0000000000407e49 in remote_open (name=0x7fff7b82a6fc ":2347") at /home/pedro/gdb/mygit/src/gdb/gdbserver/remote-utils.c:389
#20 0x0000000000411b12 in captured_main (argc=4, argv=0x7fff7b828a68) at /home/pedro/gdb/mygit/src/gdb/gdbserver/server.c:3414
#21 0x0000000000411ca2 in main (argc=4, argv=0x7fff7b828a68) at /home/pedro/gdb/mygit/src/gdb/gdbserver/server.c:3490
...

Seems like gdb disconnects, and we end up in remote_open again.
Then probably due to --once (the list descriptor is closed), that
fails and throws, which runs the "kill or detach everything" cleanup
(detach_or_kill_for_exit_cleanup).  And that ends up in your new
code here:

static int
linux_kill (int pid)
{
  struct process_info *process;
  struct lwp_info *lwp;
  struct target_waitstatus last;
  ptid_t last_ptid;

  /* If we're stopped while forking and we haven't followed yet,
     kill the child task.  We need to do this first because the
     parent will be sleeping if this is a vfork.  */

  get_last_target_status (&last_ptid, &last);

  if (last.kind == TARGET_WAITKIND_FORKED
      || last.kind == TARGET_WAITKIND_VFORKED)
    {
      lwp = find_lwp_pid (last.value.related_pid);
      gdb_assert (lwp != NULL);
      kill_wait_lwp (lwp);
      process = find_process_pid (ptid_get_pid (last.value.related_pid));
      the_target->mourn (process);
    }

trying to kill the vfork child.

Really get_last_target_status is not a good idea.  It's broken
on the native side already, and adding it to gdbserver too is
not a good idea.  E.g., consider scheduler-locking or non-stop.
Other events on other processes/threads can easily happen
and thus overwrite the last target status, before something
decides to kill the fork parent.

Thanks,
Pedro Alves