From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from simark.ca by simark.ca with LMTP id gtVlNd/oqmo8bRMAWB0awg (envelope-from ) for ; Wed, 16 Sep 2026 15:07:11 -0400 Authentication-Results: simark.ca; dkim=pass (2048-bit key; unprotected) header.d=polymtl.ca header.i=@polymtl.ca header.a=rsa-sha256 header.s=oct2025 header.b=VWI8oDzE; dkim-atps=neutral Received: by simark.ca (Postfix, from userid 112) id BB16E1E06B; Wed, 16 Sep 2026 15:07:11 -0400 (EDT) X-Spam-Checker-Version: SpamAssassin 4.0.1 (2024-03-25) on simark.ca X-Spam-Level: X-Spam-Status: No, score=-5.4 required=5.0 tests=ARC_SIGNED,ARC_VALID,BAYES_00, DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,MAILING_LIST_MULTI, RCVD_IN_DNSWL_MED autolearn=ham autolearn_force=no version=4.0.1 Received: from vm01.sourceware.org (vm01.sourceware.org [IPv6:2620:52:6:3111::32]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange x25519 server-signature ECDSA (prime256v1) server-digest SHA256) (No client certificate requested) by simark.ca (Postfix) with ESMTPS id DFDD81E01F for ; Wed, 16 Sep 2026 15:07:09 -0400 (EDT) Received: from vm01.sourceware.org (localhost [IPv6:::1]) by sourceware.org (Postfix) with ESMTP id 714FC4BA7992 for ; Wed, 16 Sep 2026 19:07:08 +0000 (GMT) DKIM-Filter: OpenDKIM Filter v2.11.0 sourceware.org 714FC4BA7992 Authentication-Results: sourceware.org; dkim=pass (2048-bit key, unprotected) header.d=polymtl.ca header.i=@polymtl.ca header.a=rsa-sha256 header.s=oct2025 header.b=VWI8oDzE Received: from smtp.polymtl.ca (smtp.polymtl.ca [132.207.4.11]) by sourceware.org (Postfix) with ESMTPS id 322C64BA2E10 for ; Wed, 16 Sep 2026 19:06:41 +0000 (GMT) DMARC-Filter: OpenDMARC Filter v1.4.2 sourceware.org 322C64BA2E10 Authentication-Results: sourceware.org; dmarc=pass (p=none dis=none) header.from=polymtl.ca Authentication-Results: sourceware.org; spf=pass smtp.mailfrom=polymtl.ca ARC-Filter: OpenARC Filter v1.0.0 sourceware.org 322C64BA2E10 Authentication-Results: sourceware.org; arc=none smtp.remote-ip=132.207.4.11 ARC-Seal: i=1; a=rsa-sha256; d=sourceware.org; s=key; t=1789585601; cv=none; b=MJqnPpOJciajwbXq32/El9VsYrANOo0LFveBXvbfT8lOUhGuPuOf2RPc625l6QOckSJoMC2nFQsDz/XCVmlhDBajqCeH0g+CwiSP06pbKY8SZQa3zmTJX0lzdn9wUMWtqozw7jsePYK0j0wf5wxlgInKbQ5eLyzkYFzCvh+ML6E= ARC-Message-Signature: i=1; a=rsa-sha256; d=sourceware.org; s=key; t=1789585601; c=relaxed/simple; bh=n6C/cM7LANSPhEj1CzPBpcf5LHBEOR0KfdrsRyq6TlY=; h=DKIM-Signature:Message-ID:Date:MIME-Version:Subject:To:From; b=m8+9cmVSY90cTBN8FPBWZyYEYua82vAMumWw6iayiaeRRcYpqhyPL+C1NhcKul5Bk081rIyYkAUwQ+IY+9tO5JUI1hR8fIcEalwNxVqOgELhLkqrevughqM0fsUly9slRJbcBdyw9ma1JdpYaow3axR3SgiALaOdDkhNFmvzej4= ARC-Authentication-Results: i=1; sourceware.org; dkim=pass (2048-bit key, unprotected) header.d=polymtl.ca header.i=@polymtl.ca header.a=rsa-sha256 header.s=oct2025 header.b=VWI8oDzE DKIM-Filter: OpenDKIM Filter v2.11.0 sourceware.org 322C64BA2E10 Received: from simark.ca (simark.ca [158.69.221.121]) (authenticated bits=0) by smtp.polymtl.ca (8.14.7/8.14.7) with ESMTP id 68GJ6Us3005466 (version=TLSv1/SSLv3 cipher=ECDHE-RSA-AES256-GCM-SHA384 bits=256 verify=NOT); Wed, 16 Sep 2026 15:06:35 -0400 DKIM-Filter: OpenDKIM Filter v2.11.0 smtp.polymtl.ca 68GJ6Us3005466 DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=polymtl.ca; s=oct2025; t=1789585597; bh=naOwneE9N2X/BvHv6Stq5SdCiwjoZJ8gR0B+agDEC9s=; h=Date:Subject:To:Cc:From:In-Reply-To:From; b=VWI8oDzECy5+oHJIBLDegBNlJQsrJjb5dNAFMQDRAW5zmjWzltnlmk0KiFm5YnWUv dc1dUVAT3Qu+Lq61QrAAvhRCoqzT6Oq5ShYBhnA5zLXjR0a9DZNQrUBHK0Pd9xsVTy 0JRDnocTFuvYLHhqKLhuD1wQui7kNk9ptr2DhQPeIcNsGY1rQPur9UzHvCuVIITVdZ zXC6Gp5m6WLK3FpXNHes5CGCFqUj/o879uDKpwXKKcNL6o8yIuAHDPfdnvWNyUwqDf /kDu2IBtKPbPy8gmrYFaPfI61O0nlflFiFIZ2lWlY4m5yC93P/jYfnLxM4zdLfsYI6 HMzV/1xXcWnSg== Received: by simark.ca (Postfix) id F08DF1E01F; Wed, 16 Sep 2026 15:06:29 -0400 (EDT) Message-ID: Date: Wed, 16 Sep 2026 15:06:29 -0400 MIME-Version: 1.0 User-Agent: Mozilla Thunderbird Subject: Re: [PATCH v3 3/3][RFC] Speed up next/step while debugging multithreaded programs on AIX. To: Aditya Vidyadhar Kamath , ulrich.weigand@de.ibm.com, tom@tromey.com Cc: gdb-patches@sourceware.org, Aditya.Kamath1@ibm.com, sangamesh.swamy@in.ibm.com References: <20260916114931.17516-3-akamath996@gmail.com> Content-Language: en-US From: Simon Marchi In-Reply-To: <20260916114931.17516-3-akamath996@gmail.com> Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 7bit X-Poly-FromMTA: (simark.ca [158.69.221.121]) at Wed, 16 Sep 2026 19:06:30 +0000 X-BeenThere: gdb-patches@sourceware.org X-Mailman-Version: 2.1.30 Precedence: list List-Id: Gdb-patches mailing list List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: gdb-patches-bounces~public-inbox=simark.ca@sourceware.org On 2026-09-16 07:49, Aditya Vidyadhar Kamath wrote: > From: Aditya Vidyadhar Kamath > > 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 "10 simple" what? > 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. Again, I am not sure that's true. There is certainly one single instruction (possibly a syscall) inside pthread_create that commits the thread creation, after which the new thread will be visible. If you single-step that instruction, you'll have one more thread after stepping than you had before. And with "set scheduler-locking off", threads other than the one being stepped run freely during the step. One of those threads could exit during your instruction single step, so you'd miss that. If you know that new threads can only appear during a syscall instruction (I have no idea, just speculating), then you could perhaps check what is the instruction about to be stepped. If it's not a syscall instruction, and if the scheduler-locking setting is "on" or "step" (nothing else than this thread will run during the step), then perhaps it would be safe to skip the thread update. But you'd have to check how it really works under the hood. > 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. Regardless of the problems I stated above: do you actually need to record this during resume? Couldn't you check thread_has_single_step_breakpoints_set in wait to know if the signalled thread has single-step breakpoints set? I assume it would still return true, because infrun wouldn't have removed it yet. > 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 > #include > #include > #include > > #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 When you show benchmark numbers, you should show both the before and after numbers. The after numbers in isolation mean nothing. Also, try to trim the logs a bit to make it easier to understand for others. You don't need to paste 10 steps, just choose one that is representative. You also mentioned above that the especially costly call was the first pthdb_pthread one, but it doesn't even appear in this log, even though there is a "scoped_time_it" for it. > 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) > + {} Initialize the fields directly where they are declared in the struct, like this: /* Whether the current application is debuggable by pthdb. */ int pd_able = 0; /* Whether a threaded application is being debugged. */ int pd_active = 0; Is it an existing bug that the existing fields are not initialized? This structure is allocated by registry::try_emplace, and I don't see anything that zeroes the structure. In any case that could be a patch that you could send separately, it should be trivial. And while at it, some of these fields could be changed from int to bool. > @@ -184,6 +189,14 @@ struct aix_thread_variables > > /* Describes the number of thread exit events reported. */ > std::unordered_set 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; This should be a bool, and the comment should read "Set to true" instead of "non-zero". Simon