aboutsummaryrefslogtreecommitdiff
diff options
context:
space:
mode:
authorSimon Marchi <simon.marchi@polymtl.ca>2025-04-17 15:23:54 -0400
committerSimon Marchi <simon.marchi@efficios.com>2025-04-29 15:10:17 -0400
commitcc55260231e4302e69796fe56c455ac9a7f24f5d (patch)
tree0725fb6f26c620631f3089d4a2a58f0f4554f5a5
parent0b79576c9d398caec787fa913c3b115afdc3d06a (diff)
downloadbinutils-cc55260231e4302e69796fe56c455ac9a7f24f5d.zip
binutils-cc55260231e4302e69796fe56c455ac9a7f24f5d.tar.gz
binutils-cc55260231e4302e69796fe56c455ac9a7f24f5d.tar.bz2
gdb: add some scoped_time_its to profile startup time
I'm investigating some issues where GDB takes a lot of time to start up (read: for the DWARF index to be ready to do anything useful). Adding those scoped_time_it instances helped me gain some insights about where GDB spends time. I think they would be useful to have upstream, to make investigating future problems easier. It would also be useful to be able to give some numbers in the commit messages. Here's an example of what GDB outputs: Time for "minsyms install worker": wall 0.045, user 0.040, sys 0.004, user+sys 0.044, 97.8 % CPU Time for "minsyms install worker": wall 0.511, user 0.457, sys 0.048, user+sys 0.505, 98.8 % CPU Time for "minsyms install worker": wall 1.513, user 1.389, sys 0.111, user+sys 1.500, 99.1 % CPU Time for "minsyms install worker": wall 1.688, user 1.451, sys 0.102, user+sys 1.553, 92.0 % CPU Time for "minsyms install worker": wall 1.897, user 1.518, sys 0.089, user+sys 1.607, 84.7 % CPU Time for "minsyms install worker": wall 2.811, user 2.558, sys 0.231, user+sys 2.789, 99.2 % CPU Time for "minsyms install worker": wall 3.257, user 3.049, sys 0.188, user+sys 3.237, 99.4 % CPU Time for "minsyms install worker": wall 3.617, user 3.089, sys 0.211, user+sys 3.300, 91.2 % CPU Time for "DWARF indexing worker": wall 19.517, user 0.894, sys 0.075, user+sys 0.969, 5.0 % CPU Time for "DWARF indexing worker": wall 19.807, user 0.891, sys 0.086, user+sys 0.977, 4.9 % CPU Time for "DWARF indexing worker": wall 20.270, user 1.559, sys 0.119, user+sys 1.678, 8.3 % CPU Time for "DWARF indexing worker": wall 20.329, user 1.878, sys 0.147, user+sys 2.025, 10.0 % CPU Time for "DWARF indexing worker": wall 20.848, user 3.483, sys 0.224, user+sys 3.707, 17.8 % CPU Time for "DWARF indexing worker": wall 21.088, user 4.285, sys 0.295, user+sys 4.580, 21.7 % CPU Time for "DWARF indexing worker": wall 21.109, user 4.501, sys 0.274, user+sys 4.775, 22.6 % CPU Time for "DWARF indexing worker": wall 21.198, user 5.087, sys 0.319, user+sys 5.406, 25.5 % CPU Time for "DWARF skeletonless type units": wall 4.024, user 3.858, sys 0.115, user+sys 3.973, 98.7 % CPU Time for "DWARF add parent map": wall 0.092, user 0.086, sys 0.004, user+sys 0.090, 97.8 % CPU Time for "DWARF finalize worker": wall 0.278, user 0.241, sys 0.009, user+sys 0.250, 89.9 % CPU Time for "DWARF finalize worker": wall 0.307, user 0.304, sys 0.000, user+sys 0.304, 99.0 % CPU Time for "DWARF finalize worker": wall 0.727, user 0.719, sys 0.000, user+sys 0.719, 98.9 % CPU Time for "DWARF finalize worker": wall 0.913, user 0.901, sys 0.003, user+sys 0.904, 99.0 % CPU Time for "DWARF finalize worker": wall 0.776, user 0.767, sys 0.004, user+sys 0.771, 99.4 % CPU Time for "DWARF finalize worker": wall 1.897, user 1.869, sys 0.006, user+sys 1.875, 98.8 % CPU Time for "DWARF finalize worker": wall 2.534, user 2.512, sys 0.005, user+sys 2.517, 99.3 % CPU Time for "DWARF finalize worker": wall 2.607, user 2.583, sys 0.006, user+sys 2.589, 99.3 % CPU Time for "DWARF finalize worker": wall 3.142, user 3.094, sys 0.022, user+sys 3.116, 99.2 % CPU Change-Id: I9453589b9005c3226499428ae9cab9f4a8c22904 Approved-By: Tom Tromey <tom@tromey.com>
-rw-r--r--gdb/dwarf2/cooked-index-worker.c9
-rw-r--r--gdb/dwarf2/cooked-index.c7
-rw-r--r--gdb/dwarf2/read.c4
-rw-r--r--gdb/minsyms.c3
4 files changed, 20 insertions, 3 deletions
diff --git a/gdb/dwarf2/cooked-index-worker.c b/gdb/dwarf2/cooked-index-worker.c
index da51a8c..5d7fc46 100644
--- a/gdb/dwarf2/cooked-index-worker.c
+++ b/gdb/dwarf2/cooked-index-worker.c
@@ -20,6 +20,7 @@
#include "dwarf2/cooked-index-worker.h"
#include "dwarf2/cooked-index.h"
#include "gdbsupport/thread-pool.h"
+#include "maint.h"
#include "run-on-main-thread.h"
#include "event-top.h"
#include "exceptions.h"
@@ -244,8 +245,12 @@ cooked_index_worker::write_to_cache (const cooked_index *idx)
void
cooked_index_worker::done_reading ()
{
- for (auto &one_result : m_results)
- m_all_parents_map.add_map (*one_result.get_parent_map ());
+ {
+ scoped_time_it time_it ("DWARF add parent map");
+
+ for (auto &one_result : m_results)
+ m_all_parents_map.add_map (*one_result.get_parent_map ());
+ }
dwarf2_per_bfd *per_bfd = m_per_objfile->per_bfd;
cooked_index *table
diff --git a/gdb/dwarf2/cooked-index.c b/gdb/dwarf2/cooked-index.c
index 7948ffa..2c7e31e 100644
--- a/gdb/dwarf2/cooked-index.c
+++ b/gdb/dwarf2/cooked-index.c
@@ -21,6 +21,7 @@
#include "dwarf2/read.h"
#include "dwarf2/stringify.h"
#include "event-top.h"
+#include "maint.h"
#include "observable.h"
#include "run-on-main-thread.h"
#include "gdbsupport/task-group.h"
@@ -101,7 +102,11 @@ cooked_index::set_contents ()
{
auto this_shard = shard.get ();
const parent_map_map *parent_maps = m_state->get_parent_map_map ();
- finalizers.add_task ([=] () { this_shard->finalize (parent_maps); });
+ finalizers.add_task ([=] ()
+ {
+ scoped_time_it time_it ("DWARF finalize worker");
+ this_shard->finalize (parent_maps);
+ });
}
finalizers.start ();
diff --git a/gdb/dwarf2/read.c b/gdb/dwarf2/read.c
index a177a05..a48fb65 100644
--- a/gdb/dwarf2/read.c
+++ b/gdb/dwarf2/read.c
@@ -52,6 +52,7 @@
#include "event-top.h"
#include "exceptions.h"
#include "gdbsupport/task-group.h"
+#include "maint.h"
#include "symtab.h"
#include "gdbtypes.h"
#include "objfiles.h"
@@ -3515,6 +3516,8 @@ static void
process_skeletonless_type_units (dwarf2_per_objfile *per_objfile,
cooked_index_worker_result *storage)
{
+ scoped_time_it time_it ("DWARF skeletonless type units");
+
/* Skeletonless TUs in DWP files without .gdb_index is not supported yet. */
if (per_objfile->per_bfd->dwp_file == nullptr)
for (const dwo_file_up &file : per_objfile->per_bfd->dwo_files)
@@ -3677,6 +3680,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");
process_cus (task_count, iter, last);
});
diff --git a/gdb/minsyms.c b/gdb/minsyms.c
index 9ac3145..124d96d 100644
--- a/gdb/minsyms.c
+++ b/gdb/minsyms.c
@@ -37,6 +37,7 @@
#include <ctype.h>
+#include "maint.h"
#include "symtab.h"
#include "bfd.h"
#include "filenames.h"
@@ -1481,6 +1482,8 @@ minimal_symbol_reader::install ()
gdb::parallel_for_each (10, &msymbols[0], &msymbols[mcount],
[&] (minimal_symbol *start, minimal_symbol *end)
{
+ scoped_time_it time_it ("minsyms install worker");
+
for (minimal_symbol *msym = start; msym < end; ++msym)
{
size_t idx = msym - msymbols;