From: Simon Marchi Date: Thu, 17 Apr 2025 19:23:54 +0000 (-0400) Subject: gdb: add some scoped_time_its to profile startup time X-Git-Url: http://git.ipfire.org/?a=commitdiff_plain;h=cc55260231e4302e69796fe56c455ac9a7f24f5d;p=thirdparty%2Fbinutils-gdb.git 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 --- diff --git a/gdb/dwarf2/cooked-index-worker.c b/gdb/dwarf2/cooked-index-worker.c index da51a8c72e8..5d7fc462a05 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 7948ffac236..2c7e31e5676 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 a177a056e13..a48fb65566d 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 9ac3145cb62..124d96d90b5 100644 --- a/gdb/minsyms.c +++ b/gdb/minsyms.c @@ -37,6 +37,7 @@ #include +#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;