gdb_server: Log both incoming and outgoing GDB packets

- Made sure that also outgoing GDB packets are logged,
  not only the incoming ones.

- Improved the treatment of non-printable characters
  in the packets to make it more robust.

Prior to this change:

- Outgoing packets were not printed unless OpenOCD was
  re-compiled with _DEBUG_GDB_IO_.
- Non-prinable characters were only treated in incoming
  'X' packets.

After this change:

- Both incoming and outgoing GDB packets are logged
  on debug_level >= 3, so that both directions of the
  GDB channel are visible.
- Non-printable characters are checked for in every packet
  so that hey do not interfere with the terminal.

Change-Id: I0613e57ae5059b3279b0abcb71276cf5719a8699
Signed-off-by: Jan Matyas <matyas@codasip.com>
Reviewed-on: http://openocd.zylin.com/6269
Tested-by: jenkins
Reviewed-by: Antonio Borneo <borneo.antonio@gmail.com>

diff --git a/src/helper/log.c b/src/helper/log.c
index f5a80623f36a2a1e1e24ef65d08c829b1b022a34..36b59fe77198bd528ca81da56be12140a92a05d6 100644 (file)
--- a/src/helper/log.c
+++ b/src/helper/log.c
@@ -518,3 +518,16 @@ void log_socket_error(const char *socket_desc)
        LOG_ERROR("Error on socket '%s': errno==%d, message: %s.", socket_desc, error_code, strerror(error_code));
 #endif
 }
+
+/**
+ * Find the first non-printable character in the char buffer, return a pointer to it.
+ * If no such character exists, return NULL.
+ */
+char *find_nonprint_char(char *buf, unsigned buf_len)
+{
+       for (unsigned int i = 0; i < buf_len; i++) {
+               if (!isprint(buf[i]))
+                       return buf + i;
+       }
+       return NULL;
+}

diff --git a/src/helper/log.h b/src/helper/log.h
index f2ba0daa6f973ed5cfcd8f915dad132a67184886..34ff835b81ba9cae19929a6de9341d39fc44dc0e 100644 (file)
--- a/src/helper/log.h
+++ b/src/helper/log.h
@@ -100,6 +100,8 @@ char *alloc_vprintf(const char *fmt, va_list ap);
 char *alloc_printf(const char *fmt, ...)
        __attribute__ ((format (PRINTF_ATTRIBUTE_FORMAT, 1, 2)));
 
+char *find_nonprint_char(char *buf, unsigned buf_len);
+
 extern int debug_level;
 
 /* Avoid fn call and building parameter list if we're not outputting the information.

diff --git a/src/server/gdb_server.c b/src/server/gdb_server.c
index 00c04e363990eb0dcb59656f19292d16e3257485..d0586d1706e89ded317c5845ab2e180efe1a3528 100644 (file)
--- a/src/server/gdb_server.c
+++ b/src/server/gdb_server.c
@@ -357,14 +357,50 @@ static int gdb_write(struct connection *connection, void *data, int len)
        return ERROR_SERVER_REMOTE_CLOSED;
 }
 
+static void gdb_log_incoming_packet(char *packet)
+{
+       if (!LOG_LEVEL_IS(LOG_LVL_DEBUG))
+               return;
+
+       /* Avoid dumping non-printable characters to the terminal */
+       const unsigned packet_len = strlen(packet);
+       const char *nonprint = find_nonprint_char(packet, packet_len);
+       if (nonprint) {
+               /* Does packet at least have a prefix that is printable?
+                * Look within the first 50 chars of the packet. */
+               const char *colon = memchr(packet, ':', MIN(50, packet_len));
+               const bool packet_has_prefix = (colon != NULL);
+               const bool packet_prefix_printable = (packet_has_prefix && nonprint > colon);
+
+               if (packet_prefix_printable) {
+                       const unsigned int prefix_len = colon - packet + 1;  /* + 1 to include the ':' */
+                       const unsigned int payload_len = packet_len - prefix_len;
+                       LOG_DEBUG("received packet: %.*s<binary-data-%u-bytes>", prefix_len, packet, payload_len);
+               } else {
+                       LOG_DEBUG("received packet: <binary-data-%u-bytes>", packet_len);
+               }
+       } else {
+               /* All chars printable, dump the packet as is */
+               LOG_DEBUG("received packet: %s", packet);
+       }
+}
+
+static void gdb_log_outgoing_packet(char *packet_buf, unsigned int packet_len, unsigned char checksum)
+{
+       if (!LOG_LEVEL_IS(LOG_LVL_DEBUG))
+               return;
+
+       if (find_nonprint_char(packet_buf, packet_len))
+               LOG_DEBUG("sending packet: $<binary-data-%u-bytes>#%2.2x", packet_len, checksum);
+       else
+               LOG_DEBUG("sending packet: $%.*s#%2.2x'", packet_len, packet_buf, checksum);
+}
+
 static int gdb_put_packet_inner(struct connection *connection,
                char *buffer, int len)
 {
        int i;
        unsigned char my_checksum = 0;
-#ifdef _DEBUG_GDB_IO_
-       char *debug_buffer;
-#endif
        int reply;
        int retval;
        struct gdb_connection *gdb_con = connection->priv;
@@ -400,11 +436,7 @@ static int gdb_put_packet_inner(struct connection *connection,
 #endif
 
        while (1) {
-#ifdef _DEBUG_GDB_IO_
-               debug_buffer = strndup(buffer, len);
-               LOG_DEBUG("sending packet '$%s#%2.2x'", debug_buffer, my_checksum);
-               free(debug_buffer);
-#endif
+               gdb_log_outgoing_packet(buffer, len, my_checksum);
 
                char local_buffer[1024];
                local_buffer[0] = '$';
@@ -3259,18 +3291,7 @@ static int gdb_input_inner(struct connection *connection)
                /* terminate with zero */
                gdb_packet_buffer[packet_size] = '\0';
 
-               if (LOG_LEVEL_IS(LOG_LVL_DEBUG)) {
-                       if (packet[0] == 'X') {
-                               /* binary packets spew junk into the debug log stream */
-                               char buf[50];
-                               int x;
-                               for (x = 0; (x < 49) && (packet[x] != ':'); x++)
-                                       buf[x] = packet[x];
-                               buf[x] = 0;
-                               LOG_DEBUG("received packet: '%s:<binary-data>'", buf);
-                       } else
-                               LOG_DEBUG("received packet: '%s'", packet);
-               }
+               gdb_log_incoming_packet(gdb_packet_buffer);
 
                if (packet_size > 0) {
                        retval = ERROR_OK;