SymbolFileDWARF::FindTypes is called too many times (apparently)

dmt · July 2, 2024, 10:54pm

I was debugging slow expression evaluation in lldb in my project and noticed that most of the time is spent on calling the functions SymbolFileDWARF::FindTypes and SymbolFileDWARF::FindFunctions. And a lot of these calls are made on my module's objects, but trying to search foreign symbols, like swift_release, swift_retain, $ss4VoidaD, $ss16_DebuggerSupportO20stringForPrintObjectySSypFZ, and so on.
Looks like this search is performed for each type/function resolution request in every module.
I made a small example reproducing this behavior and took logs with
log enable -T -f ~/lldb_dwarf_map.log dwarf all
Examples:

$ss16_DebuggerSupportO20stringForPrintObjectySSypFZ

<...>/F1.o: SymbolFileDWARF::FindFunctions (name="$ss16_DebuggerSupportO20stringForPrintObjectySSypFZ", name_type_mask=0x4, sc_list)
<...>/F2.o: SymbolFileDWARF::FindFunctions (name="$ss16_DebuggerSupportO20stringForPrintObjectySSypFZ", name_type_mask=0x4, sc_list)
<...>/F3.o: SymbolFileDWARF::FindFunctions (name="$ss16_DebuggerSupportO20stringForPrintObjectySSypFZ", name_type_mask=0x4, sc_list)
<...>/F4.o: SymbolFileDWARF::FindFunctions (name="$ss16_DebuggerSupportO20stringForPrintObjectySSypFZ", name_type_mask=0x4, sc_list)
<...>/F5.o: SymbolFileDWARF::FindFunctions (name="$ss16_DebuggerSupportO20stringForPrintObjectySSypFZ", name_type_mask=0x4, sc_list)
<...>/F6.o: SymbolFileDWARF::FindFunctions (name="$ss16_DebuggerSupportO20stringForPrintObjectySSypFZ", name_type_mask=0x4, sc_list)
<...>/F7.o: SymbolFileDWARF::FindFunctions (name="$ss16_DebuggerSupportO20stringForPrintObjectySSypFZ", name_type_mask=0x4, sc_list)
<...>/main1.o: SymbolFileDWARF::FindFunctions (name="$ss16_DebuggerSupportO20stringForPrintObjectySSypFZ", name_type_mask=0x4, sc_list)
<...>/Foo.o: SymbolFileDWARF::FindFunctions (name="$ss16_DebuggerSupportO20stringForPrintObjectySSypFZ", name_type_mask=0x4, sc_list)
<...>/F1.o: SymbolFileDWARF::FindFunctions (name="$ss16_DebuggerSupportO20stringForPrintObjectySSypFZ", name_type_mask=0x4, sc_list)
<...>/F2.o: SymbolFileDWARF::FindFunctions (name="$ss16_DebuggerSupportO20stringForPrintObjectySSypFZ", name_type_mask=0x4, sc_list)
<...>/F3.o: SymbolFileDWARF::FindFunctions (name="$ss16_DebuggerSupportO20stringForPrintObjectySSypFZ", name_type_mask=0x4, sc_list)
<...>/F4.o: SymbolFileDWARF::FindFunctions (name="$ss16_DebuggerSupportO20stringForPrintObjectySSypFZ", name_type_mask=0x4, sc_list)
<...>/F5.o: SymbolFileDWARF::FindFunctions (name="$ss16_DebuggerSupportO20stringForPrintObjectySSypFZ", name_type_mask=0x4, sc_list)
<...>/F6.o: SymbolFileDWARF::FindFunctions (name="$ss16_DebuggerSupportO20stringForPrintObjectySSypFZ", name_type_mask=0x4, sc_list)
<...>/F7.o: SymbolFileDWARF::FindFunctions (name="$ss16_DebuggerSupportO20stringForPrintObjectySSypFZ", name_type_mask=0x4, sc_list)
<...>/main1.o: SymbolFileDWARF::FindFunctions (name="$ss16_DebuggerSupportO20stringForPrintObjectySSypFZ", name_type_mask=0x4, sc_list)
<...>/Foo.o: SymbolFileDWARF::FindFunctions (name="$ss16_DebuggerSupportO20stringForPrintObjectySSypFZ", name_type_mask=0x4, sc_list)

swift_release/swift_retain

<...>/F1.o: SymbolFileDWARF::FindFunctions (name="swift_release", name_type_mask=0x4, sc_list)
<...>/F2.o: SymbolFileDWARF::FindFunctions (name="swift_release", name_type_mask=0x4, sc_list)
<...>/F3.o: SymbolFileDWARF::FindFunctions (name="swift_release", name_type_mask=0x4, sc_list)
<...>/F4.o: SymbolFileDWARF::FindFunctions (name="swift_release", name_type_mask=0x4, sc_list)
<...>/F5.o: SymbolFileDWARF::FindFunctions (name="swift_release", name_type_mask=0x4, sc_list)
<...>/F6.o: SymbolFileDWARF::FindFunctions (name="swift_release", name_type_mask=0x4, sc_list)
<...>/F7.o: SymbolFileDWARF::FindFunctions (name="swift_release", name_type_mask=0x4, sc_list)
<...>/main1.o: SymbolFileDWARF::FindFunctions (name="swift_release", name_type_mask=0x4, sc_list)
<...>/Foo.o: SymbolFileDWARF::FindFunctions (name="swift_release", name_type_mask=0x4, sc_list)
<...>/F1.o: SymbolFileDWARF::FindFunctions (name="swift_release", name_type_mask=0x4, sc_list)
<...>/F2.o: SymbolFileDWARF::FindFunctions (name="swift_release", name_type_mask=0x4, sc_list)
<...>/F3.o: SymbolFileDWARF::FindFunctions (name="swift_release", name_type_mask=0x4, sc_list)
<...>/F4.o: SymbolFileDWARF::FindFunctions (name="swift_release", name_type_mask=0x4, sc_list)
<...>/F5.o: SymbolFileDWARF::FindFunctions (name="swift_release", name_type_mask=0x4, sc_list)
<...>/F6.o: SymbolFileDWARF::FindFunctions (name="swift_release", name_type_mask=0x4, sc_list)
<...>/F7.o: SymbolFileDWARF::FindFunctions (name="swift_release", name_type_mask=0x4, sc_list)
<...>/main1.o: SymbolFileDWARF::FindFunctions (name="swift_release", name_type_mask=0x4, sc_list)
<...>/Foo.o: SymbolFileDWARF::FindFunctions (name="swift_release", name_type_mask=0x4, sc_list)
<...>/F1.o: SymbolFileDWARF::FindFunctions (name="swift_retain", name_type_mask=0x4, sc_list)
<...>/F2.o: SymbolFileDWARF::FindFunctions (name="swift_retain", name_type_mask=0x4, sc_list)
<...>/F3.o: SymbolFileDWARF::FindFunctions (name="swift_retain", name_type_mask=0x4, sc_list)
<...>/F4.o: SymbolFileDWARF::FindFunctions (name="swift_retain", name_type_mask=0x4, sc_list)
<...>/F5.o: SymbolFileDWARF::FindFunctions (name="swift_retain", name_type_mask=0x4, sc_list)
<...>/F6.o: SymbolFileDWARF::FindFunctions (name="swift_retain", name_type_mask=0x4, sc_list)
<...>/F7.o: SymbolFileDWARF::FindFunctions (name="swift_retain", name_type_mask=0x4, sc_list)
<...>/main1.o: SymbolFileDWARF::FindFunctions (name="swift_retain", name_type_mask=0x4, sc_list)
<...>/Foo.o: SymbolFileDWARF::FindFunctions (name="swift_retain", name_type_mask=0x4, sc_list)
<...>/F1.o: SymbolFileDWARF::FindFunctions (name="swift_retain", name_type_mask=0x4, sc_list)
<...>/F2.o: SymbolFileDWARF::FindFunctions (name="swift_retain", name_type_mask=0x4, sc_list)
<...>/F3.o: SymbolFileDWARF::FindFunctions (name="swift_retain", name_type_mask=0x4, sc_list)
<...>/F4.o: SymbolFileDWARF::FindFunctions (name="swift_retain", name_type_mask=0x4, sc_list)
<...>/F5.o: SymbolFileDWARF::FindFunctions (name="swift_retain", name_type_mask=0x4, sc_list)
<...>/F6.o: SymbolFileDWARF::FindFunctions (name="swift_retain", name_type_mask=0x4, sc_list)
<...>/F7.o: SymbolFileDWARF::FindFunctions (name="swift_retain", name_type_mask=0x4, sc_list)
<...>/main1.o: SymbolFileDWARF::FindFunctions (name="swift_retain", name_type_mask=0x4, sc_list)
<...>/Foo.o: SymbolFileDWARF::FindFunctions (name="swift_retain", name_type_mask=0x4, sc_list)

$ss4VoidaD

<...>/F1.o: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/Foundation-2RKMKGO99ROHJ.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/CoreFoundation-20CBG5TV841E9.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/Darwin-14D19EDNU7P9P.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/_Builtin_stddef_max_align_t-3RYDM0OTC9EKN.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/Dispatch-3K0ABAQN0ZCKQ.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/ObjectiveC-2PMW55H95VPI1.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/MachO-2CX7LH15EXF2A.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/os_object-14D19EDNU7P9P.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/os_workgroup-14D19EDNU7P9P.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/ptrauth-3RYDM0OTC9EKN.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/CoreServices-1DCIL6EKJYUI6.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/CFNetwork-1B1SSEQKOUJ8N.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/DiskArbitration-28NQO1BH2IX70.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/IOKit-1ZFD1OOS6JM4F.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/libkern-14D19EDNU7P9P.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/Security-2CATWL7YJDERF.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/XPC-2I05NQT8SVVQ4.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/launch-XFFOGOXUT3UJ.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/libDER-2DT2GFW0ST9L6.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/_SwiftConcurrencyShims-QCY7C47RPWD1.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<...>/F2.o: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<...>/F3.o: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<...>/F4.o: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<...>/F5.o: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<...>/F6.o: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<...>/F7.o: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<...>/main1.o: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<...>/Foo.o: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<...>/F1.o: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/Foundation-2RKMKGO99ROHJ.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/CoreFoundation-20CBG5TV841E9.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/Darwin-14D19EDNU7P9P.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/_Builtin_stddef_max_align_t-3RYDM0OTC9EKN.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/Dispatch-3K0ABAQN0ZCKQ.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/ObjectiveC-2PMW55H95VPI1.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/MachO-2CX7LH15EXF2A.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/os_object-14D19EDNU7P9P.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/os_workgroup-14D19EDNU7P9P.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/ptrauth-3RYDM0OTC9EKN.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/CoreServices-1DCIL6EKJYUI6.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/CFNetwork-1B1SSEQKOUJ8N.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/DiskArbitration-28NQO1BH2IX70.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/IOKit-1ZFD1OOS6JM4F.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/libkern-14D19EDNU7P9P.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/Security-2CATWL7YJDERF.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/XPC-2I05NQT8SVVQ4.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/launch-XFFOGOXUT3UJ.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/libDER-2DT2GFW0ST9L6.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
<mcp>/JHGINULXXWPJ/_SwiftConcurrencyShims-QCY7C47RPWD1.pcm: SymbolFileDWARF::FindTypes (sc, name="$ss4VoidaD", parent_decl_ctx = NULL, max_matches=4294967295, type_list)
...2000+ more $ss4VoidaD lookups...

In my small sample project, it performs quite fast. However, in my main project, we have approximately 24,000 .o and .pcm files in a target, and these lookups take a noticeable amount of time, often tens of seconds.

I would like to discuss how we can improve the debugging experience:

In the case of Swift symbols, we often have a good guess about where the symbol is located by looking at the module name in the unmangled symbol. Can we leverage this?
It appears there is no cache for these lookups. Can we add one?
Are there any other possible improvements?

Lancelotbronner · July 3, 2024, 1:20pm

I would love for debugger performance to be improved, it was so problematic in our team that we mostly stopped using it.

Doing any debugging (with explicit module building enabled) in our project, even just hitting a breakpoint in Xcode, is often long enough that you can go get a coffee in another building.

Adrian_Prantl · July 4, 2024, 3:42pm

It would be interesting to know the backtrace of the FindTypes calls; there are many code paths that can trigger type lookups, so the first thing we should look into is which component is requesting them (and why it’s done repeatedly).
Could you upload your sample project somewhere, so we could take a look?

Adrian_Prantl · July 4, 2024, 3:44pm

If debugging with explicit modules takes a long time, I’d love to see an instruments trace of LLDB to understand what it’s doing.

dmt · July 4, 2024, 4:11pm

Sure GitHub - DmT021/lldb_perf_dbg
It's basically an Xcode template with several more files just to have some .os.

I also took a log with -S and included it here for your convenience.
The interesting calls are those called by CommandObjectDWIMPrint::DoExecute