This is the mail archive of the gdb@sources.redhat.com mailing list for the GDB project.


Index Nav: [Date Index] [Subject Index] [Author Index] [Thread Index]
Message Nav: [Date Prev] [Date Next] [Thread Prev] [Thread Next]
Other format: [Raw text]

Re: Terminally slow (75 seconds) on some steps


On Fri, 15 Aug 2003 18:59:17 -0400 Andrew Cagney <ac131313@redhat.com>
wrote:

> I'm guessing that the second column is seconds.

Sorry, no, I should have included information about this. The second
column is percents. The first column is hit count. I am not sure how much
do you know about oprofile. It has several counters. I have used default
counter that counts Cpu cycles when Cpu is not halted. It makes hit (the
first column) every time the counter reaches zero. I have used default
counter period of 500 000 cycles. One hit is 0.0005 milliseconds on my
gigahertz Pentium III.

> > [1]
> > 
> >      2371 30.3352 vmlinux
> >       736  9.4166 XFree86
> >       729  9.3270 ld-2.3.1.so
> >       595  7.6126 libwx_based-2.5.so.0.0.0
> >       487  6.2308 libwx_gtkd_core-2.5.so.0.0.0
> >       471  6.0261 libc-2.3.1.so
> >       454  5.8086 M
> > ...
> > 
> > [2]
> > 
> >     10567 37.2826 vmlinux
> >      8537 30.1203 gdb
> >      4402 15.5312 libc-2.3.1.so
> >       786  2.7732 ld-2.3.1.so
> >       622  2.1945 XFree86
> >       511  1.8029 libwx_based-2.5.so.0.0.0
> >       455  1.6053 M
> > ...
> 
> The first suprize is how much time, without GDB, it spends in the kernel 
> and the link-loader (ld.so?).  GDB's adding 7 seconds of kernel time 
> which isn't too bad but would be useful to know where.
>
> Second is yes, 30s of GDB and 9 of glibc.

Gdb is adding (10567-2371)*0.0005 = 4 seconds of kernel time along with
8537*0.0005 = 4.3 seconds of gdb time and 2 seconds of libc time.

> > 00000000 4402     15.5317     libc-2.3.1.so            (no symbols)
> > 080e40e0 1134      4.0011     gdb                      bcache
> 
> That's striking.  GDB spent 4s/30s avoiding the creation of duplicate 

0.6/4.3 seconds.

> strings and other symbols.

> > c01221cc 1011      3.5671     vmlinux                  file_read_actor
> > c01dc330 955       3.3696     vmlinux                 
> __generic_copy_to_user
> 
> Does this copy-to-user appear when GDB isn't present?

Yes, but it has only 31 hits.

> Have you tried `set trust-read-only-sections on'?

I'll try this next time I'll be running oprofile.

Btw, I just realized that we are using modules. Our modules are small .so
libraries. There is 27 of them and they are normally loaded at startup.
They take up 500KB each, but I think this is all debug information,
because source is just one .cpp file for each library. Although there is
some (very little) template code (strings, iostreams).

Here's symbol list for non-gdb run, so you have something to compare
against.

00000000 736       9.4166     XFree86                  (no symbols)
00000000 471       6.0261     libc-2.3.1.so            (no symbols)
00000000 451       5.7702     libglib-1.2.so.0.0.10    (no symbols)
00000000 262       3.3521     libX11.so.6.2            (no symbols)
00006e48 248       3.1730     ld-2.3.1.so              do_lookup
00007042 210       2.6868     ld-2.3.1.so              do_lookup_versioned
c01397f4 192       2.4565     vmlinux                  do_select
00002210 175       2.2390     unix.o                   unix_poll
0000dc18 169       2.1622     ld-2.3.1.so              strcmp
00000000 166       2.1238     libgdk-1.2.so.0.9.1      (no symbols)
c0106d54 136       1.7400     vmlinux                  system_call
00000000 133       1.7016     libgtk-1.2.so.0.9.1      (no symbols)
c010fbe4 131       1.6760     vmlinux                  schedule
c012da38 127       1.6249     vmlinux                  fput
c012db08 99        1.2666     vmlinux                  fget
c019738c 91        1.1643     vmlinux                  sock_poll
c0110cfc 89        1.1387     vmlinux                  remove_wait_queue
c0110cb0 83        1.0619     vmlinux                  add_wait_queue
00001d04 83        1.0619     unix.o                   unix_stream_recvmsg
000096bf 81        1.0363     libpthread-0.10.so       __pthread_alt_lock
000098c3 77        0.9852     libpthread-0.10.so       __pthread_alt_unlock
c01399f8 76        0.9724     vmlinux                  sys_select
00000000 69        0.8828     librep.so.9.2.2          (no symbols)
c01396c4 67        0.8572     vmlinux                  __pollwait
c0127640 62        0.7932     vmlinux                  __free_pages_ok
c0127834 61        0.7805     vmlinux                  rmqueue
082c7ce4 59        0.7549     M                        get_bblocks
000068e6 58        0.7421     libpthread-0.10.so       __pthread_mutex_lock
c01261b0 55        0.7037     vmlinux                  kmalloc
000c9fea 48        0.6141     libwx_based-2.5.so.0.0.0 wxStringBase::insert(unsigned int, wxStri
ngBase const&, unsigned int, unsigned int)



Index Nav: [Date Index] [Subject Index] [Author Index] [Thread Index]
Message Nav: [Date Prev] [Date Next] [Thread Prev] [Thread Next]