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>
This commit is contained in:
Simon Marchi
2025-04-17 15:23:54 -04:00
committed by Simon Marchi
parent 0b79576c9d
commit cc55260231
4 changed files with 20 additions and 3 deletions

View File

@@ -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

View File

@@ -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 ();

View File

@@ -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);
});

View File

@@ -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;