[PATCH 2/4] gdb/py: convert debug logging in py-unwind to use new scheme

[Andrew Burgess]

* Simon Marchi <simon.marchi@polymtl.ca> [2021-05-08 20:32:13 -0400]:

> On 2021-05-08 1:07 p.m., Andrew Burgess wrote:
> > Converts the debug print out in python/py-unwind.c to use the new
> > debug printing scheme.  I have also modified what is printed in a few
> > places, for example, rather than printing frame pointers, I now print
> > the frame level, this matches what we do in the general 'set debug
> > frame' tracing, and is usually more helpful (I think).
> > 
> > I also added a couple of ENTER/EXIT scope printers.
> > 
> > gdb/ChangeLog:
> > 
> > 	* python/py-unwind.c (pyuw_debug): Convert to bool.
> > 	(show_pyuw_debug): New function.
> > 	(pyuw_debug_printf): Define.
> > 	(PYUW_SCOPED_DEBUG_ENTER_EXIT): Define.
> > 	(pyuw_this_id): Convert to new debug print macros.
> > 	(pyuw_prev_register): Likewise.
> > 	(pyuw_sniffer): Likewise.
> > 	(pyuw_dealloc_cache): Likewise.
> > 	(_initialize_py_unwind): Update now pyuw_debug is a bool, and add
> > 	show function when registering.
> > ---
> >  gdb/ChangeLog          | 13 ++++++++++
> >  gdb/python/py-unwind.c | 54 +++++++++++++++++++++++++++++-------------
> >  2 files changed, 51 insertions(+), 16 deletions(-)
> > 
> > diff --git a/gdb/python/py-unwind.c b/gdb/python/py-unwind.c
> > index c82fa3dbe97..6dc1502acd3 100644
> > --- a/gdb/python/py-unwind.c
> > +++ b/gdb/python/py-unwind.c
> > @@ -28,8 +28,28 @@
> >  #include "regcache.h"
> >  #include "valprint.h"
> >  
> > -#define TRACE_PY_UNWIND(level, args...) if (pyuw_debug >= level)  \
> > -  { fprintf_unfiltered (gdb_stdlog, args); }
> > +/* Debugging of Python unwinders.  */
> > +
> > +static bool pyuw_debug;
> > +
> > +/* Implementation of "show debug py-unwind".  */
> > +
> > +static void
> > +show_pyuw_debug (struct ui_file *file, int from_tty,
> > +		 struct cmd_list_element *c, const char *value)
> > +{
> > +  fprintf_filtered (file, _("Python unwinder debugging is %s.\n"), value);
> > +}
> > +
> > +/* Print an "py-unwind" debug statement.  */
> > +
> > +#define pyuw_debug_printf(fmt, ...) \
> > +  debug_prefixed_printf_cond (pyuw_debug, "py_unwind",fmt, ##__VA_ARGS__)
> 
> Missing space before "fmt".  Did you copy this from infrun.h?  Because
> this one is missing that space too, and I keep copying it, and it makes
> me mad, but I've been to lazy to fix it...  one day I will.
> 
> So far the "component" names use dashes, not underscores (they
> typicallly match the "set debug" option that control them).  So I'd
> suggest using "py-unwind".
> 
> > +
> > +/* Print "py_unwind" enter/exit debug statements.  */
> > +
> > +#define PYUW_SCOPED_DEBUG_ENTER_EXIT \
> > +  scoped_debug_enter_exit (pyuw_debug, "py_unwind")
> >  
> >  struct pending_frame_object
> >  {
> > @@ -96,8 +116,6 @@ extern PyTypeObject pending_frame_object_type
> >  extern PyTypeObject unwind_info_object_type
> >      CPYCHECKER_TYPE_OBJECT_FOR_TYPEDEF ("unwind_info_object");
> >  
> > -static unsigned int pyuw_debug = 0;
> > -
> >  static struct gdbarch_data *pyuw_gdbarch_data;
> >  
> >  /* Convert gdb.Value instance to inferior's pointer.  Return 1 on success,
> > @@ -431,9 +449,7 @@ pyuw_this_id (struct frame_info *this_frame, void **cache_ptr,
> >  	      struct frame_id *this_id)
> >  {
> >    *this_id = ((cached_frame_info *) *cache_ptr)->frame_id;
> > -  if (pyuw_debug >= 1)
> > -    fprintf_unfiltered (gdb_stdlog, "%s: frame_id: %s\n", __FUNCTION__,
> > -			this_id->to_string ().c_str ());
> > +  pyuw_debug_printf ("frame_id: %s", this_id->to_string ().c_str ());
> >  }
> >  
> >  /* frame_unwind.prev_register.  */
> > @@ -442,12 +458,14 @@ static struct value *
> >  pyuw_prev_register (struct frame_info *this_frame, void **cache_ptr,
> >  		    int regnum)
> >  {
> > +  PYUW_SCOPED_DEBUG_ENTER_EXIT;
> > +
> >    cached_frame_info *cached_frame = (cached_frame_info *) *cache_ptr;
> >    cached_reg_t *reg_info = cached_frame->reg;
> >    cached_reg_t *reg_info_end = reg_info + cached_frame->reg_count;
> >  
> > -  TRACE_PY_UNWIND (1, "%s (frame=%p,...,reg=%d)\n", __FUNCTION__, this_frame,
> > -		   regnum);
> > +  pyuw_debug_printf ("frame=%d,reg=%d",
> > +		     frame_relative_level (this_frame), regnum);
> 
> I'd suggest using a space after the comma, it helps readability a bit.
> 
> >    for (; reg_info < reg_info_end; ++reg_info)
> >      {
> >        if (regnum == reg_info->num)
> > @@ -463,14 +481,17 @@ static int
> >  pyuw_sniffer (const struct frame_unwind *self, struct frame_info *this_frame,
> >  	      void **cache_ptr)
> >  {
> > +  PYUW_SCOPED_DEBUG_ENTER_EXIT;
> > +
> >    struct gdbarch *gdbarch = (struct gdbarch *) (self->unwind_data);
> >    cached_frame_info *cached_frame;
> >  
> >    gdbpy_enter enter_py (gdbarch, current_language);
> >  
> > -  TRACE_PY_UNWIND (3, "%s (SP=%s, PC=%s)\n", __FUNCTION__,
> > -		   paddress (gdbarch, get_frame_sp (this_frame)),
> > -		   paddress (gdbarch, get_frame_pc (this_frame)));
> > +  pyuw_debug_printf ("frame=%d, sp=%s, pc=%s",
> > +		     frame_relative_level (this_frame),
> > +		     paddress (gdbarch, get_frame_sp (this_frame)),
> > +		     paddress (gdbarch, get_frame_pc (this_frame)));
> >  
> >    /* Create PendingFrame instance to pass to sniffers.  */
> >    pending_frame_object *pfo = PyObject_New (pending_frame_object,
> > @@ -554,6 +575,7 @@ pyuw_sniffer (const struct frame_unwind *self, struct frame_info *this_frame,
> >    }
> >  
> >    *cache_ptr = cached_frame;
> > +  pyuw_debug_printf ("frame claimed");
> 
> I don't really know this area very well, so my request may not make
> sense, but is it possible that have multiple Python unwinders
> registered?  If so, is there a name (maybe the Python class name) we
> could print here, to say which unwinder claimed the frame?  I'm thinking
> it could help in case the unwinder that claims the frame is not the one
> you expect.

I'm not sure what helpful things could be printed here.  The actual
code that finds the "correct" unwinder is elsewhere (see
_execute_unwinders in python/lib/gdb/__init__.py), back in this C
function all we get given is a gdb.UnwindInfo object - and in most
cases that's all it will ever be, there's nothing really identifying
it as having come from any particular unwinder.

For now I've just left this as it is, but would be more than happy if
someone has a good idea for what could be printed.

Thanks,
Andrew