This is the mail archive of the gdb-patches@sourceware.org mailing list for the GDB project.


Index Nav: [Date Index] [Subject Index] [Author Index] [Thread Index]
Message Nav: [Date Prev] [Date Next] [Thread Prev] [Thread Next]
Other format: [Raw text]

Re: [RFC] output remote protocol timestamps with "set debug remote"


On Tuesday 18 November 2008 21:45:35, Daniel Jacobowitz wrote:
> On Fri, Nov 14, 2008 at 06:50:28PM +0000, Pedro Alves wrote:
> > I'm making use of this:
> > 
> >  /* Debugging level.  0 is off, and non-zero values mean to print some debug
> >     information (higher values, more information).  */
> >  extern int remote_debug;
> > 
> > ... to enable timestamps, you do "set debug remote 2".  level 1
> > still outputs the same as usual.
> 
> It's such a good idea, that it's already there :-)  "set debug
> timestamp".  However, I'd never tried it with remote; it clearly
> does not work right for multiple printf calls in a single debugging
> message.  I'd suggest fixing that, instead.

Ah, sneaky!  I missed that going in.

> 1227044669:904148 Sending packet: 1227044669:904155 $1227044669:904161
> q1227044669:904166 S1227044669:904172 y1227044669:904177
> m1227044669:904182 b1227044669:904188 o1227044669:904193
> l1227044669:904198 :1227044669:904205 :1227044669:904211
> #1227044669:904217 51227044669:904222 b1227044669:904228
> ...1227044669:904279 Ack

That attached patch make two changes to address this.

1) Makes sure that timestamped output always ends with a newline, so we
   get this,

  un-timestamped, like before, unchanged:

    Sending packet: $m80484d1,1#67... Packet received: 51

  and timestamped:

    1227058218:708583 Sending packet: $m80484d1,1#67...
    1227058218:708675 Packet received: 51

  [ If other output other than gdb_stdlog is mixed, then you still
  don't have the nice alignment, but, that doesn't seem as bad. ]

2) Makes sure a single fprintf_unfiltered is used to dump a packet,
   so we get a single timestamp for a packet, unlike your output
   above, where there's one timestamp per octet (that's from
   fputstrn_unfiltered ending up on fprintf_unfiltered once
   per char).

Something like this?

(I'm running it through the testsuite against gdbserver with
"set debug remote 1"/"set debug timestamp" just in case).

-- 
Pedro Alves
2008-11-19  Pedro Alves  <pedro@codesourcery.com>

	* remote.c (escape_buffer): New.
	(putpkt_binary, read_frame, getpkt_or_notif_sane_1): Use it.  Make
	sure debug output printing a packet buffer goes through a single
	fprintf_unfiltered call.
	* utils.c (vfprintf_unfiltered): If outputting timestamps, end
	output with a newline if it wasn't going to already.

---
 gdb/remote.c |   81 ++++++++++++++++++++++++++++++++++++++++++++++-------------
 gdb/utils.c  |   13 ++++++++-
 2 files changed, 75 insertions(+), 19 deletions(-)

Index: src/gdb/remote.c
===================================================================
--- src.orig/gdb/remote.c	2008-11-19 01:41:52.000000000 +0000
+++ src/gdb/remote.c	2008-11-19 01:42:26.000000000 +0000
@@ -5847,6 +5847,28 @@ remote_send (char **buf,
     error (_("Remote failure reply: %s"), *buf);
 }
 
+/* Return a pointer to an xmalloc'ed string representing an escaped
+   version of BUF, of len N.  E.g. \n is converted to \\n, \t to \\t,
+   etc.  The caller is responsible for releasing the returned
+   memory.  */
+
+static char *
+escape_buffer (const char *buf, int n)
+{
+  struct cleanup *old_chain;
+  struct ui_file *stb;
+  char *str;
+  long length;
+
+  stb = mem_fileopen ();
+  old_chain = make_cleanup_ui_file_delete (stb);
+
+  fputstrn_unfiltered (buf, n, 0, stb);
+  str = ui_file_xstrdup (stb, &length);
+  do_cleanups (old_chain);
+  return str;
+}
+
 /* Display a null-terminated packet on stdout, for debugging, using C
    string notation.  */
 
@@ -5919,11 +5941,15 @@ putpkt_binary (char *buf, int cnt)
 
       if (remote_debug)
 	{
+	  struct cleanup *old_chain;
+	  char *str;
+
 	  *p = '\0';
-	  fprintf_unfiltered (gdb_stdlog, "Sending packet: ");
-	  fputstrn_unfiltered (buf2, p - buf2, 0, gdb_stdlog);
-	  fprintf_unfiltered (gdb_stdlog, "...");
+	  str = escape_buffer (buf2, p - buf2);
+	  old_chain = make_cleanup (xfree, str);
+	  fprintf_unfiltered (gdb_stdlog, "Sending packet: %s...", str);
 	  gdb_flush (gdb_stdlog);
+	  do_cleanups (old_chain);
 	}
       if (serial_write (remote_desc, buf2, p - buf2))
 	perror_with_name (_("putpkt: write failed"));
@@ -5997,9 +6023,15 @@ putpkt_binary (char *buf, int cnt)
 		  {
 		    if (remote_debug)
 		      {
-			fprintf_unfiltered (gdb_stdlog, "  Notification received: ");
-			fputstrn_unfiltered (rs->buf, val, 0, gdb_stdlog);
-			fprintf_unfiltered (gdb_stdlog, "\n");
+			struct cleanup *old_chain;
+			char *str;
+
+			str = escape_buffer (rs->buf, val);
+			old_chain = make_cleanup (xfree, str);
+			fprintf_unfiltered (gdb_stdlog,
+					    "  Notification received: %s\n",
+					    str);
+			do_cleanups (old_chain);
 		      }
 		    handle_notification (rs->buf, val);
 		    /* We're in sync now, rewait for the ack.  */
@@ -6163,11 +6195,16 @@ read_frame (char **buf_p,
 
 	    if (remote_debug)
 	      {
-		fprintf_filtered (gdb_stdlog,
-			      "Bad checksum, sentsum=0x%x, csum=0x%x, buf=",
-				  pktcsum, csum);
-		fputstrn_filtered (buf, bc, 0, gdb_stdlog);
-		fputs_filtered ("\n", gdb_stdlog);
+		struct cleanup *old_chain;
+		char *str;
+
+		str = escape_buffer (buf, bc);
+		old_chain = make_cleanup (xfree, str);
+		fprintf_unfiltered (gdb_stdlog,
+				    "\
+Bad checksum, sentsum=0x%x, csum=0x%x, buf=%s\n",
+				    pktcsum, csum, str);
+		do_cleanups (old_chain);
 	      }
 	    /* Number of characters in buffer ignoring trailing
                NULL.  */
@@ -6340,9 +6377,13 @@ getpkt_or_notif_sane_1 (char **buf, long
 	{
 	  if (remote_debug)
 	    {
-	      fprintf_unfiltered (gdb_stdlog, "Packet received: ");
-	      fputstrn_unfiltered (*buf, val, 0, gdb_stdlog);
-	      fprintf_unfiltered (gdb_stdlog, "\n");
+	     struct cleanup *old_chain;
+	     char *str;
+
+	     str = escape_buffer (*buf, val);
+	     old_chain = make_cleanup (xfree, str);
+	     fprintf_unfiltered (gdb_stdlog, "Packet received: %s\n", str);
+	     do_cleanups (old_chain);
 	    }
 
 	  /* Skip the ack char if we're in no-ack mode.  */
@@ -6359,9 +6400,15 @@ getpkt_or_notif_sane_1 (char **buf, long
 
 	  if (remote_debug)
 	    {
-	      fprintf_unfiltered (gdb_stdlog, "  Notification received: ");
-	      fputstrn_unfiltered (*buf, val, 0, gdb_stdlog);
-	      fprintf_unfiltered (gdb_stdlog, "\n");
+	      struct cleanup *old_chain;
+	      char *str;
+
+	      str = escape_buffer (*buf, val);
+	      old_chain = make_cleanup (xfree, str);
+	      fprintf_unfiltered (gdb_stdlog,
+				  "  Notification received: %s\n",
+				  str);
+	      do_cleanups (old_chain);
 	    }
 
 	  handle_notification (*buf, val);
Index: src/gdb/utils.c
===================================================================
--- src.orig/gdb/utils.c	2008-11-19 01:41:52.000000000 +0000
+++ src/gdb/utils.c	2008-11-19 01:42:26.000000000 +0000
@@ -2286,13 +2286,22 @@ vfprintf_unfiltered (struct ui_file *str
     {
       struct timeval tm;
       char *timestamp;
+      int len, need_nl;
 
       gettimeofday (&tm, NULL);
-      timestamp = xstrprintf ("%ld:%ld ", (long) tm.tv_sec, (long) tm.tv_usec);
+
+      len = strlen (linebuffer);
+      need_nl = (len > 0 && linebuffer[len - 1] != '\n');
+
+      timestamp = xstrprintf ("%ld:%ld %s%s",
+			      (long) tm.tv_sec, (long) tm.tv_usec,
+			      linebuffer,
+			      need_nl ? "\n": "");
       make_cleanup (xfree, timestamp);
       fputs_unfiltered (timestamp, stream);
     }
-  fputs_unfiltered (linebuffer, stream);
+  else
+    fputs_unfiltered (linebuffer, stream);
   do_cleanups (old_cleanups);
 }
 

Index Nav: [Date Index] [Subject Index] [Author Index] [Thread Index]
Message Nav: [Date Prev] [Date Next] [Thread Prev] [Thread Next]