MI: -var-update performance

MI: -var-update performance

[Vladimir Prus]

Hi,
I'm running into a case where -var-update takes about 2 seconds to execute.
There's quite a lot of varobjs, but 2 seconds is beyond any expectation.

Here's the profile:

Each sample counts as 0.01 seconds.
  %   cumulative   self              self     total
 time   seconds   seconds    calls  Ts/call  Ts/call  name
 22.44     70.23    70.23                             lookup_partial_symbol
 19.65    131.72    61.49                            
lookup_minimal_symbol_by_pc_section
 15.80    181.16    49.44                            
basic_lookup_transparent_type
 10.39    213.67    32.51                             find_pc_sect_psymtab
  5.25    230.11    16.45                             strcmp_iw_ordered
  2.50    237.93     7.82                             find_pc_sect_section
  1.96    244.06     6.13                             dwarf2_frame_find_fde
  1.88    249.94     5.89                             strcmp_iw
  1.21    253.72     3.78                             read_partial_die
  1.02    256.90     3.18                            
lookup_symbol_aux_psymtabs
  0.97    259.94     3.04                             symbol_search_name



Any ideas what's up? Should I try to rebuild gdb with --enable-profiling to
get call graph?

- Volodya

Re: MI: -var-update performance

[Daniel Jacobowitz]

On Tue, Jun 06, 2006 at 11:05:24AM +0400, Vladimir Prus wrote:
> Any ideas what's up? Should I try to rebuild gdb with --enable-profiling to
> get call graph?

Probably.  There's something being lame, either in the symbol table
data structures themselves, or in what's being looked up.

-- 
Daniel Jacobowitz
CodeSourcery

Re: MI: -var-update performance

[Nick Roberts]

Vladimir Prus writes:
 > 
 > Hi,
 > I'm running into a case where -var-update takes about 2 seconds to execute.
 > There's quite a lot of varobjs, but 2 seconds is beyond any expectation.
 > 
 > Here's the profile:
 > 
 > Each sample counts as 0.01 seconds.
 >   %   cumulative   self              self     total
 >  time   seconds   seconds    calls  Ts/call  Ts/call  name
 >  22.44     70.23    70.23                             lookup_partial_symbol
 >  19.65    131.72    61.49                            
 > lookup_minimal_symbol_by_pc_section
 >  15.80    181.16    49.44                            
 > basic_lookup_transparent_type
 >  10.39    213.67    32.51                             find_pc_sect_psymtab
 >   5.25    230.11    16.45                             strcmp_iw_ordered
 >   2.50    237.93     7.82                             find_pc_sect_section
 >   1.96    244.06     6.13                             dwarf2_frame_find_fde
 >   1.88    249.94     5.89                             strcmp_iw
 >   1.21    253.72     3.78                             read_partial_die
 >   1.02    256.90     3.18                            
 > lookup_symbol_aux_psymtabs
 >   0.97    259.94     3.04                             symbol_search_name
 > 
 > 
 > 
 > Any ideas what's up? Should I try to rebuild gdb with --enable-profiling to
 > get call graph?

More generally, I think we should add a timestamp field, like Apple have, so
we can see which MI commands are using most of the time e.g.

   From: Jason Molenda <jmolenda@apple.com>
   Subject: Re: How does GDB/MI give the current frame
   Date: Thu, 15 Jul 2004 13:04:20 -0700

  (gdb)
  -interpreter-exec console-quoted up
  ~"#2  0x000321f4 in gdb_main (args=0xbffff620) at  
  ../../gdb/src/gdb/main.c:851\n"
  ~"851\t  catch_errors (captured_main, args, \"\", RETURN_MASK_ALL);\n"
  ^done,MI_HOOK_RESULT=[HOOK_TYPE="frame_changed",frame="2"],time= 
  {wallclock="0.00620",user="0.00323",system="0.00283",start="1089921236.3 
  59009",end="1089921236.365212"}
  (gdb)


-- 
Nick                                           http://www.inet.net.nz/~nickrob