[RFC PATCH] gdb: add linux_nat_debug_printf macro

classic Classic list List threaded Threaded
10 messages Options
Reply | Threaded
Open this post in threaded view
|

[RFC PATCH] gdb: add linux_nat_debug_printf macro

Sourceware - gdb-patches mailing list
From: Simon Marchi <[hidden email]>

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(-)

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 ())
--
2.27.0

Reply | Threaded
Open this post in threaded view
|

Re: [RFC PATCH] gdb: add linux_nat_debug_printf macro

Joel Brobecker
Hi Simon,

On Thu, Jul 02, 2020 at 03:30:34PM -0400, Simon Marchi via Gdb-patches wrote:

> From: Simon Marchi <[hidden email]>
>
> 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
Reply | Threaded
Open this post in threaded view
|

[PATCH] gdb: add linux_nat_debug_printf macro

Simon Marchi-4
On 2020-07-03 1:33 p.m., Joel Brobecker wrote:
> FWIW, this looks pretty nice to me :).

Thanks, here's the full patch then.

From fa85218469a5a21aacfad613c75fba60817ea531 Mon Sep 17 00:00:00 2001
From: Simon Marchi <[hidden email]>
Date: Wed, 8 Jul 2020 15:40:02 -0400
Subject: [PATCH] gdb: add linux_nat_debug_printf macro

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,
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.

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]

gdb/ChangeLog:

        * linux-nat.c (linux_nat_debug_printf): New function.
        (linux_nat_debug_printf_1): New macro.  Use throughout the file.

Change-Id: Ifcea3255b91400d3ad093cd0b75d3fac241cb998
---
 gdb/linux-nat.c | 619 ++++++++++++++++++------------------------------
 1 file changed, 226 insertions(+), 393 deletions(-)

diff --git a/gdb/linux-nat.c b/gdb/linux-nat.c
index fde360f5080a..3b5c803b83fd 100644
--- a/gdb/linux-nat.c
+++ b/gdb/linux-nat.c
@@ -198,6 +198,27 @@ show_debug_linux_nat (struct ui_file *file, int from_tty,
     value);
 }

+/* Print a debug statement.  Should be used through linux_nat_debug_printf.  */
+
+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;
@@ -535,10 +556,8 @@ linux_nat_target::follow_fork (bool follow_child, bool detach_fork)

   if (linux_supports_tracevforkdone ())
     {
-        if (debug_linux_nat)
-   fprintf_unfiltered (gdb_stdlog,
-      "LCFF: waiting for VFORK_DONE on %d\n",
-      parent_pid);
+      linux_nat_debug_printf ("waiting for VFORK_DONE on %d",
+      parent_pid);
       parent_lp->stopped = 1;

       /* We'll handle the VFORK_DONE event like any other
@@ -577,10 +596,7 @@ linux_nat_target::follow_fork (bool follow_child, bool detach_fork)
  is only the single-step breakpoint at vfork's return
  point.  */

-        if (debug_linux_nat)
-   fprintf_unfiltered (gdb_stdlog,
-    "LCFF: no VFORK_DONE "
-    "support, sleeping a bit\n");
+      linux_nat_debug_printf ("no VFORK_DONE support, sleeping a bit");

       usleep (10000);

@@ -1030,9 +1046,7 @@ linux_nat_post_attach_wait (ptid_t ptid, int *signalled)

   if (linux_proc_pid_is_stopped (pid))
     {
-      if (debug_linux_nat)
- fprintf_unfiltered (gdb_stdlog,
-    "LNPAW: Attaching to a stopped process\n");
+      linux_nat_debug_printf ("Attaching to a stopped process");

       /* The process is definitely stopped.  It is in a job control
  stop, unless the kernel predates the TASK_STOPPED /
@@ -1063,19 +1077,16 @@ linux_nat_post_attach_wait (ptid_t ptid, int *signalled)
   if (!WIFSTOPPED (status))
     {
       /* The pid we tried to attach has apparently just exited.  */
-      if (debug_linux_nat)
- fprintf_unfiltered (gdb_stdlog, "LNPAW: Failed to stop %d: %s",
-    pid, status_to_str (status));
+      linux_nat_debug_printf ("Failed to stop %d: %s", pid,
+      status_to_str (status));
       return status;
     }

   if (WSTOPSIG (status) != SIGSTOP)
     {
       *signalled = 1;
-      if (debug_linux_nat)
- fprintf_unfiltered (gdb_stdlog,
-    "LNPAW: Received %s after attaching\n",
-    status_to_str (status));
+      linux_nat_debug_printf ("Received %s after attaching",
+      status_to_str (status));
     }

   return status;
@@ -1125,13 +1136,10 @@ attach_proc_task_lwp_callback (ptid_t ptid)
   if (err == ESRCH
       || (err == EPERM && linux_proc_pid_is_gone (lwpid)))
     {
-      if (debug_linux_nat)
- {
-  fprintf_unfiltered (gdb_stdlog,
-      "Cannot attach to lwp %d: "
-      "thread is gone (%d: %s)\n",
-      lwpid, err, safe_strerror (err));
- }
+      linux_nat_debug_printf
+ ("Cannot attach to lwp %d: thread is gone (%d: %s)",
+ lwpid, err, safe_strerror (err));
+
     }
   else
     {
@@ -1144,10 +1152,8 @@ attach_proc_task_lwp_callback (ptid_t ptid)
  }
       else
  {
-  if (debug_linux_nat)
-    fprintf_unfiltered (gdb_stdlog,
- "PTRACE_ATTACH %s, 0, 0 (OK)\n",
- target_pid_to_str (ptid).c_str ());
+  linux_nat_debug_printf ("PTRACE_ATTACH %s, 0, 0 (OK)",
+  target_pid_to_str (ptid).c_str ());

   lp = add_lwp (ptid);

@@ -1249,10 +1255,8 @@ linux_nat_target::attach (const char *args, int from_tty)

   /* Save the wait status to report later.  */
   lp->resumed = 1;
-  if (debug_linux_nat)
-    fprintf_unfiltered (gdb_stdlog,
- "LNA: waitpid %ld, saving status %s\n",
- (long) lp->ptid.pid (), status_to_str (status));
+  linux_nat_debug_printf ("waitpid %ld, saving status %s",
+  (long) lp->ptid.pid (), status_to_str (status));

   lp->status = status;

@@ -1331,27 +1335,20 @@ get_detach_signal (struct lwp_info *lp)

   if (signo == GDB_SIGNAL_0)
     {
-      if (debug_linux_nat)
- fprintf_unfiltered (gdb_stdlog,
-    "GPT: lwp %s has no pending signal\n",
-    target_pid_to_str (lp->ptid).c_str ());
+      linux_nat_debug_printf ("lwp %s has no pending signal",
+      target_pid_to_str (lp->ptid).c_str ());
     }
   else if (!signal_pass_state (signo))
     {
-      if (debug_linux_nat)
- fprintf_unfiltered (gdb_stdlog,
-    "GPT: lwp %s had signal %s, "
-    "but it is in no pass state\n",
-    target_pid_to_str (lp->ptid).c_str (),
-    gdb_signal_to_string (signo));
+      linux_nat_debug_printf
+ ("lwp %s had signal %s but it is in no pass state",
+ target_pid_to_str (lp->ptid).c_str (), gdb_signal_to_string (signo));
     }
   else
     {
-      if (debug_linux_nat)
- fprintf_unfiltered (gdb_stdlog,
-    "GPT: lwp %s has pending signal %s\n",
-    target_pid_to_str (lp->ptid).c_str (),
-    gdb_signal_to_string (signo));
+      linux_nat_debug_printf ("lwp %s has pending signal %s",
+      target_pid_to_str (lp->ptid).c_str (),
+      gdb_signal_to_string (signo));

       return gdb_signal_to_host (signo);
     }
@@ -1371,18 +1368,16 @@ detach_one_lwp (struct lwp_info *lp, int *signo_p)

   gdb_assert (lp->status == 0 || WIFSTOPPED (lp->status));

-  if (debug_linux_nat && lp->status)
-    fprintf_unfiltered (gdb_stdlog, "DC:  Pending %s for %s on detach.\n",
- strsignal (WSTOPSIG (lp->status)),
- target_pid_to_str (lp->ptid).c_str ());
+  if (lp->status != 0)
+    linux_nat_debug_printf ("Pending %s for %s on detach.",
+    strsignal (WSTOPSIG (lp->status)),
+    target_pid_to_str (lp->ptid).c_str ());

   /* If there is a pending SIGSTOP, get rid of it.  */
   if (lp->signalled)
     {
-      if (debug_linux_nat)
- fprintf_unfiltered (gdb_stdlog,
-    "DC: Sending SIGCONT to %s\n",
-    target_pid_to_str (lp->ptid).c_str ());
+      linux_nat_debug_printf ("Sending SIGCONT to %s",
+      target_pid_to_str (lp->ptid).c_str ());

       kill_lwp (lwpid, SIGCONT);
       lp->signalled = 0;
@@ -1441,13 +1436,10 @@ detach_one_lwp (struct lwp_info *lp, int *signo_p)
  safe_strerror (save_errno));
  }
     }
-  else if (debug_linux_nat)
-    {
-      fprintf_unfiltered (gdb_stdlog,
-  "PTRACE_DETACH (%s, %s, 0) (OK)\n",
-  target_pid_to_str (lp->ptid).c_str (),
-  strsignal (signo));
-    }
+  else
+    linux_nat_debug_printf ("PTRACE_DETACH (%s, %s, 0) (OK)",
+    target_pid_to_str (lp->ptid).c_str (),
+    strsignal (signo));

   delete_lwp (lp->ptid);
 }
@@ -1603,39 +1595,29 @@ resume_lwp (struct lwp_info *lp, int step, enum gdb_signal signo)

       if (inf->vfork_child != NULL)
  {
-  if (debug_linux_nat)
-    fprintf_unfiltered (gdb_stdlog,
- "RC: Not resuming %s (vfork parent)\n",
- target_pid_to_str (lp->ptid).c_str ());
+  linux_nat_debug_printf ("Not resuming %s (vfork parent)",
+  target_pid_to_str (lp->ptid).c_str ());
  }
       else if (!lwp_status_pending_p (lp))
  {
-  if (debug_linux_nat)
-    fprintf_unfiltered (gdb_stdlog,
- "RC: Resuming sibling %s, %s, %s\n",
- target_pid_to_str (lp->ptid).c_str (),
- (signo != GDB_SIGNAL_0
- ? strsignal (gdb_signal_to_host (signo))
- : "0"),
- step ? "step" : "resume");
+  linux_nat_debug_printf ("Resuming sibling %s, %s, %s",
+  target_pid_to_str (lp->ptid).c_str (),
+  (signo != GDB_SIGNAL_0
+   ? strsignal (gdb_signal_to_host (signo))
+   : "0"),
+  step ? "step" : "resume");

   linux_resume_one_lwp (lp, step, signo);
  }
       else
  {
-  if (debug_linux_nat)
-    fprintf_unfiltered (gdb_stdlog,
- "RC: Not resuming sibling %s (has pending)\n",
- target_pid_to_str (lp->ptid).c_str ());
+  linux_nat_debug_printf ("Not resuming sibling %s (has pending)",
+  target_pid_to_str (lp->ptid).c_str ());
  }
     }
   else
-    {
-      if (debug_linux_nat)
- fprintf_unfiltered (gdb_stdlog,
-    "RC: Not resuming sibling %s (not stopped)\n",
+    linux_nat_debug_printf ("Not resuming sibling %s (not stopped)",
     target_pid_to_str (lp->ptid).c_str ());
-    }
 }

 /* Callback for iterate_over_lwps.  If LWP is EXCEPT, do nothing.
@@ -1687,14 +1669,12 @@ linux_nat_target::resume (ptid_t ptid, int step, enum gdb_signal signo)
   struct lwp_info *lp;
   int resume_many;

-  if (debug_linux_nat)
-    fprintf_unfiltered (gdb_stdlog,
- "LLR: Preparing to %s %s, %s, inferior_ptid %s\n",
- step ? "step" : "resume",
- target_pid_to_str (ptid).c_str (),
- (signo != GDB_SIGNAL_0
- ? strsignal (gdb_signal_to_host (signo)) : "0"),
- target_pid_to_str (inferior_ptid).c_str ());
+  linux_nat_debug_printf ("Preparing to %s %s, %s, inferior_ptid %s",
+  step ? "step" : "resume",
+  target_pid_to_str (ptid).c_str (),
+  (signo != GDB_SIGNAL_0
+   ? strsignal (gdb_signal_to_host (signo)) : "0"),
+  target_pid_to_str (inferior_ptid).c_str ());

   /* A specific PTID means `step only this process id'.  */
   resume_many = (minus_one_ptid == ptid
@@ -1729,10 +1709,8 @@ linux_nat_target::resume (ptid_t ptid, int step, enum gdb_signal signo)
   && WSTOPSIG (lp->status)
   && sigismember (&pass_mask, WSTOPSIG (lp->status)))
  {
-  if (debug_linux_nat)
-    fprintf_unfiltered (gdb_stdlog,
- "LLR: Not short circuiting for ignored "
- "status 0x%x\n", lp->status);
+  linux_nat_debug_printf
+    ("Not short circuiting for ignored status 0x%x", lp->status);

   /* FIXME: What should we do if we are supposed to continue
      this thread with a signal?  */
@@ -1748,10 +1726,8 @@ linux_nat_target::resume (ptid_t ptid, int step, enum gdb_signal signo)
  this thread with a signal?  */
       gdb_assert (signo == GDB_SIGNAL_0);

-      if (debug_linux_nat)
- fprintf_unfiltered (gdb_stdlog,
-    "LLR: Short circuiting for status 0x%x\n",
-    lp->status);
+      linux_nat_debug_printf ("Short circuiting for status 0x%x",
+      lp->status);

       if (target_can_async_p ())
  {
@@ -1768,13 +1744,11 @@ linux_nat_target::resume (ptid_t ptid, int step, enum gdb_signal signo)
        return linux_nat_resume_callback (info, lp);
      });

-  if (debug_linux_nat)
-    fprintf_unfiltered (gdb_stdlog,
- "LLR: %s %s, %s (resume event thread)\n",
- step ? "PTRACE_SINGLESTEP" : "PTRACE_CONT",
- target_pid_to_str (lp->ptid).c_str (),
- (signo != GDB_SIGNAL_0
- ? strsignal (gdb_signal_to_host (signo)) : "0"));
+  linux_nat_debug_printf ("%s %s, %s (resume event thread)",
+  step ? "PTRACE_SINGLESTEP" : "PTRACE_CONT",
+  target_pid_to_str (lp->ptid).c_str (),
+  (signo != GDB_SIGNAL_0
+   ? strsignal (gdb_signal_to_host (signo)) : "0"));

   linux_resume_one_lwp (lp, step, signo);

@@ -1836,13 +1810,9 @@ linux_handle_syscall_trap (struct lwp_info *lp, int stopping)
  actually get to execute.  It seems it would be even more
  confusing to the user.  */

-      if (debug_linux_nat)
- fprintf_unfiltered (gdb_stdlog,
-    "LHST: ignoring syscall %d "
-    "for LWP %ld (stopping threads), "
-    "resuming with PTRACE_CONT for SIGSTOP\n",
-    syscall_number,
-    lp->ptid.lwp ());
+      linux_nat_debug_printf
+ ("ignoring syscall %d for LWP %ld (stopping threads), resuming with "
+ "PTRACE_CONT for SIGSTOP", syscall_number, lp->ptid.lwp ());

       lp->syscall_state = TARGET_WAITKIND_IGNORE;
       ptrace (PTRACE_CONT, lp->ptid.lwp (), 0, 0);
@@ -1867,26 +1837,18 @@ linux_handle_syscall_trap (struct lwp_info *lp, int stopping)
   ourstatus->kind = lp->syscall_state;
   ourstatus->value.syscall_number = syscall_number;

-  if (debug_linux_nat)
-    fprintf_unfiltered (gdb_stdlog,
- "LHST: stopping for %s of syscall %d"
- " for LWP %ld\n",
- lp->syscall_state
- == TARGET_WAITKIND_SYSCALL_ENTRY
- ? "entry" : "return",
- syscall_number,
- lp->ptid.lwp ());
+  linux_nat_debug_printf
+    ("stopping for %s of syscall %d for LWP %ld",
+     (lp->syscall_state == TARGET_WAITKIND_SYSCALL_ENTRY
+      ? "entry" : "return"), syscall_number, lp->ptid.lwp ());
+
   return 0;
  }

-      if (debug_linux_nat)
- fprintf_unfiltered (gdb_stdlog,
-    "LHST: ignoring %s of syscall %d "
-    "for LWP %ld\n",
-    lp->syscall_state == TARGET_WAITKIND_SYSCALL_ENTRY
-    ? "entry" : "return",
-    syscall_number,
-    lp->ptid.lwp ());
+      linux_nat_debug_printf
+ ("ignoring %s of syscall %d for LWP %ld",
+ (lp->syscall_state == TARGET_WAITKIND_SYSCALL_ENTRY
+  ? "entry" : "return"), syscall_number, lp->ptid.lwp ());
     }
   else
     {
@@ -1906,13 +1868,9 @@ linux_handle_syscall_trap (struct lwp_info *lp, int stopping)

  The points above mean that the next resume, be it PT_STEP or
  PT_CONTINUE, can not trigger a syscall trace event.  */
-      if (debug_linux_nat)
- fprintf_unfiltered (gdb_stdlog,
-    "LHST: caught syscall event "
-    "with no syscall catchpoints."
-    " %d for LWP %ld, ignoring\n",
-    syscall_number,
-    lp->ptid.lwp ());
+      linux_nat_debug_printf
+ ("caught syscall event with no syscall catchpoints. %d for LWP %ld, "
+ "ignoring", syscall_number, lp->ptid.lwp ());
       lp->syscall_state = TARGET_WAITKIND_IGNORE;
     }

@@ -2017,11 +1975,8 @@ linux_handle_extended_wait (struct lwp_info *lp, int status)

   ourstatus->kind = TARGET_WAITKIND_IGNORE;

-  if (debug_linux_nat)
-    fprintf_unfiltered (gdb_stdlog,
- "LHEW: Got clone event "
- "from LWP %d, new child is LWP %ld\n",
- pid, new_pid);
+  linux_nat_debug_printf
+    ("Got clone event from LWP %d, new child is LWP %ld", pid, new_pid);

   new_lp = add_lwp (ptid_t (lp->ptid.pid (), new_pid, 0));
   new_lp->stopped = 1;
@@ -2060,12 +2015,9 @@ linux_handle_extended_wait (struct lwp_info *lp, int status)
       gdb_assert (new_lp->status == 0);

       /* Save the wait status to report later.  */
-      if (debug_linux_nat)
- fprintf_unfiltered (gdb_stdlog,
-    "LHEW: waitpid of new LWP %ld, "
-    "saving status %s\n",
-    (long) new_lp->ptid.lwp (),
-    status_to_str (status));
+      linux_nat_debug_printf
+ ("waitpid of new LWP %ld, saving status %s",
+ (long) new_lp->ptid.lwp (), status_to_str (status));
       new_lp->status = status;
     }
   else if (report_thread_events)
@@ -2082,10 +2034,7 @@ linux_handle_extended_wait (struct lwp_info *lp, int status)

   if (event == PTRACE_EVENT_EXEC)
     {
-      if (debug_linux_nat)
- fprintf_unfiltered (gdb_stdlog,
-    "LHEW: Got exec event from LWP %ld\n",
-    lp->ptid.lwp ());
+      linux_nat_debug_printf ("Got exec event from LWP %ld", lp->ptid.lwp ());

       ourstatus->kind = TARGET_WAITKIND_EXECD;
       ourstatus->value.execd_pathname
@@ -2102,21 +2051,17 @@ linux_handle_extended_wait (struct lwp_info *lp, int status)
     {
       if (current_inferior ()->waiting_for_vfork_done)
  {
-  if (debug_linux_nat)
-    fprintf_unfiltered (gdb_stdlog,
- "LHEW: Got expected PTRACE_EVENT_"
- "VFORK_DONE from LWP %ld: stopping\n",
- lp->ptid.lwp ());
+  linux_nat_debug_printf
+    ("Got expected PTRACE_EVENT_VFORK_DONE from LWP %ld: stopping",
+     lp->ptid.lwp ());

   ourstatus->kind = TARGET_WAITKIND_VFORK_DONE;
   return 0;
  }

-      if (debug_linux_nat)
- fprintf_unfiltered (gdb_stdlog,
-    "LHEW: Got PTRACE_EVENT_VFORK_DONE "
-    "from LWP %ld: ignoring\n",
-    lp->ptid.lwp ());
+      linux_nat_debug_printf
+ ("Got PTRACE_EVENT_VFORK_DONE from LWP %ld: ignoring", lp->ptid.lwp ());
+
       return 1;
     }

@@ -2130,8 +2075,7 @@ linux_handle_extended_wait (struct lwp_info *lp, int status)
 static void
 wait_for_signal ()
 {
-  if (debug_linux_nat)
-    fprintf_unfiltered (gdb_stdlog, "linux-nat: about to sigsuspend\n");
+  linux_nat_debug_printf ("about to sigsuspend");
   sigsuspend (&suspend_mask);

   /* If the quit flag is set, it means that the user pressed Ctrl-C
@@ -2175,9 +2119,8 @@ wait_lwp (struct lwp_info *lp)
      won't get an exit event.  See comments on exec events at
      the top of the file.  */
   thread_dead = 1;
-  if (debug_linux_nat)
-    fprintf_unfiltered (gdb_stdlog, "WL: %s vanished.\n",
- target_pid_to_str (lp->ptid).c_str ());
+  linux_nat_debug_printf ("%s vanished.",
+  target_pid_to_str (lp->ptid).c_str ());
  }
       if (pid != 0)
  break;
@@ -2200,10 +2143,8 @@ wait_lwp (struct lwp_info *lp)
   && linux_proc_pid_is_zombie (lp->ptid.lwp ()))
  {
   thread_dead = 1;
-  if (debug_linux_nat)
-    fprintf_unfiltered (gdb_stdlog,
- "WL: Thread group leader %s vanished.\n",
- target_pid_to_str (lp->ptid).c_str ());
+  linux_nat_debug_printf ("Thread group leader %s vanished.",
+  target_pid_to_str (lp->ptid).c_str ());
   break;
  }

@@ -2222,13 +2163,9 @@ wait_lwp (struct lwp_info *lp)
     {
       gdb_assert (pid == lp->ptid.lwp ());

-      if (debug_linux_nat)
- {
-  fprintf_unfiltered (gdb_stdlog,
-      "WL: waitpid %s received %s\n",
+      linux_nat_debug_printf ("waitpid %s received %s",
       target_pid_to_str (lp->ptid).c_str (),
       status_to_str (status));
- }

       /* Check if the thread has exited.  */
       if (WIFEXITED (status) || WIFSIGNALED (status))
@@ -2236,9 +2173,7 @@ wait_lwp (struct lwp_info *lp)
   if (report_thread_events
       || lp->ptid.pid () == lp->ptid.lwp ())
     {
-      if (debug_linux_nat)
- fprintf_unfiltered (gdb_stdlog, "WL: LWP %d exited.\n",
-    lp->ptid.pid ());
+      linux_nat_debug_printf ("LWP %d exited.", lp->ptid.pid ());

       /* If this is the leader exiting, it means the whole
  process is gone.  Store the status to report to the
@@ -2249,9 +2184,8 @@ wait_lwp (struct lwp_info *lp)
     }

   thread_dead = 1;
-  if (debug_linux_nat)
-    fprintf_unfiltered (gdb_stdlog, "WL: %s exited.\n",
- target_pid_to_str (lp->ptid).c_str ());
+  linux_nat_debug_printf ("%s exited.",
+  target_pid_to_str (lp->ptid).c_str ());
  }
     }

@@ -2295,10 +2229,7 @@ wait_lwp (struct lwp_info *lp)
   if (WIFSTOPPED (status) && WSTOPSIG (status) == SIGTRAP
       && linux_is_extended_waitstatus (status))
     {
-      if (debug_linux_nat)
- fprintf_unfiltered (gdb_stdlog,
-    "WL: Handling extended status 0x%06x\n",
-    status);
+      linux_nat_debug_printf ("Handling extended status 0x%06x", status);
       linux_handle_extended_wait (lp, status);
       return 0;
     }
@@ -2315,21 +2246,13 @@ stop_callback (struct lwp_info *lp)
     {
       int ret;

-      if (debug_linux_nat)
- {
-  fprintf_unfiltered (gdb_stdlog,
-      "SC:  kill %s **<SIGSTOP>**\n",
+      linux_nat_debug_printf ("kill %s **<SIGSTOP>**",
       target_pid_to_str (lp->ptid).c_str ());
- }
+
       errno = 0;
       ret = kill_lwp (lp->ptid.lwp (), SIGSTOP);
-      if (debug_linux_nat)
- {
-  fprintf_unfiltered (gdb_stdlog,
-      "SC:  lwp kill %d %s\n",
-      ret,
+      linux_nat_debug_printf ("lwp kill %d %s", ret,
       errno ? safe_strerror (errno) : "ERRNO-OK");
- }

       lp->signalled = 1;
       gdb_assert (lp->status == 0);
@@ -2417,10 +2340,8 @@ maybe_clear_ignore_sigint (struct lwp_info *lp)

   if (!linux_nat_has_pending_sigint (lp->ptid.lwp ()))
     {
-      if (debug_linux_nat)
- fprintf_unfiltered (gdb_stdlog,
-    "MCIS: Clearing bogus flag for %s\n",
-    target_pid_to_str (lp->ptid).c_str ());
+      linux_nat_debug_printf ("Clearing bogus flag for %s",
+      target_pid_to_str (lp->ptid).c_str ());
       lp->ignore_sigint = 0;
     }
 }
@@ -2516,12 +2437,10 @@ stop_wait_callback (struct lwp_info *lp)
   errno = 0;
   ptrace (PTRACE_CONT, lp->ptid.lwp (), 0, 0);
   lp->stopped = 0;
-  if (debug_linux_nat)
-    fprintf_unfiltered (gdb_stdlog,
- "PTRACE_CONT %s, 0, 0 (%s) "
- "(discarding SIGINT)\n",
- target_pid_to_str (lp->ptid).c_str (),
- errno ? safe_strerror (errno) : "OK");
+  linux_nat_debug_printf
+    ("PTRACE_CONT %s, 0, 0 (%s) (discarding SIGINT)",
+     target_pid_to_str (lp->ptid).c_str (),
+     errno ? safe_strerror (errno) : "OK");

   return stop_wait_callback (lp);
  }
@@ -2532,11 +2451,9 @@ stop_wait_callback (struct lwp_info *lp)
  {
   /* The thread was stopped with a signal other than SIGSTOP.  */

-  if (debug_linux_nat)
-    fprintf_unfiltered (gdb_stdlog,
- "SWC: Pending event %s in %s\n",
- status_to_str ((int) status),
- target_pid_to_str (lp->ptid).c_str ());
+  linux_nat_debug_printf ("Pending event %s in %s",
+  status_to_str ((int) status),
+  target_pid_to_str (lp->ptid).c_str ());

   /* Save the sigtrap event.  */
   lp->status = status;
@@ -2547,10 +2464,8 @@ stop_wait_callback (struct lwp_info *lp)
  {
   /* We caught the SIGSTOP that we intended to catch.  */

-  if (debug_linux_nat)
-    fprintf_unfiltered (gdb_stdlog,
- "SWC: Expected SIGSTOP caught for %s.\n",
- target_pid_to_str (lp->ptid).c_str ());
+  linux_nat_debug_printf ("Expected SIGSTOP caught for %s.",
+  target_pid_to_str (lp->ptid).c_str ());

   lp->signalled = 0;

@@ -2594,23 +2509,19 @@ status_callback (struct lwp_info *lp)

       if (pc != lp->stop_pc)
  {
-  if (debug_linux_nat)
-    fprintf_unfiltered (gdb_stdlog,
- "SC: PC of %s changed.  was=%s, now=%s\n",
- target_pid_to_str (lp->ptid).c_str (),
- paddress (target_gdbarch (), lp->stop_pc),
- paddress (target_gdbarch (), pc));
+  linux_nat_debug_printf ("PC of %s changed.  was=%s, now=%s",
+  target_pid_to_str (lp->ptid).c_str (),
+  paddress (target_gdbarch (), lp->stop_pc),
+  paddress (target_gdbarch (), pc));
   discard = 1;
  }

 #if !USE_SIGTRAP_SIGINFO
       else if (!breakpoint_inserted_here_p (regcache->aspace (), pc))
  {
-  if (debug_linux_nat)
-    fprintf_unfiltered (gdb_stdlog,
- "SC: previous breakpoint of %s, at %s gone\n",
- target_pid_to_str (lp->ptid).c_str (),
- paddress (target_gdbarch (), lp->stop_pc));
+  linux_nat_debug_printf ("previous breakpoint of %s, at %s gone",
+  target_pid_to_str (lp->ptid).c_str (),
+  paddress (target_gdbarch (), lp->stop_pc));

   discard = 1;
  }
@@ -2618,10 +2529,8 @@ status_callback (struct lwp_info *lp)

       if (discard)
  {
-  if (debug_linux_nat)
-    fprintf_unfiltered (gdb_stdlog,
- "SC: pending event of %s cancelled.\n",
- target_pid_to_str (lp->ptid).c_str ());
+  linux_nat_debug_printf ("pending event of %s cancelled.",
+  target_pid_to_str (lp->ptid).c_str ());

   lp->status = 0;
   linux_resume_one_lwp (lp, lp->step, GDB_SIGNAL_0);
@@ -2744,10 +2653,8 @@ save_stop_reason (struct lwp_info *lp)
     }
   else if (siginfo.si_code == TRAP_TRACE)
     {
-      if (debug_linux_nat)
- fprintf_unfiltered (gdb_stdlog,
-    "CSBB: %s stopped by trace\n",
-    target_pid_to_str (lp->ptid).c_str ());
+      linux_nat_debug_printf ("%s stopped by trace",
+      target_pid_to_str (lp->ptid).c_str ());

       /* We may have single stepped an instruction that
  triggered a watchpoint.  In that case, on some
@@ -2777,10 +2684,8 @@ save_stop_reason (struct lwp_info *lp)

   if (lp->stop_reason == TARGET_STOPPED_BY_SW_BREAKPOINT)
     {
-      if (debug_linux_nat)
- fprintf_unfiltered (gdb_stdlog,
-    "CSBB: %s stopped by software breakpoint\n",
-    target_pid_to_str (lp->ptid).c_str ());
+      linux_nat_debug_printf ("%s stopped by software breakpoint",
+      target_pid_to_str (lp->ptid).c_str ());

       /* Back up the PC if necessary.  */
       if (pc != sw_bp_pc)
@@ -2791,17 +2696,13 @@ save_stop_reason (struct lwp_info *lp)
     }
   else if (lp->stop_reason == TARGET_STOPPED_BY_HW_BREAKPOINT)
     {
-      if (debug_linux_nat)
- fprintf_unfiltered (gdb_stdlog,
-    "CSBB: %s stopped by hardware breakpoint\n",
-    target_pid_to_str (lp->ptid).c_str ());
+      linux_nat_debug_printf ("%s stopped by hardware breakpoint",
+      target_pid_to_str (lp->ptid).c_str ());
     }
   else if (lp->stop_reason == TARGET_STOPPED_BY_WATCHPOINT)
     {
-      if (debug_linux_nat)
- fprintf_unfiltered (gdb_stdlog,
-    "CSBB: %s stopped by hardware watchpoint\n",
-    target_pid_to_str (lp->ptid).c_str ());
+      linux_nat_debug_printf ("%s stopped by hardware watchpoint",
+      target_pid_to_str (lp->ptid).c_str ());
     }

   lp->stop_pc = pc;
@@ -2875,10 +2776,8 @@ select_event_lwp (ptid_t filter, struct lwp_info **orig_lp, int *status)
       event_lp = iterate_over_lwps (filter, select_singlestep_lwp_callback);
       if (event_lp != NULL)
  {
-  if (debug_linux_nat)
-    fprintf_unfiltered (gdb_stdlog,
- "SEL: Select single-step %s\n",
- target_pid_to_str (event_lp->ptid).c_str ());
+  linux_nat_debug_printf ("Select single-step %s",
+  target_pid_to_str (event_lp->ptid).c_str ());
  }
     }

@@ -2899,10 +2798,9 @@ select_event_lwp (ptid_t filter, struct lwp_info **orig_lp, int *status)
       random_selector = (int)
  ((num_events * (double) rand ()) / (RAND_MAX + 1.0));

-      if (debug_linux_nat && num_events > 1)
- fprintf_unfiltered (gdb_stdlog,
-    "SEL: Found %d events, selecting #%d\n",
-    num_events, random_selector);
+      if (num_events > 1)
+ linux_nat_debug_printf ("Found %d events, selecting #%d",
+ num_events, random_selector);

       event_lp
  = (iterate_over_lwps
@@ -2961,10 +2859,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;
@@ -2974,10 +2869,8 @@ linux_nat_filter_event (int lwpid, int status)

   if (WIFSTOPPED (status) && !lp)
     {
-      if (debug_linux_nat)
- fprintf_unfiltered (gdb_stdlog,
-    "LHEW: saving LWP %ld status %s in stopped_pids list\n",
-    (long) lwpid, status_to_str (status));
+      linux_nat_debug_printf ("saving LWP %ld status %s in stopped_pids list",
+      (long) lwpid, status_to_str (status));
       add_to_pid_list (&stopped_pids, lwpid, status);
       return NULL;
     }
@@ -3024,10 +2917,8 @@ linux_nat_filter_event (int lwpid, int status)
   if (WIFSTOPPED (status) && WSTOPSIG (status) == SIGTRAP
       && linux_is_extended_waitstatus (status))
     {
-      if (debug_linux_nat)
- fprintf_unfiltered (gdb_stdlog,
-    "LLW: Handling extended status 0x%06x\n",
-    status);
+      linux_nat_debug_printf ("Handling extended status 0x%06x", status);
+
       if (linux_handle_extended_wait (lp, status))
  return NULL;
     }
@@ -3038,10 +2929,8 @@ linux_nat_filter_event (int lwpid, int status)
       if (!report_thread_events
   && num_lwps (lp->ptid.pid ()) > 1)
  {
-  if (debug_linux_nat)
-    fprintf_unfiltered (gdb_stdlog,
- "LLW: %s exited.\n",
- target_pid_to_str (lp->ptid).c_str ());
+  linux_nat_debug_printf ("%s exited.",
+  target_pid_to_str (lp->ptid).c_str ());

   /* If there is at least one more LWP, then the exit signal
      was not the end of the debugged application and should be
@@ -3054,10 +2943,8 @@ linux_nat_filter_event (int lwpid, int status)
  exit, if e.g., some other thread brings down the whole
  process (calls `exit').  So don't assert that the lwp is
  resumed.  */
-      if (debug_linux_nat)
- fprintf_unfiltered (gdb_stdlog,
-    "LWP %ld exited (resumed=%d)\n",
-    lp->ptid.lwp (), lp->resumed);
+      linux_nat_debug_printf ("LWP %ld exited (resumed=%d)",
+      lp->ptid.lwp (), lp->resumed);

       /* Dead LWP's aren't expected to reported a pending sigstop.  */
       lp->signalled = 0;
@@ -3077,21 +2964,17 @@ linux_nat_filter_event (int lwpid, int status)

       if (lp->last_resume_kind == resume_stop)
  {
-  if (debug_linux_nat)
-    fprintf_unfiltered (gdb_stdlog,
- "LLW: resume_stop SIGSTOP caught for %s.\n",
- target_pid_to_str (lp->ptid).c_str ());
+  linux_nat_debug_printf ("resume_stop SIGSTOP caught for %s.",
+  target_pid_to_str (lp->ptid).c_str ());
  }
       else
  {
   /* This is a delayed SIGSTOP.  Filter out the event.  */

-  if (debug_linux_nat)
-    fprintf_unfiltered (gdb_stdlog,
- "LLW: %s %s, 0, 0 (discard delayed SIGSTOP)\n",
- lp->step ?
- "PTRACE_SINGLESTEP" : "PTRACE_CONT",
- target_pid_to_str (lp->ptid).c_str ());
+  linux_nat_debug_printf
+    ("%s %s, 0, 0 (discard delayed SIGSTOP)",
+     lp->step ? "PTRACE_SINGLESTEP" : "PTRACE_CONT",
+     target_pid_to_str (lp->ptid).c_str ());

   linux_resume_one_lwp (lp, lp->step, GDB_SIGNAL_0);
   gdb_assert (lp->resumed);
@@ -3104,21 +2987,16 @@ linux_nat_filter_event (int lwpid, int status)
   if (lp->ignore_sigint
       && WIFSTOPPED (status) && WSTOPSIG (status) == SIGINT)
     {
-      if (debug_linux_nat)
- fprintf_unfiltered (gdb_stdlog,
-    "LLW: Delayed SIGINT caught for %s.\n",
-    target_pid_to_str (lp->ptid).c_str ());
+      linux_nat_debug_printf ("Delayed SIGINT caught for %s.",
+      target_pid_to_str (lp->ptid).c_str ());

       /* This is a delayed SIGINT.  */
       lp->ignore_sigint = 0;

       linux_resume_one_lwp (lp, lp->step, GDB_SIGNAL_0);
-      if (debug_linux_nat)
- fprintf_unfiltered (gdb_stdlog,
-    "LLW: %s %s, 0, 0 (discard SIGINT)\n",
-    lp->step ?
-    "PTRACE_SINGLESTEP" : "PTRACE_CONT",
-    target_pid_to_str (lp->ptid).c_str ());
+      linux_nat_debug_printf ("%s %s, 0, 0 (discard SIGINT)",
+      lp->step ? "PTRACE_SINGLESTEP" : "PTRACE_CONT",
+      target_pid_to_str (lp->ptid).c_str ());
       gdb_assert (lp->resumed);

       /* Discard the event.  */
@@ -3165,15 +3043,12 @@ linux_nat_filter_event (int lwpid, int status)
   && !linux_wstatus_maybe_breakpoint (status))
  {
   linux_resume_one_lwp (lp, lp->step, signo);
-  if (debug_linux_nat)
-    fprintf_unfiltered (gdb_stdlog,
- "LLW: %s %s, %s (preempt 'handle')\n",
- lp->step ?
- "PTRACE_SINGLESTEP" : "PTRACE_CONT",
- target_pid_to_str (lp->ptid).c_str (),
- (signo != GDB_SIGNAL_0
- ? strsignal (gdb_signal_to_host (signo))
- : "0"));
+  linux_nat_debug_printf
+    ("%s %s, %s (preempt 'handle')",
+     lp->step ? "PTRACE_SINGLESTEP" : "PTRACE_CONT",
+     target_pid_to_str (lp->ptid).c_str (),
+     (signo != GDB_SIGNAL_0
+      ? strsignal (gdb_signal_to_host (signo)) : "0"));
   return NULL;
  }
     }
@@ -3205,11 +3080,9 @@ check_zombie_leaders (void)
   && num_lwps (inf->pid) > 1
   && linux_proc_pid_is_zombie (inf->pid))
  {
-  if (debug_linux_nat)
-    fprintf_unfiltered (gdb_stdlog,
- "CZL: Thread group leader %d zombie "
- "(it exited, or another thread execd).\n",
- inf->pid);
+  linux_nat_debug_printf ("Thread group leader %d zombie "
+  "(it exited, or another thread execd).",
+  inf->pid);

   /* A leader zombie can mean one of two things:

@@ -3229,10 +3102,7 @@ check_zombie_leaders (void)
      previous leader did exit voluntarily before some other
      thread execs).  */

-  if (debug_linux_nat)
-    fprintf_unfiltered (gdb_stdlog,
- "CZL: Thread group leader %d vanished.\n",
- inf->pid);
+  linux_nat_debug_printf ("Thread group leader %d vanished.", inf->pid);
   exit_lwp (leader_lp);
  }
     }
@@ -3271,8 +3141,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
@@ -3295,11 +3164,9 @@ linux_nat_wait_1 (ptid_t ptid, struct target_waitstatus *ourstatus,
   lp = iterate_over_lwps (ptid, status_callback);
   if (lp != NULL)
     {
-      if (debug_linux_nat)
- fprintf_unfiltered (gdb_stdlog,
-    "LLW: Using pending wait status %s for %s.\n",
-    status_to_str (lp->status),
-    target_pid_to_str (lp->ptid).c_str ());
+      linux_nat_debug_printf ("Using pending wait status %s for %s.",
+      status_to_str (lp->status),
+      target_pid_to_str (lp->ptid).c_str ());
     }

   /* But if we don't find a pending event, we'll have to wait.  Always
@@ -3326,19 +3193,14 @@ linux_nat_wait_1 (ptid_t ptid, struct target_waitstatus *ourstatus,
       errno = 0;
       lwpid = my_waitpid (-1, &status,  __WALL | WNOHANG);

-      if (debug_linux_nat)
- fprintf_unfiltered (gdb_stdlog,
-    "LNW: waitpid(-1, ...) returned %d, %s\n",
-    lwpid, errno ? safe_strerror (errno) : "ERRNO-OK");
+      linux_nat_debug_printf ("waitpid(-1, ...) returned %d, %s",
+      lwpid,
+      errno ? safe_strerror (errno) : "ERRNO-OK");

       if (lwpid > 0)
  {
-  if (debug_linux_nat)
-    {
-      fprintf_unfiltered (gdb_stdlog,
-  "LLW: waitpid %ld received %s\n",
+  linux_nat_debug_printf ("waitpid %ld received %s",
   (long) lwpid, status_to_str (status));
-    }

   linux_nat_filter_event (lwpid, status);
   /* Retry until nothing comes out of waitpid.  A single
@@ -3368,8 +3230,7 @@ linux_nat_wait_1 (ptid_t ptid, struct target_waitstatus *ourstatus,
  forever in the sigsuspend call below otherwise.  */
       if (iterate_over_lwps (ptid, resumed_callback) == NULL)
  {
-  if (debug_linux_nat)
-    fprintf_unfiltered (gdb_stdlog, "LLW: exit (no resumed LWP)\n");
+  linux_nat_debug_printf ("exit (no resumed LWP)");

   ourstatus->kind = TARGET_WAITKIND_NO_RESUMED;

@@ -3381,8 +3242,7 @@ linux_nat_wait_1 (ptid_t ptid, struct target_waitstatus *ourstatus,

       if (target_options & TARGET_WNOHANG)
  {
-  if (debug_linux_nat)
-    fprintf_unfiltered (gdb_stdlog, "LLW: exit (ignore)\n");
+  linux_nat_debug_printf ("exit (ignore)");

   ourstatus->kind = TARGET_WAITKIND_IGNORE;
   restore_child_signals_mask (&prev_mask);
@@ -3456,10 +3316,8 @@ linux_nat_wait_1 (ptid_t ptid, struct target_waitstatus *ourstatus,

   if (linux_target->low_status_is_event (status))
     {
-      if (debug_linux_nat)
- fprintf_unfiltered (gdb_stdlog,
-    "LLW: trap ptid is %s.\n",
-    target_pid_to_str (lp->ptid).c_str ());
+      linux_nat_debug_printf ("trap ptid is %s.",
+      target_pid_to_str (lp->ptid).c_str ());
     }

   if (lp->waitstatus.kind != TARGET_WAITKIND_IGNORE)
@@ -3470,8 +3328,7 @@ linux_nat_wait_1 (ptid_t ptid, struct target_waitstatus *ourstatus,
   else
     store_waitstatus (ourstatus, status);

-  if (debug_linux_nat)
-    fprintf_unfiltered (gdb_stdlog, "LLW: exit\n");
+  linux_nat_debug_printf ("exit");

   restore_child_signals_mask (&prev_mask);

@@ -3505,24 +3362,18 @@ resume_stopped_resumed_lwps (struct lwp_info *lp, const ptid_t wait_ptid)
 {
   if (!lp->stopped)
     {
-      if (debug_linux_nat)
- fprintf_unfiltered (gdb_stdlog,
-    "RSRL: NOT resuming LWP %s, not stopped\n",
-    target_pid_to_str (lp->ptid).c_str ());
+      linux_nat_debug_printf ("NOT resuming LWP %s, not stopped",
+      target_pid_to_str (lp->ptid).c_str ());
     }
   else if (!lp->resumed)
     {
-      if (debug_linux_nat)
- fprintf_unfiltered (gdb_stdlog,
-    "RSRL: NOT resuming LWP %s, not resumed\n",
-    target_pid_to_str (lp->ptid).c_str ());
+      linux_nat_debug_printf ("NOT resuming LWP %s, not resumed",
+      target_pid_to_str (lp->ptid).c_str ());
     }
   else if (lwp_status_pending_p (lp))
     {
-      if (debug_linux_nat)
- fprintf_unfiltered (gdb_stdlog,
-    "RSRL: NOT resuming LWP %s, has pending status\n",
-    target_pid_to_str (lp->ptid).c_str ());
+      linux_nat_debug_printf ("NOT resuming LWP %s, has pending status",
+      target_pid_to_str (lp->ptid).c_str ());
     }
   else
     {
@@ -3544,13 +3395,10 @@ resume_stopped_resumed_lwps (struct lwp_info *lp, const ptid_t wait_ptid)

   if (!leave_stopped)
     {
-      if (debug_linux_nat)
- fprintf_unfiltered (gdb_stdlog,
-    "RSRL: resuming stopped-resumed LWP %s at "
-    "%s: step=%d\n",
-    target_pid_to_str (lp->ptid).c_str (),
-    paddress (gdbarch, pc),
-    lp->step);
+      linux_nat_debug_printf
+ ("resuming stopped-resumed LWP %s at %s: step=%d",
+ target_pid_to_str (lp->ptid).c_str (), paddress (gdbarch, pc),
+ lp->step);

       linux_resume_one_lwp_throw (lp, lp->step, GDB_SIGNAL_0);
     }
@@ -3571,14 +3419,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 ())
@@ -3621,13 +3463,14 @@ kill_one_lwp (pid_t pid)

   errno = 0;
   kill_lwp (pid, SIGKILL);
+
   if (debug_linux_nat)
     {
       int save_errno = errno;

-      fprintf_unfiltered (gdb_stdlog,
-  "KC:  kill (SIGKILL) %ld, 0, 0 (%s)\n", (long) pid,
-  save_errno ? safe_strerror (save_errno) : "OK");
+      linux_nat_debug_printf
+ ("kill (SIGKILL) %ld, 0, 0 (%s)", (long) pid,
+ save_errno != 0 ? safe_strerror (save_errno) : "OK");
     }

   /* Some kernels ignore even SIGKILL for processes under ptrace.  */
@@ -3638,9 +3481,9 @@ kill_one_lwp (pid_t pid)
     {
       int save_errno = errno;

-      fprintf_unfiltered (gdb_stdlog,
-  "KC:  PTRACE_KILL %ld, 0, 0 (%s)\n", (long) pid,
-  save_errno ? safe_strerror (save_errno) : "OK");
+      linux_nat_debug_printf
+ ("PTRACE_KILL %ld, 0, 0 (%s)", (long) pid,
+ save_errno ? safe_strerror (save_errno) : "OK");
     }
 }

@@ -3660,10 +3503,8 @@ kill_wait_one_lwp (pid_t pid)
       res = my_waitpid (pid, NULL, __WALL);
       if (res != (pid_t) -1)
  {
-  if (debug_linux_nat)
-    fprintf_unfiltered (gdb_stdlog,
- "KWC: wait %ld received unknown.\n",
- (long) pid);
+  linux_nat_debug_printf ("wait %ld received unknown.", (long) pid);
+
   /* The Linux kernel sometimes fails to kill a thread
      completely after PTRACE_KILL; that goes from the stop
      point in do_fork out to the one in get_signal_to_deliver
@@ -4311,19 +4152,14 @@ linux_nat_stop_lwp (struct lwp_info *lwp)
 {
   if (!lwp->stopped)
     {
-      if (debug_linux_nat)
- fprintf_unfiltered (gdb_stdlog,
-    "LNSL: running -> suspending %s\n",
-    target_pid_to_str (lwp->ptid).c_str ());
+      linux_nat_debug_printf ("running -> suspending %s",
+      target_pid_to_str (lwp->ptid).c_str ());


       if (lwp->last_resume_kind == resume_stop)
  {
-  if (debug_linux_nat)
-    fprintf_unfiltered (gdb_stdlog,
- "linux-nat: already stopping LWP %ld at "
- "GDB's request\n",
- lwp->ptid.lwp ());
+  linux_nat_debug_printf ("already stopping LWP %ld at GDB's request",
+  lwp->ptid.lwp ());
   return 0;
  }

@@ -4337,14 +4173,11 @@ linux_nat_stop_lwp (struct lwp_info *lwp)
       if (debug_linux_nat)
  {
   if (find_thread_ptid (linux_target, lwp->ptid)->stop_requested)
-    fprintf_unfiltered (gdb_stdlog,
- "LNSL: already stopped/stop_requested %s\n",
- target_pid_to_str (lwp->ptid).c_str ());
+    linux_nat_debug_printf ("already stopped/stop_requested %s",
+    target_pid_to_str (lwp->ptid).c_str ());
   else
-    fprintf_unfiltered (gdb_stdlog,
- "LNSL: already stopped/no "
- "stop_requested yet %s\n",
- target_pid_to_str (lwp->ptid).c_str ());
+    linux_nat_debug_printf ("already stopped/no stop_requested yet %s",
+    target_pid_to_str (lwp->ptid).c_str ());
  }
     }
   return 0;
--
2.26.2


Reply | Threaded
Open this post in threaded view
|

Re: [PATCH] gdb: add linux_nat_debug_printf macro

Sourceware - gdb-patches mailing list
Simon Marchi wrote:

> diff --git a/gdb/linux-nat.c b/gdb/linux-nat.c
> index fde360f5080a..3b5c803b83fd 100644
> --- a/gdb/linux-nat.c
> +++ b/gdb/linux-nat.c
> @@ -198,6 +198,27 @@ show_debug_linux_nat (struct ui_file *file, int from_tty,
>      value);
>  }
>
> +/* Print a debug statement.  Should be used through linux_nat_debug_printf.  */
> +
> +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");
> +}

Would it be useful to use debug_printf and debug_vprintf here?

Thanks,
Gary

--
Gary Benson - he / him / his
Principal Software Engineer, Red Hat

Reply | Threaded
Open this post in threaded view
|

Re: [PATCH] gdb: add linux_nat_debug_printf macro

Simon Marchi-4
On 2020-07-10 7:47 a.m., Gary Benson via Gdb-patches wrote:

> Simon Marchi wrote:
>> diff --git a/gdb/linux-nat.c b/gdb/linux-nat.c
>> index fde360f5080a..3b5c803b83fd 100644
>> --- a/gdb/linux-nat.c
>> +++ b/gdb/linux-nat.c
>> @@ -198,6 +198,27 @@ show_debug_linux_nat (struct ui_file *file, int from_tty,
>>      value);
>>  }
>>
>> +/* Print a debug statement.  Should be used through linux_nat_debug_printf.  */
>> +
>> +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");
>> +}
>
> Would it be useful to use debug_printf and debug_vprintf here?
>
> Thanks,
> Gary

Indeed, I think the result would be the same, and it seems to exist for this purpose.  I've
replaced locally the implementation of linux_nat_debug_printf_1 with:

static void ATTRIBUTE_PRINTF (2, 3)
linux_nat_debug_printf_1 (const char *func_name, const char *fmt, ...)
{
  debug_printf ("[linux-nat] %s: ", func_name);

  va_list ap;
  va_start (ap, fmt);
  debug_vprintf (fmt, ap);
  va_end (ap);

  debug_printf ("\n");
}

Simon
Reply | Threaded
Open this post in threaded view
|

Re: [PATCH] gdb: add linux_nat_debug_printf macro

Sourceware - gdb-patches mailing list
Simon Marchi wrote:

> On 2020-07-10 7:47 a.m., Gary Benson via Gdb-patches wrote:
> > Simon Marchi wrote:
> > > diff --git a/gdb/linux-nat.c b/gdb/linux-nat.c
> > > index fde360f5080a..3b5c803b83fd 100644
> > > --- a/gdb/linux-nat.c
> > > +++ b/gdb/linux-nat.c
> > > @@ -198,6 +198,27 @@ show_debug_linux_nat (struct ui_file *file, int from_tty,
> > >      value);
> > >  }
> > >
> > > +/* Print a debug statement.  Should be used through linux_nat_debug_printf.  */
> > > +
> > > +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");
> > > +}
> >
> > Would it be useful to use debug_printf and debug_vprintf here?
>
> Indeed, I think the result would be the same, and it seems to exist for this purpose.  I've
> replaced locally the implementation of linux_nat_debug_printf_1 with:
>
> static void ATTRIBUTE_PRINTF (2, 3)
> linux_nat_debug_printf_1 (const char *func_name, const char *fmt, ...)
> {
>   debug_printf ("[linux-nat] %s: ", func_name);
>
>   va_list ap;
>   va_start (ap, fmt);
>   debug_vprintf (fmt, ap);
>   va_end (ap);
>
>   debug_printf ("\n");
> }

Awesome, thanks Simon.

Cheers,
Gary

--
Gary Benson - he / him / his
Principal Software Engineer, Red Hat

Reply | Threaded
Open this post in threaded view
|

Re: [RFC PATCH] gdb: add linux_nat_debug_printf macro

Tom Tromey-2
In reply to this post by Sourceware - gdb-patches mailing list
>>>>> "Simon" == Simon Marchi via Gdb-patches <[hidden email]> 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
Reply | Threaded
Open this post in threaded view
|

Re: [PATCH] gdb: add linux_nat_debug_printf macro

Joel Brobecker
In reply to this post by Simon Marchi-4
Hi Simon,

On Fri, Jul 10, 2020 at 09:55:40AM -0400, Simon Marchi wrote:

> On 2020-07-10 7:47 a.m., Gary Benson via Gdb-patches wrote:
> > Simon Marchi wrote:
> >> diff --git a/gdb/linux-nat.c b/gdb/linux-nat.c
> >> index fde360f5080a..3b5c803b83fd 100644
> >> --- a/gdb/linux-nat.c
> >> +++ b/gdb/linux-nat.c
> >> @@ -198,6 +198,27 @@ show_debug_linux_nat (struct ui_file *file, int from_tty,
> >>      value);
> >>  }
> >>
> >> +/* Print a debug statement.  Should be used through linux_nat_debug_printf.  */
> >> +
> >> +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");
> >> +}
> >
> > Would it be useful to use debug_printf and debug_vprintf here?
> >
> > Thanks,
> > Gary
>
> Indeed, I think the result would be the same, and it seems to exist for this purpose.  I've
> replaced locally the implementation of linux_nat_debug_printf_1 with:
>
> static void ATTRIBUTE_PRINTF (2, 3)
> linux_nat_debug_printf_1 (const char *func_name, const char *fmt, ...)
> {
>   debug_printf ("[linux-nat] %s: ", func_name);
>
>   va_list ap;
>   va_start (ap, fmt);
>   debug_vprintf (fmt, ap);
>   va_end (ap);
>
>   debug_printf ("\n");
> }

I skimmed through the patch, and it looked good to me.

Thanks again for doing that. That's a nice improvement.

Thinking out loud (and certainly not a suggestion or request that
you take care of the implementation): I'm wondering if we should be
thinking about generalizing this approach, somehow. For instance,
if we a function that took not just a func name, but also the name
of the unit:

    unit_debug_vprintf (const char *module_name, const char *func_name,
                        const char *fmt, ...)

... or perhaps more generally:

    unit_debug_vprintf (const char *label, const char *func_name,
                        const char *fmt, ...)

... then all modules would have to do to have consistent logging
is to define one macro.

--
Joel
Reply | Threaded
Open this post in threaded view
|

Re: [PATCH] gdb: add linux_nat_debug_printf macro

Simon Marchi-4
On 2020-07-13 10:32 a.m., Joel Brobecker wrote:

> I skimmed through the patch, and it looked good to me.
>
> Thanks again for doing that. That's a nice improvement.
>
> Thinking out loud (and certainly not a suggestion or request that
> you take care of the implementation): I'm wondering if we should be
> thinking about generalizing this approach, somehow. For instance,
> if we a function that took not just a func name, but also the name
> of the unit:
>
>     unit_debug_vprintf (const char *module_name, const char *func_name,
>                         const char *fmt, ...)
>
> ... or perhaps more generally:
>
>     unit_debug_vprintf (const char *label, const char *func_name,
>                         const char *fmt, ...)
>
> ... then all modules would have to do to have consistent logging
> is to define one macro.
>
> --
> Joel
>

Yes, if people like the format I'd be open to changing other "modules" to
use it, and having a generic function to ensure the same formatting is used
everywhere would be the logical thing to do.

Simon
Reply | Threaded
Open this post in threaded view
|

Re: [PATCH] gdb: add linux_nat_debug_printf macro

Sourceware - gdb-patches mailing list
Simon Marchi wrote:

> On 2020-07-13 10:32 a.m., Joel Brobecker wrote:
> > I skimmed through the patch, and it looked good to me.
> >
> > Thanks again for doing that. That's a nice improvement.
> >
> > Thinking out loud (and certainly not a suggestion or request that
> > you take care of the implementation): I'm wondering if we should be
> > thinking about generalizing this approach, somehow. For instance,
> > if we a function that took not just a func name, but also the name
> > of the unit:
> >
> >     unit_debug_vprintf (const char *module_name, const char *func_name,
> >                         const char *fmt, ...)
> >
> > ... or perhaps more generally:
> >
> >     unit_debug_vprintf (const char *label, const char *func_name,
> >                         const char *fmt, ...)
> >
> > ... then all modules would have to do to have consistent logging
> > is to define one macro.
>
> Yes, if people like the format I'd be open to changing other
> "modules" to use it, and having a generic function to ensure the
> same formatting is used everywhere would be the logical thing to do.

I like it :)

Cheers,
Gary

--
Gary Benson - he / him / his
Principal Software Engineer, Red Hat