[PATCH v3 3/3][RFC] Speed up next/step while debugging multithreaded programs on AIX.

[Aditya Vidyadhar Kamath <akamath996@gmail.com>]

From: Aditya Vidyadhar Kamath <aditya.kamath1@ibm.com>

During go compiler debugging on AIX my collegue and I noticed that
the next command was pretty slow compared to Linux - around 7 seconds
per step when program has atleast 3 or more threads running. Debugging
10 - 12 line function took around a minute. In compiler codes this is
slow.

To measure this properly I wrote a benchmark pasted below. The program spawns
3 worker threads , then stops inside a function with 10 simple
that GDB steps over one by one. The GDB batch script breaks at that
function and issues 10 next commands and then quits. Timing the whole
run gives a fair picture of how much overhead each next carries.
Both the .c file and batch file are pasted below.

Before this patch, on AIX 7.3 ppc64 with 20 background threads:

real    1m10.05s
user    0m17.59s
sys     0m20.43s

That is roughly 7 seconds per `next` step.

After this patch:

real    0m20.37s
user    0m5.94s
sys     0m6.53s

About 2 seconds per step.  3.5x faster for the same workload.

Every stop including single-step traps from next/step called
pd_update(), which unconditionally ran pthdb_session_update() followed
by sync_threadlists().  The scoped_time_it instrumentation added in the
previous commit shows that the entire cost is in sync_threadlists(),
dominated by the first pthdb_pthread(PTHDB_LIST_FIRST) call.

This cost is the same regardless of thread count.
So it is a fixed per-stop overhead paid on every single-step trap.

During a next/step sequence I assume,
the stepped thread is running a single instruction, so it cannot call
pthread_create or pthread_exit.  It is therefore safe to skip both
pthdb_session_update() and sync_threadlists() when we know this stop
is the result of a software single-step.

In AIX, single-stepping is implemented in software: GDB inserts
breakpoints at the next instruction before resuming with step=0.
A completed software single-step and a user breakpoint both arrive as
TARGET_WAITKIND_STOPPED/GDB_SIGNAL_TRAP and are otherwise
indistinguishable at the target layer.  The only reliable indicator is
whether single-step breakpoints were inserted for the resumed thread
just before the resume.  Which the code is doing.

For now this patch is request for comment / draft. Once feedback is
recieved from maintainers I will remove this paragraph and benchmark results
pasted below.

==================
Benchmark program (bench_next.c):

    /* Spawns NUM_THREADS worker threads that spin, then steps through
       10 assignments in do_steps() so GDB can time each next.

       Also tests two scenarios from the bug report:
         1. "next" over a call that spawns a thread (spawn_thread_here()).
         2. A background thread exits while "next" is in progress
            (exit_thread_here()).  */
    #include <stdio.h>
    #include <stdlib.h>
    #include <pthread.h>
    #include <unistd.h>

    #ifndef NUM_THREADS
    #define NUM_THREADS 3
    #endif

    static volatile int keep_running = 1;
    static volatile int extra_thread_started = 0;

    static void *
    worker (void *arg)
    {
      while (keep_running)
        sched_yield ();
      return NULL;
    }

    /* Thread that exits on its own after signalling it has started.  */
    static void *
    short_lived (void *arg)
    {
      extra_thread_started = 1;
      return NULL;
    }

    /* GDB will "next" over this call -- a new thread is spawned inside.  */
    static void
    spawn_thread_here (void)
    {
      pthread_t t;
      pthread_create (&t, NULL, short_lived, NULL);
      pthread_join (t, NULL);
    }

    /* GDB will "next" over this call -- the short-lived background thread
       is in the process of exiting while we step.  */
    static void
    exit_thread_here (void)
    {
      /* Just a visible marker so GDB can stop here.  */
      volatile int x = 42;
      (void)x;
    }

    void
    do_steps (void)
    {
      volatile int a = 1;
      volatile int b = 2;
      volatile int c = a + b;
      volatile int d = c * 2;
      volatile int e = d - a;
      volatile int f = e + c;
      volatile int g = f / 2;
      volatile int h = g + 1;
      volatile int i2 = h * h;
      volatile int j = i2 - b;
      (void)j;
    }

    int
    main (void)
    {
      pthread_t threads[NUM_THREADS];
      pthread_t bg;
      int i;

      /* Start background spinning threads.  */
      for (i = 0; i < NUM_THREADS; i++)
        pthread_create (&threads[i], NULL, worker, NULL);

      /* Next over a call that spawns a thread */
      spawn_thread_here ();

      /* Next while a background thread is exiting
         Launch a thread that exits quickly; "next" through exit_thread_here()
         while that exit is in flight.  */
      pthread_create (&bg, NULL, short_lived, NULL);
      exit_thread_here ();
      pthread_join (bg, NULL);

      do_steps ();

      keep_running = 0;
      for (i = 0; i < NUM_THREADS; i++)
        pthread_join (threads[i], NULL);

      return 0;
    }

====================
Build done with
gcc -O0 -g -gdwarf -maix64 -DNUM_THREADS=3 -o bench_next_bin bench_next.c -lpthread
=====================
GDB batch script (bench_next.gdb):

    set pagination off
    set confirm off
    maintenance set per-command time on

    # Scenario 1: next over a call that spawns a thread
    break spawn_thread_here
    run
    next

    # Scenario 2: next while a background thread is exiting
    break exit_thread_here
    continue
    next

    break do_steps
    continue

    next
    next
    next
    next
    next
    next
    next
    next
    next
    next

    quit
========================
Then run,
time gdb -batch -x bench_next.gdb ./bench_next_bin

=========================================
Time for "pthdb_session_update": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "sync_threadlists": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pthdb_session_update": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "sync_threadlists": wall 0.941, user 0.094, sys 0.096, user+sys 0.190, 20.2 % CPU
Time for "pd_update total": wall 0.941, user 0.094, sys 0.096, user+sys 0.190, 20.2 % CPU
25        volatile int a = 1;
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pthdb_session_update": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "sync_threadlists": wall 0.938, user 0.093, sys 0.096, user+sys 0.189, 20.1 % CPU
Time for "pd_update total": wall 0.938, user 0.093, sys 0.096, user+sys 0.189, 20.1 % CPU
26        volatile int b = 2;
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pthdb_session_update": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "sync_threadlists": wall 1.149, user 0.082, sys 0.090, user+sys 0.172, 15.0 % CPU
Time for "pd_update total": wall 1.149, user 0.082, sys 0.090, user+sys 0.172, 15.0 % CPU
27        volatile int c = a + b;
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pthdb_session_update": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "sync_threadlists": wall 1.262, user 0.075, sys 0.087, user+sys 0.162, 12.8 % CPU
Time for "pd_update total": wall 1.262, user 0.075, sys 0.087, user+sys 0.162, 12.8 % CPU
28        volatile int d = c * 2;
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pthdb_session_update": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "sync_threadlists": wall 1.281, user 0.078, sys 0.091, user+sys 0.169, 13.2 % CPU
Time for "pd_update total": wall 1.281, user 0.078, sys 0.091, user+sys 0.169, 13.2 % CPU
29        volatile int e = d - a;
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pthdb_session_update": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "sync_threadlists": wall 1.264, user 0.076, sys 0.087, user+sys 0.163, 12.9 % CPU
Time for "pd_update total": wall 1.264, user 0.076, sys 0.087, user+sys 0.163, 12.9 % CPU
30        volatile int f = e + c;
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pthdb_session_update": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "sync_threadlists": wall 1.262, user 0.075, sys 0.086, user+sys 0.161, 12.8 % CPU
Time for "pd_update total": wall 1.262, user 0.075, sys 0.086, user+sys 0.161, 12.8 % CPU
31        volatile int g = f / 2;
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pthdb_session_update": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "sync_threadlists": wall 1.220, user 0.086, sys 0.098, user+sys 0.184, 15.1 % CPU
Time for "pd_update total": wall 1.220, user 0.086, sys 0.098, user+sys 0.184, 15.1 % CPU
32        volatile int h = g + 1;
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pthdb_session_update": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "sync_threadlists": wall 1.071, user 0.091, sys 0.098, user+sys 0.189, 17.6 % CPU
Time for "pd_update total": wall 1.071, user 0.091, sys 0.098, user+sys 0.189, 17.6 % CPU
33        volatile int i2 = h * h;
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pthdb_session_update": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "sync_threadlists": wall 1.276, user 0.077, sys 0.089, user+sys 0.166, 13.0 % CPU
Time for "pd_update total": wall 1.276, user 0.077, sys 0.089, user+sys 0.166, 13.0 % CPU
34        volatile int j = i2 - b;
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pd_update total": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "pthdb_session_update": wall 0.000, user 0.000, sys 0.000, user+sys 0.000, NaNQ % CPU
Time for "sync_threadlists": wall 1.278, user 0.077, sys 0.091, user+sys 0.168, 13.1 % CPU
Time for "pd_update total": wall 1.278, user 0.077, sys 0.091, user+sys 0.168, 13.1 % CPU

real    0m20.29s
user    0m2.01s
sys     0m2.59s
---
 gdb/aix-thread.c | 75 ++++++++++++++++++++++++++++++++++++------------
 1 file changed, 57 insertions(+), 18 deletions(-)

diff --git a/gdb/aix-thread.c b/gdb/aix-thread.c
index 2355f87db54..72a26153aae 100644
--- a/gdb/aix-thread.c
+++ b/gdb/aix-thread.c
@@ -165,6 +165,11 @@ static pthdb_callbacks_t pd_callbacks = {
 /* Aix variable structure.  */
 struct aix_thread_variables
 {
+  aix_thread_variables ()
+    : pd_able (0), pd_active (0), pd_session (0), pd_brk_addr (0),
+      arch64 (0), last_resume_step (0)
+  {}
+
   /* Whether the current application is debuggable by pthdb.  */
   int pd_able;
 
@@ -184,6 +189,14 @@ struct aix_thread_variables
 
   /* Describes the number of thread exit events reported.  */
   std::unordered_set<pthdb_pthread_t> exited_threads;
+
+  /* Set to non-zero by resume() when the resume was a software
+     single-step, i.e. single-step breakpoints were inserted for the
+     resumed thread before the inferior was set running.  Cleared to
+     zero for any other kind of resume.  Used by wait() to distinguish
+     a SIGTRAP from a completed single-step from one caused by a
+     breakpoint, since both look identical at the signal level.  */
+  int last_resume_step;
 };
 
 /* Key to our per-inferior data.  */
@@ -854,11 +867,16 @@ sync_threadlists (pid_t pid)
 
 /* Synchronize libpthdebug's state with the inferior and with GDB,
    generate a composite process/thread <pid> for the current thread,
-   Return the ptid of the event thread if one can be found, else
-   return a pid-only ptid with PID.  */
+   return the ptid of the event thread if one can be found, else
+   return a pid-only ptid with PID.
+
+   STEP_STOP is non-zero when the stop is known to be a completed
+   single-step (software single-step breakpoint trap) for a single
+   thread.  In that case pthdb_session_update() and sync_threadlists()
+   are skipped because the thread population cannot have changed.  */
 
 static ptid_t
-pd_update (pid_t pid)
+pd_update (pid_t pid, bool step_stop = false)
 {
   int status;
   ptid_t ptid;
@@ -873,20 +891,23 @@ pd_update (pid_t pid)
 
   scoped_time_it total_time_it ("pd_update total");
 
-  {
-    scoped_time_it time_it ("pthdb_session_update");
-    status = pthdb_session_update (data->pd_session);
-  }
-  if (status != PTHDB_SUCCESS)
-    return ptid_t (pid);
-
-  /* Attempt to sync_threadlists () only when debugging object files
-     and not core files since list of threads never change for core
-     files.  */
-  if (target_has_execution ())
+  if (!step_stop)
     {
-      scoped_time_it time_it ("sync_threadlists");
-      sync_threadlists (pid);
+      {
+	scoped_time_it time_it ("pthdb_session_update");
+	status = pthdb_session_update (data->pd_session);
+      }
+      if (status != PTHDB_SUCCESS)
+	return ptid_t (pid);
+
+      /* Attempt to sync_threadlists () only when debugging object
+	 files and not core files since list of threads never change
+	 for core files.  */
+      if (target_has_execution ())
+	{
+	  scoped_time_it time_it ("sync_threadlists");
+	  sync_threadlists (pid);
+	}
     }
 
   /* Define "current thread" as one that just received a trap signal.  */
@@ -920,7 +941,10 @@ pd_activate (pid_t pid)
 			       PTHDB_FLAG_REGS, &pd_callbacks,
 			       &data->pd_session);
   if (status == PTHDB_SUCCESS)
-    data->pd_active = 1;
+    {
+      data->pd_active = 1;
+      data->last_resume_step = 0;
+    }
 }
 
 /* AIX implementation of update_thread_list.  */
@@ -1057,6 +1081,11 @@ aix_thread_target::resume (ptid_t ptid, int step, enum gdb_signal sig)
 
   if (ptid.tid () == 0)
     {
+      /* Resuming all threads: we cannot attribute a single-step to any
+	 one thread, so clear the flag.  */
+      if (data != nullptr)
+	data->last_resume_step = 0;
+
       scoped_restore save_inferior_ptid = make_scoped_restore (&inferior_ptid);
 
       inferior_ptid = ptid_t (inferior_ptid.pid ());
@@ -1069,6 +1098,10 @@ aix_thread_target::resume (ptid_t ptid, int step, enum gdb_signal sig)
 	error (_("aix-thread resume: unknown pthread %ld"),
 	       ptid.lwp ());
 
+      if (data != nullptr)
+	data->last_resume_step
+	  = thread_has_single_step_breakpoints_set (thread);
+
       aix_thread_info *priv = get_aix_thread_info (thread);
 
       tid[0] = ptid.lwp ();
@@ -1124,7 +1157,13 @@ aix_thread_target::wait (ptid_t ptid, struct target_waitstatus *status,
 	pd_activate (ptid.pid ());
     }
 
-  return pd_update (ptid.pid ());
+  /* A SIGTRAP stop after a software single-step is a completed step:
+     the thread population cannot have changed, so skip the expensive
+     pthdb_session_update() and sync_threadlists() calls.  */
+  bool step_stop = (data->last_resume_step
+		    && status->kind () == TARGET_WAITKIND_STOPPED
+		    && status->sig () == GDB_SIGNAL_TRAP);
+  return pd_update (ptid.pid (), step_stop);
 }
 
 /* Supply AIX altivec registers, both 64 and 32 bit.  */
-- 
2.51.2