Re: gdb script performance

[Jean-Marc Saffroy <saffroy at gmail dot com>]

Hello,

I'm resurrecting this old thread on gdb performance since I took some time 
to look into the problem recently.

On Thu, 5 Oct 2006, Daniel Jacobowitz wrote:

> On Thu, Oct 05, 2006 at 05:29:30PM +0200, Jean-Marc Saffroy wrote:
> > On Thu, 5 Oct 2006, Daniel Jacobowitz wrote:
> >
> > Please find attached gprof output (this is with gdb 6.5 +
> > gdb-lookup-internal-first-3.patch running the lsmaps script I posted
> > earlier).
> >
> > Thanks for helping!
>
> 26.14    381.31   381.31   141867     2.69     3.50  find_pc_sect_psymtab
> 18.54    651.82   270.51   331876     0.82     0.82  find_pc_sect_section
> 17.88    912.69   260.87 144847060     0.00     0.00  lookup_partial_symbol
> 11.01   1073.33   160.64 1254595136     0.00     0.00  strcmp_iw
>  4.98   1145.97    72.64    34010     2.14    16.50  lookup_symbol_aux_psymtabs
>  4.78   1215.73    69.75     9584     7.28     8.12  fixup_section
>  4.46   1280.79    65.06                             lbasename
>  3.42   1330.64    49.85    12183     4.09     4.09  lookup_partial_symtab
>  1.83   1357.34    26.70 33844664     0.00     0.00  strcmp_iw_ordered
>  1.68   1381.82    24.48 1288426966     0.00     0.00  symbol_natural_name
>  1.09   1397.71    15.89 1288426966     0.00     0.00  symbol_search_name
>
> Well then.  Observations:
>  - We're looking up partial symbols way too often.
>  - It's taking way too long.
>  - And oh my lord is that a lot of calls to the (fairly inefficient)
>    strcmp_iw.
>
> It looks like only about three calls to find_pc_sect_psymtab per
> expression evaluation, which is bad but not too bad - sounds like
> a last-searched-item cache may be useful.

Some interesting facts:
 - readelf reports no less than 7871 section headers in the vmlinux I'm 
analyzing (this is 2.6.18): any attempt to traverse the list of sections 
costs a *lot*
 - even with the patch lookup-internal-first-3, it seems lookup_symbol_aux 
is sometimes called for gdb script vars

Anyway, I followed your advice and added caching to find_pc_sect_symtab 
and lookup_symbol_aux, which together divided execution time by 6 on my 
benchmark. :-) See gprof output here (baseline is gdb 6.5 with 
gdb-lookup-internal-first-3.patch):
  http://siegfried.dnsalias.net/~saffroy/gdb-baseline.html
  http://siegfried.dnsalias.net/~saffroy/gdb-symcache.html
  http://siegfried.dnsalias.net/~saffroy/gdb-symcache-pc_cache.html
Obviously there is still room for improvement with lbasename.

For completeness I have to mention that gprof reports a completely wrong 
count of seconds on my system (x86-64 box), but it seems there is only a 
bad multiplier somewhere.

Incomplete patches are attached: they lack proper cache invalidation (eg. 
on loading of a new object), but let's discuss the approach first.


Cheers,

--
saffroy@gmail.com

Attachment: gdb-pc_cache.patch
Description: Text document

Attachment: gdb-symcache.patch
Description: Text document