From c6115b5eacda61abe76b05f610eea38eb3dbbfb3 Mon Sep 17 00:00:00 2001 From: Tom de Vries Date: Tue, 3 Jun 2025 08:59:58 +0200 Subject: [PATCH] [gdb/cli] Use captured per_command_time in worker threads With test-case gdb.base/maint.exp, I ran into: ... (gdb) file maint^M Reading symbols from maint...^M (gdb) mt set per-command on^M (gdb) Time for "DWARF indexing worker": ...^M Time for "DWARF indexing worker": ...^M Time for "DWARF indexing worker": ...^M Time for "DWARF indexing worker": ...^M Time for "DWARF skeletonless type units": ...^M Time for "DWARF add parent map": ...^M Time for "DWARF finalize worker": ...^M Time for "DWARF finalize worker": ...^M Time for "DWARF finalize worker": ...^M Time for "DWARF finalize worker": ...^M Time for "DWARF finalize worker": ...^M FAIL: $exp: warnings: per-command: mt set per-command on (timeout) mt set per-command off^M 2025-05-31 09:33:44.711 - command started^M (gdb) PASS: $exp: warnings: per-command: mt set per-command off ... I didn't manage to reproduce this by rerunning the test-case, but it's fairly easy to reproduce using a file with more debug info, for instance gdb: ... $ gdb -q -batch -ex "file build/gdb/gdb" -ex "mt set per-command on" ... Due to the default "mt dwarf synchronous" == off, the file command starts building the cooked index in the background, and returns immediately without waiting for the result. The subsequent "mt set per-command on" implies "mt set per-command time on", which switches on displaying of per-command execution time. The "Time for" lines are the result of those two commands, but these lines shouldn't be there because "mt per-command time" == off at the point of issuing the file command. Fix this by capturing the per_command_time variable, and using the captured value instead. Tested on x86_64-linux. Approved-By: Simon Marchi PR cli/33039 Bug: https://sourceware.org/bugzilla/show_bug.cgi?id=33039 --- gdb/dwarf2/cooked-index-worker.c | 2 +- gdb/dwarf2/cooked-index-worker.h | 13 +++++++++++-- gdb/dwarf2/cooked-index.c | 3 ++- gdb/dwarf2/read.c | 4 ++-- gdb/maint.c | 8 ++++---- gdb/maint.h | 6 +++++- 6 files changed, 25 insertions(+), 11 deletions(-) diff --git a/gdb/dwarf2/cooked-index-worker.c b/gdb/dwarf2/cooked-index-worker.c index 5d7fc462a05..09d80eff629 100644 --- a/gdb/dwarf2/cooked-index-worker.c +++ b/gdb/dwarf2/cooked-index-worker.c @@ -246,7 +246,7 @@ void cooked_index_worker::done_reading () { { - scoped_time_it time_it ("DWARF add parent map"); + scoped_time_it time_it ("DWARF add parent map", m_per_command_time); for (auto &one_result : m_results) m_all_parents_map.add_map (*one_result.get_parent_map ()); diff --git a/gdb/dwarf2/cooked-index-worker.h b/gdb/dwarf2/cooked-index-worker.h index c68620578cc..8b9766cddcb 100644 --- a/gdb/dwarf2/cooked-index-worker.h +++ b/gdb/dwarf2/cooked-index-worker.h @@ -25,6 +25,8 @@ #include "dwarf2/cooked-index-shard.h" #include "dwarf2/types.h" #include "dwarf2/read.h" +#include "maint.h" +#include "run-on-main-thread.h" #if CXX_STD_THREAD #include @@ -216,8 +218,12 @@ public: explicit cooked_index_worker (dwarf2_per_objfile *per_objfile) : m_per_objfile (per_objfile), - m_cache_store (global_index_cache, per_objfile->per_bfd) - { } + m_cache_store (global_index_cache, per_objfile->per_bfd), + m_per_command_time (per_command_time) + { + /* Make sure we capture per_command_time from the main thread. */ + gdb_assert (is_main_thread ()); + } virtual ~cooked_index_worker () { } DISABLE_COPY_AND_ASSIGN (cooked_index_worker); @@ -307,6 +313,9 @@ protected: std::optional m_failed; /* An object used to write to the index cache. */ index_cache_store_context m_cache_store; + + /* Captured value of per_command_time. */ + bool m_per_command_time; }; using cooked_index_worker_up = std::unique_ptr; diff --git a/gdb/dwarf2/cooked-index.c b/gdb/dwarf2/cooked-index.c index 2c7e31e5676..7232f286a40 100644 --- a/gdb/dwarf2/cooked-index.c +++ b/gdb/dwarf2/cooked-index.c @@ -104,7 +104,8 @@ cooked_index::set_contents () const parent_map_map *parent_maps = m_state->get_parent_map_map (); finalizers.add_task ([=] () { - scoped_time_it time_it ("DWARF finalize worker"); + scoped_time_it time_it ("DWARF finalize worker", + m_state->m_per_command_time); this_shard->finalize (parent_maps); }); } diff --git a/gdb/dwarf2/read.c b/gdb/dwarf2/read.c index b178dacbe3d..d3d0d4c303e 100644 --- a/gdb/dwarf2/read.c +++ b/gdb/dwarf2/read.c @@ -3464,7 +3464,7 @@ void cooked_index_worker_debug_info::process_skeletonless_type_units (dwarf2_per_objfile *per_objfile, cooked_index_worker_result *storage) { - scoped_time_it time_it ("DWARF skeletonless type units"); + scoped_time_it time_it ("DWARF skeletonless type units", m_per_command_time); /* Skeletonless TUs in DWP files without .gdb_index is not supported yet. */ if (per_objfile->per_bfd->dwp_file == nullptr) @@ -3573,7 +3573,7 @@ cooked_index_worker_debug_info::do_reading () gdb_assert (iter != last); workers.add_task ([this, task_count, iter, last] () { - scoped_time_it time_it ("DWARF indexing worker"); + scoped_time_it time_it ("DWARF indexing worker", m_per_command_time); process_units (task_count, iter, last); }); diff --git a/gdb/maint.c b/gdb/maint.c index e017d05ef41..49a308d36e2 100644 --- a/gdb/maint.c +++ b/gdb/maint.c @@ -920,9 +920,9 @@ maintenance_show_worker_threads (struct ui_file *file, int from_tty, } -/* If true, display time usage both at startup and for each command. */ +/* See maint.h. */ -static bool per_command_time; +bool per_command_time; /* If true, display space usage both at startup and for each command. */ @@ -1175,8 +1175,8 @@ per-thread run time information not available on this platform")); /* See maint.h. */ -scoped_time_it::scoped_time_it (const char *what) - : m_enabled (per_command_time), +scoped_time_it::scoped_time_it (const char *what, bool enabled) + : m_enabled (enabled), m_what (what), m_start_wall (m_enabled ? std::chrono::steady_clock::now () diff --git a/gdb/maint.h b/gdb/maint.h index 28e6280a464..cccb6f60354 100644 --- a/gdb/maint.h +++ b/gdb/maint.h @@ -70,13 +70,17 @@ class scoped_command_stats int m_start_nr_blocks; }; +/* If true, display time usage both at startup and for each command. */ + +extern bool per_command_time; + /* RAII structure used to measure the time spent by the current thread in a given scope. */ struct scoped_time_it { /* WHAT is the prefix to show when the summary line is printed. */ - scoped_time_it (const char *what); + scoped_time_it (const char *what, bool enabled = per_command_time); DISABLE_COPY_AND_ASSIGN (scoped_time_it); ~scoped_time_it (); -- 2.39.5