Fix internal error and improve 'set debug infrun 1'/target wait kind trace
authorPhilippe Waroquiers <philippe.waroquiers@skynet.be>
Sun, 24 Mar 2019 14:14:55 +0000 (15:14 +0100)
committerPhilippe Waroquiers <philippe.waroquiers@skynet.be>
Mon, 1 Apr 2019 18:51:59 +0000 (20:51 +0200)
The test  gdb.threads/watchthreads-reorder.exp verifies that the
'set debug infrun 1' debug output does not crash GDB.

Under high load, the test can still cause a GDB internal error (see details
below).

This patch fixes this crash, and improves/factorises some wait kind traces.

Tested on debian/amd64 + run one test with 'set debug infrun 1'.

Changes compared to the first version:
  * Handles the suggestions of Kevin to trace the relevant elements
    of the wait status (this is done by calling target_waitstatus_to_string).
  * Some other changes to factorise wait status tracing.

Note that using target_waitstatus_to_string instead of the 'locally printed'
status kind strings means that debug trace that was using strings such as:
   "EXITED" or "TARGET_WAITKIND_EXITED"
will now use what is printed by target_waitstatus_to_string e.g.
   "exited".

gdb/ChangeLog
2019-04-01  Philippe Waroquiers  <philippe.waroquiers@skynet.be>

* infrun.c (stop_all_threads): If debug_infrun, always
trace the wait status after wait_one, using
target_waitstatus_to_string and target_pid_to_str.
(handle_inferior_event): Replace various trace of
wait status kind by a single trace.
* gdb/gnu-nat.c (gnu_nat_target::wait): Replace local
wait status kind image by target_waitstatus_to_string.
* target/waitstatus.c (target_waitstatus_to_string): Fix
obsolete comment.

  (top-gdb) bt
  #0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
  #1  0x00007f3d54a0642a in __GI_abort () at abort.c:89
  #2  0x0000555c24c60e66 in dump_core () at ../../fixleaks/gdb/utils.c:201
  #3  0x0000555c24c63d49 in internal_vproblem(internal_problem *, const char *, int, const char *, typedef __va_list_tag __va_list_tag *) (problem=problem@entry=0x555c25338d40 <internal_error_problem>, file=<optimized out>, line=287,
      fmt=<optimized out>, ap=<optimized out>) at ../../fixleaks/gdb/utils.c:411
  #4  0x0000555c24c63eab in internal_verror (file=<optimized out>, line=<optimized out>, fmt=<optimized out>,
      ap=<optimized out>) at ../../fixleaks/gdb/utils.c:436
  #5  0x0000555c249e8c22 in internal_error (file=file@entry=0x555c24e0f2ad "../../fixleaks/gdb/inferior.c",
      line=line@entry=287, fmt=<optimized out>) at ../../fixleaks/gdb/common/errors.c:55
  #6  0x0000555c247d3f5c in find_inferior_pid (pid=<optimized out>) at ../../fixleaks/gdb/inferior.c:287
  #7  0x0000555c24ad2248 in find_inferior_pid (pid=<optimized out>) at ../../fixleaks/gdb/inferior.c:302
  #8  find_inferior_ptid (ptid=...) at ../../fixleaks/gdb/inferior.c:301
  #9  0x0000555c24c35f25 in find_thread_ptid (ptid=...) at ../../fixleaks/gdb/thread.c:522
  #10 0x0000555c24b0ab4d in thread_db_target::pid_to_str[abi:cxx11](ptid_t) (
      this=0x555c2532e3e0 <the_thread_db_target>, ptid=...) at ../../fixleaks/gdb/linux-thread-db.c:1637
  #11 0x0000555c24c2f420 in target_pid_to_str[abi:cxx11](ptid_t) (ptid=...) at ../../fixleaks/gdb/target.c:2083
  #12 0x0000555c24ad9cab in stop_all_threads () at ../../fixleaks/gdb/infrun.c:4373
  #13 0x0000555c24ada00f in stop_waiting (ecs=<optimized out>) at ../../fixleaks/gdb/infrun.c:7464
  #14 0x0000555c24adc401 in process_event_stop_test (ecs=ecs@entry=0x7ffc9402d9d0) at ../../fixleaks/gdb/infrun.c:6181
  ...
  (top-gdb) fr 12
  #12 0x0000555c24ad9cab in stop_all_threads () at ../../fixleaks/gdb/infrun.c:4373
  (top-gdb) p event_ptid
  $5 = {m_pid = 25419, m_lwp = 25427, m_tid = 0}
  (top-gdb) p ptid
  $6 = {m_pid = 0, m_lwp = 0, m_tid = 0}
  (top-gdb) p ws
  $7 = {kind = TARGET_WAITKIND_THREAD_EXITED, value = {integer = 0, sig = GDB_SIGNAL_0, related_pid = {m_pid = 0,
        m_lwp = 0, m_tid = 0}, execd_pathname = 0x0, syscall_number = 0}}
  (top-gdb)

The gdb.log corresponding to the above crash is:
  (gdb) PASS: gdb.threads/watchthreads-reorder.exp: reorder1: set debug infrun 1
  continue
  Continuing.
  infrun: clear_proceed_status_thread (Thread 0x7ffff7fcfb40 (LWP 25419))
  infrun: clear_proceed_status_thread (Thread 0x7ffff7310700 (LWP 25427))
  infrun: clear_proceed_status_thread (Thread 0x7ffff6b0f700 (LWP 25428))
  infrun: proceed (addr=0xffffffffffffffff, signal=GDB_SIGNAL_DEFAULT)
  infrun: proceed: resuming Thread 0x7ffff7fcfb40 (LWP 25419)
  infrun: resume (step=0, signal=GDB_SIGNAL_0), trap_expected=0, current thread [Thread 0x7ffff7fcfb40 (LWP 25419)] at 0x7ffff7344317
  infrun: infrun_async(1)
  infrun: prepare_to_wait
  infrun: proceed: resuming Thread 0x7ffff7310700 (LWP 25427)
  infrun: resume (step=0, signal=GDB_SIGNAL_0), trap_expected=0, current thread [Thread 0x7ffff7310700 (LWP 25427)] at 0x5555555553d7
  infrun: prepare_to_wait
  infrun: proceed: resuming Thread 0x7ffff6b0f700 (LWP 25428)
  infrun: resume (step=0, signal=GDB_SIGNAL_0), trap_expected=0, current thread [Thread 0x7ffff6b0f700 (LWP 25428)] at 0x5555555554c8
  infrun: prepare_to_wait
  infrun: target_wait (-1.0.0, status) =
  infrun:   -1.0.0 [process -1],
  infrun:   status->kind = ignore
  infrun: TARGET_WAITKIND_IGNORE
  infrun: prepare_to_wait
  Joining the threads.
  [Thread 0x7ffff6b0f700 (LWP 25428) exited]
  infrun: target_wait (-1.0.0, status) =
  infrun:   -1.0.0 [process -1],
  infrun:   status->kind = ignore
  infrun: TARGET_WAITKIND_IGNORE
  infrun: prepare_to_wait
  infrun: target_wait (-1.0.0, status) =
  infrun:   25419.25419.0 [Thread 0x7ffff7fcfb40 (LWP 25419)],
  infrun:   status->kind = stopped, signal = GDB_SIGNAL_TRAP
  infrun: TARGET_WAITKIND_STOPPED
  infrun: stop_pc = 0x555555555e50
  infrun: context switch
  infrun: Switching context from Thread 0x7ffff6b0f700 (LWP 25428) to Thread 0x7ffff7fcfb40 (LWP 25419)
  infrun: BPSTAT_WHAT_STOP_NOISY
  infrun: stop_waiting
  infrun: stop_all_threads
  infrun: stop_all_threads, pass=0, iterations=0
  infrun:   Thread 0x7ffff7fcfb40 (LWP 25419) not executing
  infrun:   Thread 0x7ffff7310700 (LWP 25427) executing, need stop
  [Thread 0x7ffff7310700 (LWP 25427) exited]
  infrun: target_wait (-1.0.0, status) =
  infrun:   25419.25427.0 [LWP 25427],
  infrun:   status->kind = thread exited, status = 0
  infrun: infrun_async(0)
  ../../fixleaks/gdb/inferior.c:287: internal-error: inferior* find_inferior_pid(int): Assertion `pid != 0' failed.
  A problem internal to GDB has been detected,
  further debugging may prove unreliable.
  Quit this debugging session? (y or n) FAIL: gdb.threads/watchthreads-reorder.exp: reorder1: continue to breakpoint: break-at-exit (GDB internal error)
  Resyncing due to internal error.
  n
  infrun: infrun_async(1)

  This is a bug, please report it.  For instructions, see:
  <http://www.gnu.org/software/gdb/bugs/>.

  infrun: infrun_async(0)
  ../../fixleaks/gdb/inferior.c:287: internal-error: inferior* find_inferior_pid(int): Assertion `pid != 0' failed.
  A problem internal to GDB has been detected,
  further debugging may prove unreliable.
  Create a core file of GDB? (y or n) y

gdb/ChangeLog
gdb/gnu-nat.c
gdb/infrun.c
gdb/target/waitstatus.c

index f3f30b1aa4c64ce630da6e190dcb9a54f69ee189..ce9c573a8ef73632ee3ce2d858bbf94eed41dfb2 100644 (file)
@@ -1,3 +1,15 @@
+2019-04-01  Philippe Waroquiers  <philippe.waroquiers@skynet.be>
+
+       * infrun.c (stop_all_threads): If debug_infrun, always
+       trace the wait status after wait_one, using
+       target_waitstatus_to_string and target_pid_to_str.
+       (handle_inferior_event): Replace various trace of
+       wait status kind by a single trace.
+       * gdb/gnu-nat.c (gnu_nat_target::wait): Replace local
+       wait status kind image by target_waitstatus_to_string.
+       * target/waitstatus.c (target_waitstatus_to_string): Fix
+       obsolete comment.
+
 2019-04-01  Tom Tromey  <tromey@adacore.com>
 
        PR symtab/23331:
index c1fafed156efc81f0971e8e8c6b6fa4cab200aef..654a652717008d1fd210d652f17516d7313b9b2f 100644 (file)
@@ -1647,15 +1647,9 @@ rewait:
       inf_update_suspends (inf);
     }
 
-  inf_debug (inf, "returning ptid = %s, status = %s (%d)",
+  inf_debug (inf, "returning ptid = %s, %s",
             target_pid_to_str (ptid).c_str (),
-            status->kind == TARGET_WAITKIND_EXITED ? "EXITED"
-            : status->kind == TARGET_WAITKIND_STOPPED ? "STOPPED"
-            : status->kind == TARGET_WAITKIND_SIGNALLED ? "SIGNALLED"
-            : status->kind == TARGET_WAITKIND_LOADED ? "LOADED"
-            : status->kind == TARGET_WAITKIND_SPURIOUS ? "SPURIOUS"
-            : "?",
-            status->value.integer);
+            target_waitstatus_to_string (&status).c_str ());
 
   return ptid;
 }
index 0cfa2d6825d57a5a01568598c421f537e6fb792d..282674116973a7bd0d18a493f2149f2284b82124 100644 (file)
@@ -4358,24 +4358,21 @@ stop_all_threads (void)
            pass = -1;
 
          event_ptid = wait_one (&ws);
-
-         if (ws.kind == TARGET_WAITKIND_NO_RESUMED)
+         if (debug_infrun)
            {
-             /* All resumed threads exited.  */
+             fprintf_unfiltered (gdb_stdlog,
+                                 "infrun: stop_all_threads %s %s\n",
+                                 target_waitstatus_to_string (&ws).c_str (),
+                                 target_pid_to_str (event_ptid).c_str ());
            }
-         else if (ws.kind == TARGET_WAITKIND_THREAD_EXITED
-                  || ws.kind == TARGET_WAITKIND_EXITED
-                  || ws.kind == TARGET_WAITKIND_SIGNALLED)
-           {
-             if (debug_infrun)
-               {
-                 ptid_t ptid = ptid_t (ws.value.integer);
 
-                 fprintf_unfiltered (gdb_stdlog,
-                                     "infrun: %s exited while "
-                                     "stopping threads\n",
-                                     target_pid_to_str (ptid).c_str ());
-               }
+         if (ws.kind == TARGET_WAITKIND_NO_RESUMED
+             || ws.kind == TARGET_WAITKIND_THREAD_EXITED
+             || ws.kind == TARGET_WAITKIND_EXITED
+             || ws.kind == TARGET_WAITKIND_SIGNALLED)
+           {
+             /* All resumed threads exited
+                or one thread/process exited/signalled.  */
            }
          else
            {
@@ -4604,6 +4601,10 @@ handle_inferior_event (struct execution_control_state *ecs)
 
   enum stop_kind stop_soon;
 
+  if (debug_infrun)
+    fprintf_unfiltered (gdb_stdlog, "infrun: handle_inferior_event %s\n",
+                       target_waitstatus_to_string (&ecs->ws).c_str ());
+
   if (ecs->ws.kind == TARGET_WAITKIND_IGNORE)
     {
       /* We had an event in the inferior, but we are not interested in
@@ -4615,16 +4616,12 @@ handle_inferior_event (struct execution_control_state *ecs)
         not stopped, and we are ignoring the event.  Another possible
         circumstance is any event which the lower level knows will be
         reported multiple times without an intervening resume.  */
-      if (debug_infrun)
-       fprintf_unfiltered (gdb_stdlog, "infrun: TARGET_WAITKIND_IGNORE\n");
       prepare_to_wait (ecs);
       return;
     }
 
   if (ecs->ws.kind == TARGET_WAITKIND_THREAD_EXITED)
     {
-      if (debug_infrun)
-       fprintf_unfiltered (gdb_stdlog, "infrun: TARGET_WAITKIND_THREAD_EXITED\n");
       prepare_to_wait (ecs);
       return;
     }
@@ -4643,9 +4640,6 @@ handle_inferior_event (struct execution_control_state *ecs)
     {
       /* No unwaited-for children left.  IOW, all resumed children
         have exited.  */
-      if (debug_infrun)
-       fprintf_unfiltered (gdb_stdlog, "infrun: TARGET_WAITKIND_NO_RESUMED\n");
-
       stop_print_frame = 0;
       stop_waiting (ecs);
       return;
@@ -4738,8 +4732,6 @@ handle_inferior_event (struct execution_control_state *ecs)
   switch (ecs->ws.kind)
     {
     case TARGET_WAITKIND_LOADED:
-      if (debug_infrun)
-        fprintf_unfiltered (gdb_stdlog, "infrun: TARGET_WAITKIND_LOADED\n");
       context_switch (ecs);
       /* Ignore gracefully during startup of the inferior, as it might
          be the shell which has just loaded some objects, otherwise
@@ -4817,8 +4809,6 @@ handle_inferior_event (struct execution_control_state *ecs)
                      _("unhandled stop_soon: %d"), (int) stop_soon);
 
     case TARGET_WAITKIND_SPURIOUS:
-      if (debug_infrun)
-        fprintf_unfiltered (gdb_stdlog, "infrun: TARGET_WAITKIND_SPURIOUS\n");
       if (handle_stop_requested (ecs))
        return;
       context_switch (ecs);
@@ -4827,8 +4817,6 @@ handle_inferior_event (struct execution_control_state *ecs)
       return;
 
     case TARGET_WAITKIND_THREAD_CREATED:
-      if (debug_infrun)
-        fprintf_unfiltered (gdb_stdlog, "infrun: TARGET_WAITKIND_THREAD_CREATED\n");
       if (handle_stop_requested (ecs))
        return;
       context_switch (ecs);
@@ -4838,16 +4826,6 @@ handle_inferior_event (struct execution_control_state *ecs)
 
     case TARGET_WAITKIND_EXITED:
     case TARGET_WAITKIND_SIGNALLED:
-      if (debug_infrun)
-       {
-         if (ecs->ws.kind == TARGET_WAITKIND_EXITED)
-           fprintf_unfiltered (gdb_stdlog,
-                               "infrun: TARGET_WAITKIND_EXITED\n");
-         else
-           fprintf_unfiltered (gdb_stdlog,
-                               "infrun: TARGET_WAITKIND_SIGNALLED\n");
-       }
-
       inferior_ptid = ecs->ptid;
       set_current_inferior (find_inferior_ptid (ecs->ptid));
       set_current_program_space (current_inferior ()->pspace);
@@ -4912,14 +4890,6 @@ Cannot fill $_exitsignal with the correct signal number.\n"));
          the above cases end in a continue or goto.  */
     case TARGET_WAITKIND_FORKED:
     case TARGET_WAITKIND_VFORKED:
-      if (debug_infrun)
-       {
-         if (ecs->ws.kind == TARGET_WAITKIND_FORKED)
-           fprintf_unfiltered (gdb_stdlog, "infrun: TARGET_WAITKIND_FORKED\n");
-         else
-           fprintf_unfiltered (gdb_stdlog, "infrun: TARGET_WAITKIND_VFORKED\n");
-       }
-
       /* Check whether the inferior is displaced stepping.  */
       {
        struct regcache *regcache = get_thread_regcache (ecs->event_thread);
@@ -5080,10 +5050,6 @@ Cannot fill $_exitsignal with the correct signal number.\n"));
       /* Done with the shared memory region.  Re-insert breakpoints in
         the parent, and keep going.  */
 
-      if (debug_infrun)
-       fprintf_unfiltered (gdb_stdlog,
-                           "infrun: TARGET_WAITKIND_VFORK_DONE\n");
-
       context_switch (ecs);
 
       current_inferior ()->waiting_for_vfork_done = 0;
@@ -5098,8 +5064,6 @@ Cannot fill $_exitsignal with the correct signal number.\n"));
       return;
 
     case TARGET_WAITKIND_EXECD:
-      if (debug_infrun)
-        fprintf_unfiltered (gdb_stdlog, "infrun: TARGET_WAITKIND_EXECD\n");
 
       /* Note we can't read registers yet (the stop_pc), because we
         don't yet know the inferior's post-exec architecture.
@@ -5148,9 +5112,6 @@ Cannot fill $_exitsignal with the correct signal number.\n"));
       /* Be careful not to try to gather much state about a thread
          that's in a syscall.  It's frequently a losing proposition.  */
     case TARGET_WAITKIND_SYSCALL_ENTRY:
-      if (debug_infrun)
-        fprintf_unfiltered (gdb_stdlog,
-                           "infrun: TARGET_WAITKIND_SYSCALL_ENTRY\n");
       /* Getting the current syscall number.  */
       if (handle_syscall_event (ecs) == 0)
        process_event_stop_test (ecs);
@@ -5162,22 +5123,15 @@ Cannot fill $_exitsignal with the correct signal number.\n"));
          syscall.  Stepping one instruction seems to get it back
          into user code.)  */
     case TARGET_WAITKIND_SYSCALL_RETURN:
-      if (debug_infrun)
-        fprintf_unfiltered (gdb_stdlog,
-                           "infrun: TARGET_WAITKIND_SYSCALL_RETURN\n");
       if (handle_syscall_event (ecs) == 0)
        process_event_stop_test (ecs);
       return;
 
     case TARGET_WAITKIND_STOPPED:
-      if (debug_infrun)
-        fprintf_unfiltered (gdb_stdlog, "infrun: TARGET_WAITKIND_STOPPED\n");
       handle_signal_stop (ecs);
       return;
 
     case TARGET_WAITKIND_NO_HISTORY:
-      if (debug_infrun)
-        fprintf_unfiltered (gdb_stdlog, "infrun: TARGET_WAITKIND_NO_HISTORY\n");
       /* Reverse execution: target ran out of history info.  */
 
       /* Switch to the stopped thread.  */
index 4ac98e50f4f2ef3bed6cfa030a51dbc4928e5916..f86ce223739f5b01477622097c16341c7faf6d6a 100644 (file)
@@ -20,8 +20,7 @@
 #include "common/common-defs.h"
 #include "waitstatus.h"
 
-/* Return a pretty printed form of target_waitstatus.
-   Space for the result is malloc'd, caller must free.  */
+/* Return a pretty printed form of target_waitstatus.  */
 
 std::string
 target_waitstatus_to_string (const struct target_waitstatus *ws)