This is the mail archive of the
gdb-prs@sourceware.org
mailing list for the GDB project.
[Bug symtab/15826] Slow symbol lookups during conditional breakpoints
- From: "mjw at redhat dot com" <sourceware-bugzilla at sourceware dot org>
- To: gdb-prs at sourceware dot org
- Date: Tue, 03 Jun 2014 09:35:48 +0000
- Subject: [Bug symtab/15826] Slow symbol lookups during conditional breakpoints
- Auto-submitted: auto-generated
- References: <bug-15826-4717 at http dot sourceware dot org/bugzilla/>
https://sourceware.org/bugzilla/show_bug.cgi?id=15826
--- Comment #10 from Mark Wielaard <mjw at redhat dot com> ---
It has been some time since I looked at this. The testcase in comment #8 isn't
really good, but should show that a symbol lookup is done on every condition
evaluation. The original libreoffice usage is much more interesting, but way
harder to setup (I currently don't have it setup). The actual symbol lookup
function did change with current gdb git trunk compared to when I tested it
back in September. But I think gdb is still doing too much work, especially
given that this example doesn't actually have any symbol table to speak of.
So with the program from comment #8 and g++, perf and gdb trunk:
g++ (GCC) 4.4.7 20120313 (Red Hat 4.4.7-4)
perf version 2.6.32-431.17.1.el6.x86_64.debug
GNU gdb (GDB) 7.7.50.20140603-cvs
With loop compiled with g++ as in comment #8. Just run $ sudo perf top in one
window. And gdb in another $ gdb loop.
Reading symbols from loop...done.
(gdb) break bar
Breakpoint 1 at 0x40055b: file loop.c, line 6.
(gdb) condition 1 y == 55
(gdb) run
Starting program: /tmp/loop
Now in the perf window you will see something like:
3.17% libc-2.12.so [.] _int_malloc
2.50% libc-2.12.so [.] vfprintf
1.79% libc-2.12.so [.] _int_free
1.37% libpthread-2.12.so [.] pthread_rwlock_unlock
1.28% libpthread-2.12.so [.] pthread_rwlock_rdlock
1.22% libc-2.12.so [.] malloc_consolidate
1.22% gdb [.] gdbarch_data
1.20% libc-2.12.so [.] __dcigettext
1.14% gdb [.] dwarf2_frame_cache
1.08% libc-2.12.so [.] getenv
1.05% [kernel] [k] _spin_lock
1.02% libc-2.12.so [.] __memset_sse2
1.01% gdb [.]
lookup_minimal_symbol_by_pc_section_1
If we attach gdb to the running gdb we see how we end up in
lookup_minimal_symbol (back in September this was lookup_symbol_aux) we see:
#0 lookup_minimal_symbol_by_pc_section_1 (pc_in=<value optimized out>,
section=0x251f370,
want_trampoline=<value optimized out>) at
/home/mark/src/binutils-gdb/gdb/minsyms.c:568
#1 0x00000000005f11e7 in lookup_minimal_symbol_by_pc_section (pc=4195675,
section=<value optimized out>)
at /home/mark/src/binutils-gdb/gdb/minsyms.c:743
#2 0x0000000000581489 in find_pc_sect_symtab (pc=4195675, section=0x0)
at /home/mark/src/binutils-gdb/gdb/symtab.c:2153
#3 0x000000000057ec1d in blockvector_for_pc_sect (pc=4195675, section=<value
optimized out>, pblock=
0x7fff3a3fcad8, symtab=<value optimized out>) at
/home/mark/src/binutils-gdb/gdb/block.c:168
#4 0x000000000057ec40 in block_for_pc_sect (pc=<value optimized out>,
section=<value optimized out>)
at /home/mark/src/binutils-gdb/gdb/block.c:246
#5 0x000000000068b5d8 in inline_frame_sniffer (self=<value optimized out>,
this_frame=0x23eb710,
this_cache=<value optimized out>) at
/home/mark/src/binutils-gdb/gdb/inline-frame.c:218
#6 0x0000000000689c53 in frame_unwind_try_unwinder (this_frame=0x23eb710,
this_cache=0x23eb728, unwinder=0x8279c0)
at /home/mark/src/binutils-gdb/gdb/frame-unwind.c:108
#7 0x0000000000689d4f in frame_unwind_find_by_frame (this_frame=0x23eb710,
this_cache=0x23eb728)
at /home/mark/src/binutils-gdb/gdb/frame-unwind.c:159
#8 0x0000000000686c9b in compute_frame_id (this_frame=0x23eb640) at
/home/mark/src/binutils-gdb/gdb/frame.c:457
#9 get_prev_frame_if_no_cycle (this_frame=0x23eb640) at
/home/mark/src/binutils-gdb/gdb/frame.c:1783
#10 0x0000000000688ad8 in get_prev_frame_always_1 (this_frame=0x23eb640)
at /home/mark/src/binutils-gdb/gdb/frame.c:1957
#11 get_prev_frame_always (this_frame=0x23eb640) at
/home/mark/src/binutils-gdb/gdb/frame.c:1974
#12 0x0000000000688fc8 in get_prev_frame (this_frame=0x23eb640) at
/home/mark/src/binutils-gdb/gdb/frame.c:2215
#13 0x00000000006891ac in unwind_to_current_frame (ui_out=<value optimized
out>, args=<value optimized out>)
at /home/mark/src/binutils-gdb/gdb/frame.c:1450
#14 0x00000000005b56f2 in catch_exceptions_with_msg (func_uiout=<value
optimized out>, func=
0x6891a0 <unwind_to_current_frame>, func_args=0x23eb640, gdberrmsg=0x0,
mask=RETURN_MASK_ERROR)
at /home/mark/src/binutils-gdb/gdb/exceptions.c:476
#15 0x00000000006867b0 in get_current_frame () at
/home/mark/src/binutils-gdb/gdb/frame.c:1489
#16 0x00000000005a81fe in handle_signal_stop (ecs=0x7fff3a3fcfc0) at
/home/mark/src/binutils-gdb/gdb/infrun.c:3969
#17 handle_inferior_event (ecs=0x7fff3a3fcfc0) at
/home/mark/src/binutils-gdb/gdb/infrun.c:3819
#18 0x00000000005a95bc in fetch_inferior_event (client_data=<value optimized
out>)
at /home/mark/src/binutils-gdb/gdb/infrun.c:2921
#19 0x00000000005c0479 in fetch_inferior_event_wrapper (client_data=<value
optimized out>)
at /home/mark/src/binutils-gdb/gdb/inf-loop.c:147
#20 0x00000000005b55fb in catch_errors (func=0x5c0470
<fetch_inferior_event_wrapper>, func_args=0x0, errstring=
0x78beca "", mask=RETURN_MASK_ALL) at
/home/mark/src/binutils-gdb/gdb/exceptions.c:524
#21 0x00000000005c01df in inferior_event_handler (event_type=INF_REG_EVENT,
client_data=0x0)
at /home/mark/src/binutils-gdb/gdb/inf-loop.c:55
#22 0x00000000005be4b4 in process_event () at
/home/mark/src/binutils-gdb/gdb/event-loop.c:343
#23 0x00000000005beeaf in gdb_do_one_event () at
/home/mark/src/binutils-gdb/gdb/event-loop.c:395
#24 0x00000000005bf085 in start_event_loop () at
/home/mark/src/binutils-gdb/gdb/event-loop.c:432
#25 0x00000000005b7fa3 in captured_command_loop (data=<value optimized out>)
at /home/mark/src/binutils-gdb/gdb/main.c:301
#26 0x00000000005b55fb in catch_errors (func=0x5b7f90 <captured_command_loop>,
func_args=0x0, errstring=
0x78beca "", mask=RETURN_MASK_ALL) at
/home/mark/src/binutils-gdb/gdb/exceptions.c:524
#27 0x00000000005b8b86 in captured_main (data=<value optimized out>) at
/home/mark/src/binutils-gdb/gdb/main.c:1097
#28 0x00000000005b55fb in catch_errors (func=0x5b8180 <captured_main>,
func_args=0x7fff3a3fd360, errstring=
0x78beca "", mask=RETURN_MASK_ALL) at
/home/mark/src/binutils-gdb/gdb/exceptions.c:524
#29 0x00000000005b7ddb in gdb_main (args=<value optimized out>) at
/home/mark/src/binutils-gdb/gdb/main.c:1105
#30 0x000000000045e375 in main (argc=<value optimized out>, argv=<value
optimized out>)
at /home/mark/src/binutils-gdb/gdb/gdb.c:33
And gdbarch_data is reached through:
#0 gdbarch_data (gdbarch=0x2540420, data=0x23e3d60) at
/home/mark/src/binutils-gdb/gdb/gdbarch.c:4499
#1 0x0000000000634582 in dwarf2_frame_signal_frame_p (self=0x816400,
this_frame=0x23eb710,
this_cache=<value optimized out>) at
/home/mark/src/binutils-gdb/gdb/dwarf2-frame.c:821
#2 dwarf2_frame_sniffer (self=0x816400, this_frame=0x23eb710,
this_cache=<value optimized out>)
at /home/mark/src/binutils-gdb/gdb/dwarf2-frame.c:1420
#3 0x0000000000689c53 in frame_unwind_try_unwinder (this_frame=0x23eb710,
this_cache=0x23eb728, unwinder=0x816400)
at /home/mark/src/binutils-gdb/gdb/frame-unwind.c:108
#4 0x0000000000689d4f in frame_unwind_find_by_frame (this_frame=0x23eb710,
this_cache=0x23eb728)
at /home/mark/src/binutils-gdb/gdb/frame-unwind.c:159
#5 0x0000000000686c9b in compute_frame_id (this_frame=0x23eb640) at
/home/mark/src/binutils-gdb/gdb/frame.c:457
#6 get_prev_frame_if_no_cycle (this_frame=0x23eb640) at
/home/mark/src/binutils-gdb/gdb/frame.c:1783
#7 0x0000000000688ad8 in get_prev_frame_always_1 (this_frame=0x23eb640)
at /home/mark/src/binutils-gdb/gdb/frame.c:1957
#8 get_prev_frame_always (this_frame=0x23eb640) at
/home/mark/src/binutils-gdb/gdb/frame.c:1974
#9 0x0000000000688fc8 in get_prev_frame (this_frame=0x23eb640) at
/home/mark/src/binutils-gdb/gdb/frame.c:2215
#10 0x00000000006891ac in unwind_to_current_frame (ui_out=<value optimized
out>, args=<value optimized out>)
at /home/mark/src/binutils-gdb/gdb/frame.c:1450
#11 0x00000000005b56f2 in catch_exceptions_with_msg (func_uiout=<value
optimized out>, func=
0x6891a0 <unwind_to_current_frame>, func_args=0x23eb640, gdberrmsg=0x0,
mask=RETURN_MASK_ERROR)
at /home/mark/src/binutils-gdb/gdb/exceptions.c:476
#12 0x00000000006867b0 in get_current_frame () at
/home/mark/src/binutils-gdb/gdb/frame.c:1489
#13 0x00000000005a81fe in handle_signal_stop (ecs=0x7fff3a3fcfc0) at
/home/mark/src/binutils-gdb/gdb/infrun.c:3969
#14 handle_inferior_event (ecs=0x7fff3a3fcfc0) at
/home/mark/src/binutils-gdb/gdb/infrun.c:3819
#15 0x00000000005a95bc in fetch_inferior_event (client_data=<value optimized
out>)
at /home/mark/src/binutils-gdb/gdb/infrun.c:2921
#16 0x00000000005c0479 in fetch_inferior_event_wrapper (client_data=<value
optimized out>)
at /home/mark/src/binutils-gdb/gdb/inf-loop.c:147
#17 0x00000000005b55fb in catch_errors (func=0x5c0470
<fetch_inferior_event_wrapper>, func_args=0x0, errstring=
0x78beca "", mask=RETURN_MASK_ALL) at
/home/mark/src/binutils-gdb/gdb/exceptions.c:524
#18 0x00000000005c01df in inferior_event_handler (event_type=INF_REG_EVENT,
client_data=0x0)
at /home/mark/src/binutils-gdb/gdb/inf-loop.c:55
#19 0x00000000005be4b4 in process_event () at
/home/mark/src/binutils-gdb/gdb/event-loop.c:343
#20 0x00000000005beeaf in gdb_do_one_event () at
/home/mark/src/binutils-gdb/gdb/event-loop.c:395
#21 0x00000000005bf085 in start_event_loop () at
/home/mark/src/binutils-gdb/gdb/event-loop.c:432
#22 0x00000000005b7fa3 in captured_command_loop (data=<value optimized out>)
at /home/mark/src/binutils-gdb/gdb/main.c:301
#23 0x00000000005b55fb in catch_errors (func=0x5b7f90 <captured_command_loop>,
func_args=0x0, errstring=
0x78beca "", mask=RETURN_MASK_ALL) at
/home/mark/src/binutils-gdb/gdb/exceptions.c:524
#24 0x00000000005b8b86 in captured_main (data=<value optimized out>) at
/home/mark/src/binutils-gdb/gdb/main.c:1097
#25 0x00000000005b55fb in catch_errors (func=0x5b8180 <captured_main>,
func_args=0x7fff3a3fd360, errstring=
0x78beca "", mask=RETURN_MASK_ALL) at
/home/mark/src/binutils-gdb/gdb/exceptions.c:524
#26 0x00000000005b7ddb in gdb_main (args=<value optimized out>) at
/home/mark/src/binutils-gdb/gdb/main.c:1105
#27 0x000000000045e375 in main (argc=<value optimized out>, argv=<value
optimized out>)
at /home/mark/src/binutils-gdb/gdb/gdb.c:33
Why is gdb even trying to unwind the frame here?
And finally the vfprintf that seems to eat up most of the time comes from:
#0 _IO_vfprintf_internal (s=0x7fff3a3fc860, format=0x8f47ff "%lx",
ap=0x7fff3a3fc9c0) at vfprintf.c:236
#1 0x0000003643c6fa52 in _IO_vsnprintf (string=0xbec610 "", maxlen=<value
optimized out>, format=0x8f47ff "%lx",
args=0x7fff3a3fc9c0) at vsnprintf.c:120
#2 0x00000000006ad3e5 in xsnprintf (str=<value optimized out>, size=50,
format=<value optimized out>)
at /home/mark/src/binutils-gdb/gdb/common/common-utils.c:148
#3 0x00000000006b47ba in phex_nz (l=<value optimized out>, sizeof_l=<value
optimized out>)
at /home/mark/src/binutils-gdb/gdb/common/print-utils.c:212
#4 0x00000000006b4912 in hex_string (num=<value optimized out>)
at /home/mark/src/binutils-gdb/gdb/common/print-utils.c:233
#5 0x00000000006357db in dwarf2_frame_cache (this_frame=0x23eb710,
this_cache=<value optimized out>)
at /home/mark/src/binutils-gdb/gdb/dwarf2-frame.c:1184
#6 0x0000000000635cae in dwarf2_frame_this_id (this_frame=0x23eb710,
this_cache=<value optimized out>, this_id=
0x23eb770) at /home/mark/src/binutils-gdb/gdb/dwarf2-frame.c:1270
#7 0x0000000000686ac3 in compute_frame_id (this_frame=0x23eb640) at
/home/mark/src/binutils-gdb/gdb/frame.c:461
#8 get_prev_frame_if_no_cycle (this_frame=0x23eb640) at
/home/mark/src/binutils-gdb/gdb/frame.c:1783
#9 0x0000000000688ad8 in get_prev_frame_always_1 (this_frame=0x23eb640)
at /home/mark/src/binutils-gdb/gdb/frame.c:1957
#10 get_prev_frame_always (this_frame=0x23eb640) at
/home/mark/src/binutils-gdb/gdb/frame.c:1974
#11 0x0000000000688fc8 in get_prev_frame (this_frame=0x23eb640) at
/home/mark/src/binutils-gdb/gdb/frame.c:2215
#12 0x00000000006891ac in unwind_to_current_frame (ui_out=<value optimized
out>, args=<value optimized out>)
at /home/mark/src/binutils-gdb/gdb/frame.c:1450
#13 0x00000000005b56f2 in catch_exceptions_with_msg (func_uiout=<value
optimized out>, func=
0x6891a0 <unwind_to_current_frame>, func_args=0x23eb640, gdberrmsg=0x0,
mask=RETURN_MASK_ERROR)
at /home/mark/src/binutils-gdb/gdb/exceptions.c:476
#14 0x00000000006867b0 in get_current_frame () at
/home/mark/src/binutils-gdb/gdb/frame.c:1489
#15 0x00000000005a81fe in handle_signal_stop (ecs=0x7fff3a3fcfc0) at
/home/mark/src/binutils-gdb/gdb/infrun.c:3969
#16 handle_inferior_event (ecs=0x7fff3a3fcfc0) at
/home/mark/src/binutils-gdb/gdb/infrun.c:3819
#17 0x00000000005a95bc in fetch_inferior_event (client_data=<value optimized
out>)
at /home/mark/src/binutils-gdb/gdb/infrun.c:2921
#18 0x00000000005c0479 in fetch_inferior_event_wrapper (client_data=<value
optimized out>)
at /home/mark/src/binutils-gdb/gdb/inf-loop.c:147
#19 0x00000000005b55fb in catch_errors (func=0x5c0470
<fetch_inferior_event_wrapper>, func_args=0x0, errstring=
0x78beca "", mask=RETURN_MASK_ALL) at
/home/mark/src/binutils-gdb/gdb/exceptions.c:524
#20 0x00000000005c01df in inferior_event_handler (event_type=INF_REG_EVENT,
client_data=0x0)
at /home/mark/src/binutils-gdb/gdb/inf-loop.c:55
#21 0x00000000005be4b4 in process_event () at
/home/mark/src/binutils-gdb/gdb/event-loop.c:343
#22 0x00000000005beeaf in gdb_do_one_event () at
/home/mark/src/binutils-gdb/gdb/event-loop.c:395
#23 0x00000000005bf085 in start_event_loop () at
/home/mark/src/binutils-gdb/gdb/event-loop.c:432
#24 0x00000000005b7fa3 in captured_command_loop (data=<value optimized out>)
at /home/mark/src/binutils-gdb/gdb/main.c:301
#25 0x00000000005b55fb in catch_errors (func=0x5b7f90 <captured_command_loop>,
func_args=0x0, errstring=
0x78beca "", mask=RETURN_MASK_ALL) at
/home/mark/src/binutils-gdb/gdb/exceptions.c:524
#26 0x00000000005b8b86 in captured_main (data=<value optimized out>) at
/home/mark/src/binutils-gdb/gdb/main.c:1097
#27 0x00000000005b55fb in catch_errors (func=0x5b8180 <captured_main>,
func_args=0x7fff3a3fd360, errstring=
0x78beca "", mask=RETURN_MASK_ALL) at
/home/mark/src/binutils-gdb/gdb/exceptions.c:524
#28 0x00000000005b7ddb in gdb_main (args=<value optimized out>) at
/home/mark/src/binutils-gdb/gdb/main.c:1105
#29 0x000000000045e375 in main (argc=<value optimized out>, argv=<value
optimized out>)
at /home/mark/src/binutils-gdb/gdb/gdb.c:33
--
You are receiving this mail because:
You are on the CC list for the bug.