Bug 30520 - Slow lookup_symbol_in_objfile
Summary: Slow lookup_symbol_in_objfile
Status: RESOLVED FIXED
Alias: None
Product: gdb
Classification: Unclassified
Component: symtab (show other bugs)
Version: 13.1
: P2 normal
Target Milestone: 15.1
Assignee: Not yet assigned to anyone
URL:
Keywords:
: 31010 (view as bug list)
Depends on:
Blocks: 29366
  Show dependency treegraph
 
Reported: 2023-06-06 09:52 UTC by Dmitry Neverov
Modified: 2024-05-17 14:50 UTC (History)
4 users (show)

See Also:
Host:
Target:
Build: 2023-12-01 0:00
Last reconfirmed: 2023-12-01 00:00:00


Attachments
gdb.log (82.51 KB, text/plain)
2023-06-06 09:52 UTC, Dmitry Neverov
Details
gdb-12.1.log (149.08 KB, text/plain)
2023-06-06 11:39 UTC, Dmitry Neverov
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Dmitry Neverov 2023-06-06 09:52:42 UTC
Created attachment 14919 [details]
gdb.log

I'm facing a performance problem in `-var-list-children` gdb/mi command in gdb 13 built on commit d05c047a71374f533ed9261c6f44707285f1b302 but also earlier gdb 13 versions. It seems like it has to do with slow lookup_symbol_in_objfile. Most lookups are fast, but one takes around a minute to finish for 449Mb shared object:

2023-06-06 10:54:51,286 <&"    [symbol-lookup] lookup_symbol_in_objfile: lookup_symbol_in_objfile (_pcbnew.kiface, GLOBAL_BLOCK, wxObjectDataPtr, VAR_DOMAIN)\n"
2023-06-06 10:55:50,418 <&"    [symbol-lookup] lookup_symbol_in_objfile: lookup_symbol_in_objfile (...) = NULL\n"

Even though a lookup for another symbol in the same session before was fast:

2023-06-06 10:54:36,910 <&"    [symbol-lookup] lookup_symbol_in_objfile: lookup_symbol_in_objfile (_pcbnew.kiface, GLOBAL_BLOCK, wxWindow, VAR_DOMAIN)\n"
2023-06-06 10:54:36,910 <&"    [symbol-lookup] lookup_symbol_in_objfile: lookup_symbol_in_objfile (...) = NULL\n"

What could cause such a slowdown? Are there any way to work that around, e.g. by trading memory for speed?
Comment 1 Dmitry Neverov 2023-06-06 11:39:35 UTC
Created attachment 14920 [details]
gdb-12.1.log
Comment 2 Dmitry Neverov 2023-06-06 11:41:18 UTC
There seems to be no 1-minute delay in gdb-12.1.
Comment 3 Tom Tromey 2023-06-06 19:51:03 UTC
It's hard to know for sure what causes the problem
without more investigation.

A typical cause is too much symtab expansion.
Maybe retrying with "set debug symtab-create 1" would show
the problem.
Comment 4 Dmitry Neverov 2023-06-07 09:50:50 UTC
With 'set debug symtab-create 1' gdb produces ~450Mb of logs between these 2 entries:

2023-06-06 10:54:51,286 <&"    [symbol-lookup] lookup_symbol_in_objfile: lookup_symbol_in_objfile (_pcbnew.kiface, GLOBAL_BLOCK, wxObjectDataPtr, VAR_DOMAIN)\n"
2023-06-06 10:55:50,418 <&"    [symbol-lookup] lookup_symbol_in_objfile: lookup_symbol_in_objfile (...) = NULL\n"

All log entries are of the form like these:

<&"    [symtab-create] start_subfile: name = /usr/include/x86_64-linux-gnu/c++/12/bits/c++config.h, name_for_id = /usr/include/x86_64-linux-gnu/c++/12/bits/c++config.h\n"
<&"    [symtab-create] start_subfile: found existing symtab with name_for_id /usr/include/x86_64-linux-gnu/c++/12/bits/c++config.h\n"

There are 1134332 '[symtab-create] start_subfile: name = ...' entries total, 707543 of them result in 'found existing symtab', 426789 don't find an existing symtab.

There are 3519 unique names for symtab-create.
Comment 5 Dmitry Neverov 2023-06-09 08:52:14 UTC
If needed I think I can share all the logs.
Comment 6 Dmitry Neverov 2023-11-06 10:45:08 UTC
I investigated it a bit further and the slowness seems to be
indeed caused by too much symtab expansion:

https://sourceware.org/pipermail/gdb/2023-October/050976.html
Comment 7 Tom Tromey 2023-12-01 20:28:56 UTC
First, thank you for your investigation.  That's very helpful.

This seems pretty similar to bug#31010 in that the cooked-index
code is expanding too many CUs for pretty much the same reason.
Comment 9 Josh Cottingham 2024-01-30 11:51:31 UTC
Not sure if this is helpful but worth mentioning that bug#31010 does appear to be fixed with https://sourceware.org/pipermail/gdb-patches/2024-January/205924.html
Comment 10 Josh Cottingham 2024-01-30 11:52:16 UTC
Not sure if this is helpful but worth mentioning that bug#31010 does appear to be fixed with https://sourceware.org/pipermail/gdb-patches/2024-January/205924.html
Comment 11 Tom Tromey 2024-02-15 17:02:57 UTC
*** Bug 31010 has been marked as a duplicate of this bug. ***
Comment 12 Tom Tromey 2024-02-15 17:05:09 UTC
We have a patch series for this pending copyright assignment
(and some minor formatting); I'd like to get this in gdb 15,
so I'm setting the target milestone.
Comment 13 Joel Brobecker 2024-05-10 22:06:15 UTC
FTR: v3 patch series at: https://sourceware.org/pipermail/gdb-patches/2024-May/209010.html

Reviewed by Tom who said they look reasonable (so I'm assuming they are approved).

I will ping the FSF copyright office.
Comment 14 Sourceware Commits 2024-05-17 14:49:45 UTC
The master branch has been updated by Tom Tromey <tromey@sourceware.org>:

https://sourceware.org/git/gitweb.cgi?p=binutils-gdb.git;h=3a0fae312983989a33608d924ff902d7b78e8ec1

commit 3a0fae312983989a33608d924ff902d7b78e8ec1
Author: Dmitry.Neverov <dmitry.neverov@jetbrains.com>
Date:   Mon May 6 17:09:17 2024 +0200

    gdb/symtab: check name matches before expanding a CU
    
    The added check fixes the case when an unqualified lookup
    name without template arguments causes expansion of many CUs
    which contain the name with template arguments.
    
    This is similar to what dw2_expand_symtabs_matching_symbol does
    before expanding the CU.
    
    In the referenced issue the lookup name was wxObjectDataPtr and many
    CUs had names like wxObjectDataPtr<wxBitmapBundleImpl>. This caused
    their expansion and the lookup took around a minute. The added check
    helps to avoid the expansion and makes the symbol lookup to return in
    a second or so.
    
    Bug: https://sourceware.org/bugzilla/show_bug.cgi?id=30520
Comment 15 Tom Tromey 2024-05-17 14:50:52 UTC
Should be fixed.