From fe67a58f98232db44e620cd2bb450fca47635104 Mon Sep 17 00:00:00 2001 From: Simon Marchi Date: Tue, 29 Jun 2021 12:05:14 -0400 Subject: [PATCH] gdb: introduce FRAME_SCOPED_DEBUG_ENTER_EXIT Introduce FRAME_SCOPED_DEBUG_ENTER_EXIT and use it to print enter/exit messages in important frame-related functions. I think this helps understand which lower-level operations are done as part of which higher-level operation. And it helps visually skip over a higher-level operation you are not interested in. Here's an example, combined with some py-unwind messages: [frame] frame_unwind_find_by_frame: enter [frame] frame_unwind_find_by_frame: this_frame=0 [frame] frame_unwind_try_unwinder: trying unwinder "dummy" [frame] frame_unwind_try_unwinder: no [frame] frame_unwind_try_unwinder: trying unwinder "dwarf2 tailcall" [frame] frame_unwind_try_unwinder: no [frame] frame_unwind_try_unwinder: trying unwinder "inline" [frame] frame_unwind_try_unwinder: no [frame] frame_unwind_try_unwinder: trying unwinder "jit" [frame] frame_unwind_try_unwinder: no [frame] frame_unwind_try_unwinder: trying unwinder "python" [py-unwind] pyuw_sniffer: enter [frame] frame_unwind_register_value: enter [frame] frame_unwind_register_value: frame=-1, regnum=7(rsp) [frame] frame_unwind_register_value: -> register=7 bytes=[40ddffffff7f0000] [frame] frame_unwind_register_value: exit [py-unwind] pyuw_sniffer: frame=0, sp=0x7fffffffdd40, pc=0x5555555551ec [frame] frame_id_p: l={stack=,!code,special=0x0000000000000000} -> 1 [frame] frame_id_p: l={stack=,!code,special=0x0000000000000000} -> 1 [frame] frame_id_eq: l={stack=,!code,special=0x0000000000000000}, r={stack=,!code,special=0x0000000000000000} -> 1 [frame] frame_unwind_register_value: enter [frame] frame_unwind_register_value: frame=-1, regnum=6(rbp) [frame] frame_unwind_register_value: -> register=6 bytes=[50ddffffff7f0000] [frame] frame_unwind_register_value: exit [frame] frame_id_p: l={stack=,!code,special=0x0000000000000000} -> 1 [frame] frame_id_eq: l={stack=,!code,special=0x0000000000000000}, r={stack=,!code,special=0x0000000000000000} -> 1 [frame] get_prev_frame: enter [frame] get_prev_frame_always_1: enter [frame] get_prev_frame_always_1: this_frame=-1 [frame] get_prev_frame_always_1: -> {level=0,type=NORMAL_FRAME,unwind=0x5588ee3d17c0,pc=0x5555555551ec,id=,func=} // cached [frame] get_prev_frame_always_1: exit [frame] get_prev_frame: exit [frame] value_fetch_lazy_register: (frame=0, regnum=6(rbp), ...) -> register=6 bytes=[50ddffffff7f0000] [frame] frame_id_p: l={stack=,!code,special=0x0000000000000000} -> 1 [frame] frame_id_p: l={stack=,!code,special=0x0000000000000000} -> 1 [frame] frame_id_eq: l={stack=,!code,special=0x0000000000000000}, r={stack=,!code,special=0x0000000000000000} -> 1 [frame] frame_unwind_register_value: enter [frame] frame_unwind_register_value: frame=-1, regnum=7(rsp) [frame] frame_unwind_register_value: -> register=7 bytes=[40ddffffff7f0000] [frame] frame_unwind_register_value: exit [frame] frame_id_p: l={stack=,!code,special=0x0000000000000000} -> 1 [frame] frame_id_eq: l={stack=,!code,special=0x0000000000000000}, r={stack=,!code,special=0x0000000000000000} -> 1 [frame] get_prev_frame: enter [frame] get_prev_frame_always_1: enter [frame] get_prev_frame_always_1: this_frame=-1 [frame] get_prev_frame_always_1: -> {level=0,type=NORMAL_FRAME,unwind=0x5588ee3d1824,pc=0x5555555551ec,id=,func=} // cached [frame] get_prev_frame_always_1: exit [frame] get_prev_frame: exit [frame] value_fetch_lazy_register: (frame=0, regnum=7(rsp), ...) -> register=7 bytes=[40ddffffff7f0000] [frame] frame_id_p: l={stack=,!code,special=0x0000000000000000} -> 1 [frame] frame_id_p: l={stack=,!code,special=0x0000000000000000} -> 1 [frame] frame_id_eq: l={stack=,!code,special=0x0000000000000000}, r={stack=,!code,special=0x0000000000000000} -> 1 [frame] frame_unwind_register_value: enter [frame] frame_unwind_register_value: frame=-1, regnum=16(rip) [frame] frame_unwind_register_value: -> register=16 bytes=[ec51555555550000] [frame] frame_unwind_register_value: exit [frame] frame_id_p: l={stack=,!code,special=0x0000000000000000} -> 1 [frame] frame_id_eq: l={stack=,!code,special=0x0000000000000000}, r={stack=,!code,special=0x0000000000000000} -> 1 [frame] get_prev_frame: enter [frame] get_prev_frame_always_1: enter [frame] get_prev_frame_always_1: this_frame=-1 [frame] get_prev_frame_always_1: -> {level=0,type=NORMAL_FRAME,unwind=0x5588ee3d1888,pc=0x5555555551ec,id=,func=} // cached [frame] get_prev_frame_always_1: exit [frame] get_prev_frame: exit [frame] value_fetch_lazy_register: (frame=0, regnum=16(rip), ...) -> register=16 bytes=[ec51555555550000] [py-unwind] pyuw_sniffer: frame claimed by unwinder test unwinder [py-unwind] pyuw_sniffer: exit [frame] frame_unwind_try_unwinder: yes [frame] frame_unwind_find_by_frame: exit gdb/ChangeLog: * frame.h (FRAME_SCOPED_DEBUG_ENTER_EXIT): New. * frame.c (compute_frame_id, get_prev_frame_always_1, get_prev_frame): Use FRAME_SCOPED_DEBUG_ENTER_EXIT. * frame-unwind.c (frame_unwind_find_by_frame): Likewise. (frame_unwind_register_value): Likewise. Change-Id: I45b69b4ed962e70572bc55b8adfb211483c1eeed --- gdb/ChangeLog | 8 +++++++ gdb/frame-unwind.c | 1 + gdb/frame.c | 21 +++++++++++-------- gdb/frame.h | 6 ++++++ .../gdb.dwarf2/dw2-reg-undefined.exp | 4 ++-- 5 files changed, 29 insertions(+), 11 deletions(-) diff --git a/gdb/ChangeLog b/gdb/ChangeLog index db55c09870b..699bf6fe568 100644 --- a/gdb/ChangeLog +++ b/gdb/ChangeLog @@ -1,3 +1,11 @@ +2021-06-29 Simon Marchi + + * frame.h (FRAME_SCOPED_DEBUG_ENTER_EXIT): New. + * frame.c (compute_frame_id, get_prev_frame_always_1, + get_prev_frame): Use FRAME_SCOPED_DEBUG_ENTER_EXIT. + * frame-unwind.c (frame_unwind_find_by_frame): Likewise. + (frame_unwind_register_value): Likewise. + 2021-06-29 Simon Marchi * frame-unwind.h (struct frame_unwind) : New. Update diff --git a/gdb/frame-unwind.c b/gdb/frame-unwind.c index 0fef2c1540e..3dc303a49ad 100644 --- a/gdb/frame-unwind.c +++ b/gdb/frame-unwind.c @@ -178,6 +178,7 @@ frame_unwind_try_unwinder (struct frame_info *this_frame, void **this_cache, void frame_unwind_find_by_frame (struct frame_info *this_frame, void **this_cache) { + FRAME_SCOPED_DEBUG_ENTER_EXIT; frame_debug_printf ("this_frame=%d", frame_relative_level (this_frame)); struct gdbarch *gdbarch = get_frame_arch (this_frame); diff --git a/gdb/frame.c b/gdb/frame.c index 7b459680313..3f2d2700541 100644 --- a/gdb/frame.c +++ b/gdb/frame.c @@ -560,6 +560,8 @@ skip_tailcall_frames (struct frame_info *frame) static void compute_frame_id (struct frame_info *fi) { + FRAME_SCOPED_DEBUG_ENTER_EXIT; + gdb_assert (fi->this_id.p == frame_id_status::NOT_COMPUTED); unsigned int entry_generation = get_frame_cache_generation (); @@ -1215,12 +1217,10 @@ get_frame_register (struct frame_info *frame, struct value * frame_unwind_register_value (frame_info *next_frame, int regnum) { - struct gdbarch *gdbarch; - struct value *value; + FRAME_SCOPED_DEBUG_ENTER_EXIT; gdb_assert (next_frame != NULL); - gdbarch = frame_unwind_arch (next_frame); - + gdbarch *gdbarch = frame_unwind_arch (next_frame); frame_debug_printf ("frame=%d, regnum=%d(%s)", next_frame->level, regnum, user_reg_map_regnum_to_name (gdbarch, regnum)); @@ -1230,9 +1230,9 @@ frame_unwind_register_value (frame_info *next_frame, int regnum) frame_unwind_find_by_frame (next_frame, &next_frame->prologue_cache); /* Ask this frame to unwind its register. */ - value = next_frame->unwind->prev_register (next_frame, - &next_frame->prologue_cache, - regnum); + value *value = next_frame->unwind->prev_register (next_frame, + &next_frame->prologue_cache, + regnum); if (frame_debug) { @@ -2104,10 +2104,9 @@ get_prev_frame_if_no_cycle (struct frame_info *this_frame) static struct frame_info * get_prev_frame_always_1 (struct frame_info *this_frame) { - struct gdbarch *gdbarch; + FRAME_SCOPED_DEBUG_ENTER_EXIT; gdb_assert (this_frame != NULL); - gdbarch = get_frame_arch (this_frame); if (frame_debug) { @@ -2117,6 +2116,8 @@ get_prev_frame_always_1 (struct frame_info *this_frame) frame_debug_printf ("this_frame=nullptr"); } + struct gdbarch *gdbarch = get_frame_arch (this_frame); + /* Only try to do the unwind once. */ if (this_frame->prev_p) { @@ -2419,6 +2420,8 @@ inside_entry_func (frame_info *this_frame) struct frame_info * get_prev_frame (struct frame_info *this_frame) { + FRAME_SCOPED_DEBUG_ENTER_EXIT; + CORE_ADDR frame_pc; int frame_pc_p; diff --git a/gdb/frame.h b/gdb/frame.h index f8314ad66ce..0d2bc08a47b 100644 --- a/gdb/frame.h +++ b/gdb/frame.h @@ -71,6 +71,7 @@ #include "language.h" #include "cli/cli-option.h" +#include "gdbsupport/common-debug.h" struct symtab_and_line; struct frame_unwind; @@ -221,6 +222,11 @@ extern bool frame_debug; #define frame_debug_printf(fmt, ...) \ debug_prefixed_printf_cond (frame_debug, "frame", fmt, ##__VA_ARGS__) +/* Print "frame" enter/exit debug statements. */ + +#define FRAME_SCOPED_DEBUG_ENTER_EXIT \ + scoped_debug_enter_exit (frame_debug, "frame") + /* Construct a frame ID. The first parameter is the frame's constant stack address (typically the outer-bound), and the second the frame's constant code address (typically the entry point). diff --git a/gdb/testsuite/gdb.dwarf2/dw2-reg-undefined.exp b/gdb/testsuite/gdb.dwarf2/dw2-reg-undefined.exp index 2473a41a0de..b1c28b2f41c 100644 --- a/gdb/testsuite/gdb.dwarf2/dw2-reg-undefined.exp +++ b/gdb/testsuite/gdb.dwarf2/dw2-reg-undefined.exp @@ -79,8 +79,8 @@ for {set f 0} {$f < 3} {incr f} { # "not saved" and not "optimized out". gdb_test "set debug frame 1" gdb_test {print $rax} [multi_line \ - {\[frame\] frame_unwind_register_value: frame=0, regnum=0\(rax\)} \ - {\[frame\] frame_unwind_register_value: -> } \ + { \[frame\] frame_unwind_register_value: frame=0, regnum=0\(rax\)} \ + { \[frame\] frame_unwind_register_value: -> } \ {.*}] gdb_test "set debug frame 0" -- 2.30.2