<div dir="ltr">Thanks Greg and Jason for pointing me in the right direction!<div><br></div><div>The results from my original tests were due to a timeout being triggered:</div><div><br></div><div><div>1524681484.092825651 (x86_64) /tmp/liblldb.so.7.0.0: Reading EH frame info</div><div>1524681489.783293724 error: timed out, status = timed out</div><div>1524681489.783379793 this = 0x00005555573DDC80, timeout = 5000000 us</div><div>1524681489.840902615 Breakpoint::ModulesChanged: num_modules: 1 load: 1 delete_locations: 0</div></div><div><br></div><div>I ran the exact same setup on a few other machines, and none of them hit the timeout (so not sure what happened with my first test, more investigation is required). Without the timeout, loading times of a stripped shared library with LLDB attached was much more reasonable.</div><div><br></div><div>I then ran another test on a shared library that had DWARF sections. I tracked down the majority of the extra time to be taking place inside SymbolFileDWARF::Index(), which confirms your theory of the additoinal time being due to indexing the DWARF sections.</div><div><br></div><div>I found this message (<a href="http://lists.llvm.org/pipermail/llvm-dev/2018-January/120509.html">http://lists.llvm.org/pipermail/llvm-dev/2018-January/120509.html</a>) which mentioned adding DWARF5 accelerator table support. Is it reasonable to assume once that is implemented the time it takes to index DWARF sections should be drastically reduced?</div></div><br><div class="gmail_quote"><div dir="ltr">On Tue, Apr 24, 2018 at 4:36 PM Greg Clayton <<a href="mailto:clayborg@gmail.com">clayborg@gmail.com</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div style="word-wrap:break-word;line-break:after-white-space"><br><div><br><blockquote type="cite"><div>On Apr 24, 2018, at 12:26 PM, Scott Funkenhauser via lldb-dev <<a href="mailto:lldb-dev@lists.llvm.org" target="_blank">lldb-dev@lists.llvm.org</a>> wrote:</div><br class="m_-2581335079889393186Apple-interchange-newline"><div><div dir="ltr">Hey guys,<div><br></div><div>I'm trying to track down an issue I'm seeing where dlopen takes significantly longer to execute when LLDB is attached vs GDB (I've attached a simple program that I used to reproduce the issue).</div><div>I was wondering if anybody had any idea what might be contributing to the additional execution time?</div></div></div></blockquote><blockquote type="cite"><div><div dir="ltr"><div>Running without any debugger attached:</div><div>$ ./lldb-load-sample</div><div>Handle: 0x555555768c80<br></div><div>Done loading. 848.27ms<br></div><div>$ ./lldb-load-sample</div><div>Handle: 0x555555768c80<br></div><div>Done loading. 19.6047ms</div><div><br></div><div>I noticed that the first run was significantly slower than any subsequent runs. Most likely due to some caching in Linux.</div><div><br></div><div><br></div><div>For LLDB:</div><div><div>(lldb) file lldb-load-sample</div><div>Current executable set to 'lldb-load-sample' (x86_64).</div><div>(lldb) run</div><div>Process 82804 launched: '/lldb-load-sample' (x86_64)</div><div>Handle: 0x555555768c80<br></div><div>Done loading. 5742.78ms</div><div>Process 82804 exited with status = 0 (0x00000000) </div><div>(lldb) run</div></div><div><div>Process 83454 launched: '<span style="color:rgb(34,34,34);font-family:sans-serif;font-size:13px;font-style:normal;font-variant-ligatures:normal;font-variant-caps:normal;font-weight:400;letter-spacing:normal;text-align:start;text-indent:0px;text-transform:none;white-space:normal;word-spacing:0px;background-color:rgb(255,255,255);text-decoration-style:initial;text-decoration-color:initial;float:none;display:inline">/lldb-load-sample'</span> (x86_64)</div><div>Handle: 0x555555768c80<br></div><div>Done loading. 19.4184ms<br></div><div>Process 83454 exited with status = 0 (0x00000000)</div></div><div><br></div><div>I noticed that subsequent runs were much faster (most likely due to some caching in Linux / LLDB), but that isn't relevant in my situation. Exiting LLDB and starting a new LLDB process still has an extremely long first run (In this case ~5.5s). There are other real world cases (initializing Vulkan which does a bunch of dlopens) where this can add 10s of seconds really slowing down iteration time.</div><div><br></div><div><br></div><div>For GDB:</div><div>(gdb) file lldb-load-sample</div><div>Reading symbols from a.out...done.<br></div><div>(gdb) run</div><div>Starting program: /lldb-load-sample<br></div><div>Handle: 0x555555768c80<br></div><div>Done loading. 79.7276ms<br></div><div>[Inferior 1 (process 85063) exited normally]<br></div><div>(gdb) run</div><div><div style="color:rgb(34,34,34);font-family:sans-serif;font-size:13px;font-style:normal;font-variant-ligatures:normal;font-variant-caps:normal;font-weight:400;letter-spacing:normal;text-align:start;text-indent:0px;text-transform:none;white-space:normal;word-spacing:0px;text-decoration-style:initial;text-decoration-color:initial">Starting program: /lldb-load-sample<br></div><div style="text-align:start;text-indent:0px;text-decoration-style:initial;text-decoration-color:initial">Handle: 0x555555768c80<br></div><div style="color:rgb(34,34,34);font-family:sans-serif;font-size:13px;font-style:normal;font-variant-ligatures:normal;font-variant-caps:normal;font-weight:400;letter-spacing:normal;text-align:start;text-indent:0px;text-transform:none;white-space:normal;word-spacing:0px;text-decoration-style:initial;text-decoration-color:initial">Done loading. 80.325ms<br></div><div style="color:rgb(34,34,34);font-family:sans-serif;font-size:13px;font-style:normal;font-variant-ligatures:normal;font-variant-caps:normal;font-weight:400;letter-spacing:normal;text-align:start;text-indent:0px;text-transform:none;white-space:normal;word-spacing:0px;text-decoration-style:initial;text-decoration-color:initial">[Inferior 1 (process 85063) exited normally]</div><div style="color:rgb(34,34,34);font-family:sans-serif;font-size:13px;font-style:normal;font-variant-ligatures:normal;font-variant-caps:normal;font-weight:400;letter-spacing:normal;text-align:start;text-indent:0px;text-transform:none;white-space:normal;word-spacing:0px;text-decoration-style:initial;text-decoration-color:initial"><br></div><div style="color:rgb(34,34,34);font-family:sans-serif;font-size:13px;font-style:normal;font-variant-ligatures:normal;font-variant-caps:normal;font-weight:400;letter-spacing:normal;text-align:start;text-indent:0px;text-transform:none;white-space:normal;word-spacing:0px;text-decoration-style:initial;text-decoration-color:initial">As you can see the first run is slightly slower than running without a debugger attached, but it's not enough to be noticeable.</div></div></div></div></blockquote><br></div><div>I would venture to say LLDB is indexing the debug info during the shared library load breakpoint for some reason. GDB might not have any breakpoints or symbols to find to do in the shared library, so it might not end up parsing anything. So my guess is LLDB is looking for a symbol in any shared library that is loaded and when the shared library gets loaded it causes LLDB to do more work. All of LLDB's breakpoints are always looking for new locations to resolve (file and line breakpoints, breakpoints by name, and other plug-ins might be looking for things). You might try enabling with:</div><div><br></div><div>(lldb) log enable --timestamp --file /tmp/log.txt dwarf info</div><div>(lldb) file lldb-load-sample</div><div>(lldb) run</div><div>(lldb) quit</div><div><br></div><div>then see if you can see any delays inside of LLDB.</div><div><br></div><div>Greg</div><div><br></div><br></div></blockquote></div>