From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (qmail 3355 invoked by alias); 19 Nov 2008 01:47:22 -0000 Received: (qmail 3222 invoked by uid 22791); 19 Nov 2008 01:47:18 -0000 X-Spam-Check-By: sourceware.org Received: from mail.codesourcery.com (HELO mail.codesourcery.com) (65.74.133.4) by sourceware.org (qpsmtpd/0.31) with ESMTP; Wed, 19 Nov 2008 01:46:43 +0000 Received: (qmail 6075 invoked from network); 19 Nov 2008 01:46:40 -0000 Received: from unknown (HELO orlando.local) (pedro@127.0.0.2) by mail.codesourcery.com with ESMTPA; 19 Nov 2008 01:46:40 -0000 From: Pedro Alves To: gdb-patches@sourceware.org Subject: Re: [RFC] output remote protocol timestamps with "set debug remote" Date: Wed, 19 Nov 2008 14:07:00 -0000 User-Agent: KMail/1.9.10 Cc: Daniel Jacobowitz References: <200811141850.28537.pedro@codesourcery.com> <20081118214535.GA678@caradoc.them.org> In-Reply-To: <20081118214535.GA678@caradoc.them.org> MIME-Version: 1.0 Content-Type: Multipart/Mixed; boundary="Boundary-00=_DA3IJ/XHjRx3tPd" Message-Id: <200811190146.43101.pedro@codesourcery.com> X-IsSubscribed: yes Mailing-List: contact gdb-patches-help@sourceware.org; run by ezmlm Precedence: bulk List-Id: List-Subscribe: List-Archive: List-Post: List-Help: , Sender: gdb-patches-owner@sourceware.org X-SW-Source: 2008-11/txt/msg00493.txt.bz2 --Boundary-00=_DA3IJ/XHjRx3tPd Content-Type: text/plain; charset="iso-8859-1" Content-Transfer-Encoding: 7bit Content-Disposition: inline Content-length: 1989 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 --Boundary-00=_DA3IJ/XHjRx3tPd Content-Type: text/x-diff; charset="iso 8859-15"; name="remote_timestamps.diff" Content-Transfer-Encoding: 7bit Content-Disposition: attachment; filename="remote_timestamps.diff" Content-length: 5520 2008-11-19 Pedro Alves * 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); } --Boundary-00=_DA3IJ/XHjRx3tPd--