[RFC] gdb: add linux_nat_debug_printf macro

Message ID 20200702193034.22279-1-simon.marchi@efficios.com
State New
Headers show
Series
  • [RFC] gdb: add linux_nat_debug_printf macro
Related show

Commit Message

Jose E. Marchesi via Gdb-patches July 2, 2020, 7:30 p.m.
From: Simon Marchi <simon.marchi@polymtl.ca>


The debug prints inside linux-nat.c almost all have a prefix that
indicate in which function they are located.  This prefix is an
abbreviation of the function name.  For example, this print is in the
`linux_nat_post_attach_wait` function:

    if (debug_linux_nat)
      fprintf_unfiltered (gdb_stdlog,
                          "LNPAW: Attaching to a stopped process\n");

Over time, the code has changed, things were moved, and many of these
prefixes are not accurate anymore.  Also, unless you know the
linux-nat.c file by heart, it's a bit cryptic what LLR, LNW, RSRL, etc,
all mean.

To address both of these issues, I suggest adding this macro for
printing debug statements, which automatically includes the function
name.  It also includes the `[linux-nat]` prefix to clarify which part
of GDB printed this (I think that ideally, all debug prints would
include such a tag).

The `__func__` magic symbol is used to get the function name.
Unfortunately, in the case of methods, it only contains the method name,
not the class name.  So we'll get "wait", where I would have liked to
get "linux_nat_target::wait".  But at least with the `[linux-nat]` tag
in the front, it's not really ambiguous.

I've made the macro automatically include the trailing newline, because
it wouldn't make sense to call it twice to print two parts of one line,
because the `[linux-nat]` tag would be printed in the middle.

An advantage of this (IMO) is that it's less verbose, we don't have to
check for `if (debug_linux_nat)` everywhere.

Another advantage is that it's easier to customize the output later,
without having to touch all call sites.

I've changed just a few call sites, if this is deemed a good idea I'll
do the rest.  It's just that there are a lot of them, so I don't want to
do the work if the idea gets rejected in the end.

Here's an example of what it looks like in the end:

    [linux-nat] linux_nat_wait_1: enter
    [linux-nat] wait: [process -1], [TARGET_WNOHANG]

Change-Id: Ifcea3255b91400d3ad093cd0b75d3fac241cb998
---
 gdb/linux-nat.c | 37 +++++++++++++++++++++++--------------
 1 file changed, 23 insertions(+), 14 deletions(-)

-- 
2.27.0

Comments

Joel Brobecker July 3, 2020, 5:33 p.m. | #1
Hi Simon,

On Thu, Jul 02, 2020 at 03:30:34PM -0400, Simon Marchi via Gdb-patches wrote:
> From: Simon Marchi <simon.marchi@polymtl.ca>

> 

> The debug prints inside linux-nat.c almost all have a prefix that

> indicate in which function they are located.  This prefix is an

> abbreviation of the function name.  For example, this print is in the

> `linux_nat_post_attach_wait` function:

> 

>     if (debug_linux_nat)

>       fprintf_unfiltered (gdb_stdlog,

>                           "LNPAW: Attaching to a stopped process\n");

> 

> Over time, the code has changed, things were moved, and many of these

> prefixes are not accurate anymore.  Also, unless you know the

> linux-nat.c file by heart, it's a bit cryptic what LLR, LNW, RSRL, etc,

> all mean.

> 

> To address both of these issues, I suggest adding this macro for

> printing debug statements, which automatically includes the function

> name.  It also includes the `[linux-nat]` prefix to clarify which part

> of GDB printed this (I think that ideally, all debug prints would

> include such a tag).

> 

> The `__func__` magic symbol is used to get the function name.

> Unfortunately, in the case of methods, it only contains the method name,

> not the class name.  So we'll get "wait", where I would have liked to

> get "linux_nat_target::wait".  But at least with the `[linux-nat]` tag

> in the front, it's not really ambiguous.

> 

> I've made the macro automatically include the trailing newline, because

> it wouldn't make sense to call it twice to print two parts of one line,

> because the `[linux-nat]` tag would be printed in the middle.

> 

> An advantage of this (IMO) is that it's less verbose, we don't have to

> check for `if (debug_linux_nat)` everywhere.

> 

> Another advantage is that it's easier to customize the output later,

> without having to touch all call sites.

> 

> I've changed just a few call sites, if this is deemed a good idea I'll

> do the rest.  It's just that there are a lot of them, so I don't want to

> do the work if the idea gets rejected in the end.

> 

> Here's an example of what it looks like in the end:

> 

>     [linux-nat] linux_nat_wait_1: enter

>     [linux-nat] wait: [process -1], [TARGET_WNOHANG]


FWIW, this looks pretty nice to me :).

-- 
Joel
Tom Tromey July 12, 2020, 5:11 p.m. | #2
>>>>> "Simon" == Simon Marchi via Gdb-patches <gdb-patches@sourceware.org> writes:


Simon> To address both of these issues, I suggest adding this macro for
Simon> printing debug statements, which automatically includes the function
Simon> name.  It also includes the `[linux-nat]` prefix to clarify which part
Simon> of GDB printed this (I think that ideally, all debug prints would
Simon> include such a tag).

Yeah.  After seeing your patch I think all the debug prints should be
done this way.

Simon> The `__func__` magic symbol is used to get the function name.
Simon> Unfortunately, in the case of methods, it only contains the method name,

We could check for GCC and use __PRETTY_FUNCTION__, though that is the
full signature, so it might be pretty long.

Tom

Patch

diff --git a/gdb/linux-nat.c b/gdb/linux-nat.c
index fde360f5080..bbe2fcb859b 100644
--- a/gdb/linux-nat.c
+++ b/gdb/linux-nat.c
@@ -198,6 +198,25 @@  show_debug_linux_nat (struct ui_file *file, int from_tty,
 		    value);
 }
 
+static void ATTRIBUTE_PRINTF (2, 3)
+linux_nat_debug_printf_1 (const char *func_name, const char *fmt, ...)
+{
+  fprintf_unfiltered (gdb_stdlog, "[linux-nat] %s: ", func_name);
+
+  va_list ap;
+  va_start (ap, fmt);
+  vfprintf_unfiltered (gdb_stdlog, fmt, ap);
+  va_end (ap);
+
+  fprintf_unfiltered (gdb_stdlog, "\n");
+}
+
+#define linux_nat_debug_printf(fmt, ...) \
+  do { \
+    if (debug_linux_nat) \
+      linux_nat_debug_printf_1 (__func__, fmt, ##__VA_ARGS__); \
+  } while (0)
+
 struct simple_pid_list
 {
   int pid;
@@ -2961,10 +2980,7 @@  linux_nat_filter_event (int lwpid, int status)
       && (WSTOPSIG (status) == SIGTRAP && event == PTRACE_EVENT_EXEC))
     {
       /* A multi-thread exec after we had seen the leader exiting.  */
-      if (debug_linux_nat)
-	fprintf_unfiltered (gdb_stdlog,
-			    "LLW: Re-adding thread group leader LWP %d.\n",
-			    lwpid);
+      linux_nat_debug_printf ("Re-adding thread group leader LWP %d.", lwpid);
 
       lp = add_lwp (ptid_t (lwpid, lwpid, 0));
       lp->stopped = 1;
@@ -3271,8 +3287,7 @@  linux_nat_wait_1 (ptid_t ptid, struct target_waitstatus *ourstatus,
   struct lwp_info *lp;
   int status;
 
-  if (debug_linux_nat)
-    fprintf_unfiltered (gdb_stdlog, "LLW: enter\n");
+  linux_nat_debug_printf ("enter");
 
   /* The first time we get here after starting a new inferior, we may
      not have added it to the LWP list yet - this is the earliest
@@ -3571,14 +3586,8 @@  linux_nat_target::wait (ptid_t ptid, struct target_waitstatus *ourstatus,
 {
   ptid_t event_ptid;
 
-  if (debug_linux_nat)
-    {
-      std::string options_string = target_options_to_string (target_options);
-      fprintf_unfiltered (gdb_stdlog,
-			  "linux_nat_wait: [%s], [%s]\n",
-			  target_pid_to_str (ptid).c_str (),
-			  options_string.c_str ());
-    }
+  linux_nat_debug_printf ("[%s], [%s]", target_pid_to_str (ptid).c_str (),
+			  target_options_to_string (target_options).c_str ());
 
   /* Flush the async file first.  */
   if (target_is_async_p ())