debug.c: Make coap_show_pdu() use coap_log() or fprintf()

coap_show_pdu()'s API is now coap_show_pdu(coap_log_t, coap_pdu_t*)
New function void coap_set_show_pdu_output(int use_fprintf)
Default is use fprintf() instead of coap_log()

The output buffer size can be configuring -DCOAP_DEBUG_BUF_SIZE

Output COAP_OPTION_SIZE2 option as well

For binary data, output ascii readable equivalent immediately under the
hex output for ease of debugging.

include/coap/debug.h
src/debug.c

Update coap_show_pdu() API
New function coap_set_show_pdu_output()
Update coap_show_pdu() code

include/coap/pdu.h

Define the coap debug output debug buffer size
COAP_DEBUG_BUF_SIZE

examples/client.c
examples/contiki/coap-observer.c
src/net.c
tests/test_wellknown.c
tests/test_pdu.c

Update coap_show_pdu() calls

libcoap-2.map
libcoap-2.sym

New function coap_set_show_pdu_output()

Author: mrdeep1

examples/client.c

@@ -211,8 +211,7 @@ clear_obs(coap_context_t *ctx, coap_session_t *session) {
     }
   }
 
-  if (LOG_INFO <= coap_get_log_level())
-    coap_show_pdu(pdu);
+  coap_show_pdu(LOG_INFO, pdu);
 
   tid = coap_send(session, pdu);
 
@@ -297,11 +296,9 @@ message_handler(struct coap_context_t *ctx,
   coap_tid_t tid;
 
 #ifndef NDEBUG
-  if (LOG_INFO <= coap_get_log_level()) {
-    coap_log(LOG_DEBUG, "** process incoming %d.%02d response:\n",
-          (received->code >> 5), received->code & 0x1F);
-    coap_show_pdu(received);
-  }
+  coap_log(LOG_DEBUG, "** process incoming %d.%02d response:\n",
+           (received->code >> 5), received->code & 0x1F);
+  coap_show_pdu(LOG_INFO, received);
 #endif
 
   /* check if this is a response to our original request */
@@ -456,7 +453,7 @@ message_handler(struct coap_context_t *ctx,
                          payload.s,
                          block.num,
                          block.szx);
-          coap_show_pdu(pdu);
+          coap_show_pdu(LOG_WARNING, pdu);
 
 	  tid = coap_send(session, pdu);
 
@@ -1278,10 +1275,8 @@ main(int argc, char **argv) {
   }
 
 #ifndef NDEBUG
-  if (LOG_INFO <= coap_get_log_level()) {
-    coap_log(LOG_DEBUG, "sending CoAP request:\n");
-    coap_show_pdu(pdu);
-  }
+  coap_log(LOG_DEBUG, "sending CoAP request:\n");
+  coap_show_pdu(LOG_INFO, pdu);
 #endif
 
   coap_send(session, pdu);

examples/contiki/coap-observer.c

@@ -103,7 +103,7 @@ message_handler(struct coap_context_t  *ctx,
 
   debug("** process incoming %d.%02d response:\n",
 	(received->hdr->code >> 5), received->hdr->code & 0x1F);
-  coap_show_pdu(received);
+  coap_show_pdu(LOG_WARNING, received);
 
   coap_ticks(&last_seen);
 }

include/coap/debug.h

@@ -74,7 +74,22 @@ void coap_log_impl(coap_log_t level, const char *format, ...);
 #define debug(...) coap_log(LOG_DEBUG, __VA_ARGS__)
 
 #include "pdu.h"
-void coap_show_pdu(const coap_pdu_t *);
+
+/**
+ * Defines the output mode for the coap_show_pdu() function.
+ *
+ * @param use_printf  1 if the output is to use fprintf() (the default)
+ *                    0 if the output is to use coap_log()
+ */
+void coap_set_show_pdu_output(int use_fprintf);
+
+/**
+ * Display the contents of the specified @p pdu.
+ *
+ * @param level The required minimum logging level
+ * @param pdu The PDU to decode
+ */
+void coap_show_pdu(coap_log_t level, const coap_pdu_t *pdu);
 
 struct coap_address_t;
 size_t coap_print_addr(const struct coap_address_t *, unsigned char *, size_t);

include/coap/pdu.h

@@ -52,6 +52,15 @@ struct coap_session_t;
 #endif
 #endif /* COAP_DEFAULT_MAX_PDU_RX_SIZE */
 
+#ifndef COAP_DEBUG_BUF_SIZE
+#if defined(WITH_CONTIKI) || defined(WITH_LWIP)
+#define COAP_DEBUG_BUF_SIZE 128
+#else /* defined(WITH_CONTIKI) || defined(WITH_LWIP) */
+/* 1024 derived from RFC7252 4.6.  Message Size max payload */
+#define COAP_DEBUG_BUF_SIZE (8 + 1024 * 2)
+#endif /* defined(WITH_CONTIKI) || defined(WITH_LWIP) */
+#endif /* COAP_DEBUG_BUF_SIZE */
+
 #define COAP_DEFAULT_VERSION      1 /* version of CoAP supported */
 #define COAP_DEFAULT_SCHEME  "coap" /* the default scheme for CoAP URIs */
 

libcoap-2.map

@@ -167,6 +167,7 @@ global:
   coap_set_event_handler;
   coap_set_log_handler;
   coap_set_log_level;
+  coap_set_show_pdu_output;
   coap_show_pdu;
   coap_socket_strerror;
   coap_split_path;

libcoap-2.sym

@@ -165,6 +165,7 @@ coap_set_app_data
 coap_set_event_handler
 coap_set_log_handler
 coap_set_log_level
+coap_set_show_pdu_output
 coap_show_pdu
 coap_socket_strerror
 coap_split_path

src/debug.c

@@ -52,6 +52,8 @@
 
 static coap_log_t maxlog = LOG_WARNING;	/* default maximum log level */
 
+static int use_fprintf_for_show_pdu = 1; /* non zero to output with fprintf */
+
 const char *coap_package_name(void) {
   return PACKAGE_NAME;
 }
@@ -60,6 +62,11 @@ const char *coap_package_version(void) {
   return PACKAGE_STRING;
 }
 
+void
+coap_set_show_pdu_output(int use_fprintf) {
+  use_fprintf_for_show_pdu = use_fprintf;
+}
+
 coap_log_t 
 coap_get_log_level(void) {
   return maxlog;
@@ -316,6 +323,7 @@ msg_option_string(uint8_t code, uint16_t option_type) {
     { COAP_OPTION_PROXY_URI, "Proxy-Uri" },
     { COAP_OPTION_PROXY_SCHEME, "Proxy-Scheme" },
     { COAP_OPTION_SIZE1, "Size1" },
+    { COAP_OPTION_SIZE2, "Size2" },
     { COAP_OPTION_NORESPONSE, "No-Response" }
   };
 
@@ -431,8 +439,18 @@ is_binary(int content_format) {
 	   content_format == COAP_MEDIATYPE_APPLICATION_JSON);
 }
 
+#define COAP_DO_SHOW_OUTPUT_LINE           \
+ do {                                      \
+   if (use_fprintf_for_show_pdu) {         \
+     fprintf(COAP_DEBUG_FD, "%s", outbuf); \
+   }                                       \
+   else {                                  \
+     coap_log(level, "%s", outbuf);        \
+   }                                       \
+ } while (0)
+
 void
-coap_show_pdu(const coap_pdu_t *pdu) {
+coap_show_pdu(coap_log_t level, const coap_pdu_t *pdu) {
   unsigned char buf[1024]; /* need some space for output creation */
   size_t buf_len = 0; /* takes the number of bytes written to buf */
   int encode = 0, have_options = 0, i;
@@ -441,25 +459,36 @@ coap_show_pdu(const coap_pdu_t *pdu) {
   int content_format = -1;
   size_t data_len;
   unsigned char *data;
+  char outbuf[COAP_DEBUG_BUF_SIZE];
+  int outbuflen = 0;
+ 
+  /* Save time if not needed */
+  if (level > coap_get_log_level())
+    return;
 
-  fprintf(COAP_DEBUG_FD, "v:%d t:%s c:%s i:%04x {",
+  snprintf(outbuf, sizeof(outbuf), "v:%d t:%s c:%s i:%04x {",
 	  COAP_DEFAULT_VERSION, msg_type_string(pdu->type),
 	  msg_code_string(pdu->code), pdu->tid);
 
   for (i = 0; i < pdu->token_length; i++) {
-    fprintf(COAP_DEBUG_FD, "%02x", pdu->token[i]);
+    outbuflen = strlen(outbuf);
+    snprintf(&outbuf[outbuflen], sizeof(outbuf)-outbuflen,
+              "%02x", pdu->token[i]);
   }
-  fprintf(COAP_DEBUG_FD, "}");
+  outbuflen = strlen(outbuf);
+  snprintf(&outbuf[outbuflen], sizeof(outbuf)-outbuflen,  "}");
 
   /* show options, if any */
   coap_option_iterator_init(pdu, &opt_iter, COAP_OPT_ALL);
 
-  fprintf(COAP_DEBUG_FD, " [");
+  outbuflen = strlen(outbuf);
+  snprintf(&outbuf[outbuflen], sizeof(outbuf)-outbuflen,  " [");
   while ((option = coap_option_next(&opt_iter))) {
     if (!have_options) {
       have_options = 1;
     } else {
-      fprintf(COAP_DEBUG_FD, ",");
+      outbuflen = strlen(outbuf);
+      snprintf(&outbuf[outbuflen], sizeof(outbuf)-outbuflen,  ",");
     }
 
     if (pdu->code == COAP_SIGNALING_CSM) switch(opt_iter.type) {
@@ -520,6 +549,7 @@ coap_show_pdu(const coap_pdu_t *pdu) {
     case COAP_OPTION_MAXAGE:
     case COAP_OPTION_OBSERVE:
     case COAP_OPTION_SIZE1:
+    case COAP_OPTION_SIZE2:
       /* show values as unsigned decimal value */
       buf_len = snprintf((char *)buf, sizeof(buf), "%u",
 			 coap_decode_var_bytes(coap_opt_value(option),
@@ -544,32 +574,70 @@ coap_show_pdu(const coap_pdu_t *pdu) {
 			       buf, sizeof(buf), encode);
     }
 
-    fprintf(COAP_DEBUG_FD, " %s:%.*s",
-      msg_option_string(pdu->code, opt_iter.type),
-      (int)buf_len, buf);
+    outbuflen = strlen(outbuf);
+    snprintf(&outbuf[outbuflen], sizeof(outbuf)-outbuflen,
+              " %s:%.*s", msg_option_string(pdu->code, opt_iter.type),
+	      (int)buf_len, buf);
   }
 
-  fprintf(COAP_DEBUG_FD, " ]");
+  outbuflen = strlen(outbuf);
+  snprintf(&outbuf[outbuflen], sizeof(outbuf)-outbuflen,  " ]");
 
   if (coap_get_data(pdu, &data_len, &data)) {
 
-    fprintf(COAP_DEBUG_FD, " :: ");
+    outbuflen = strlen(outbuf);
+    snprintf(&outbuf[outbuflen], sizeof(outbuf)-outbuflen,  " :: ");
 
     if (is_binary(content_format)) {
-      fprintf(COAP_DEBUG_FD, "<<");
+      int keep_data_len = data_len;
+      uint8_t *keep_data = data;
+
+      outbuflen = strlen(outbuf);
+      snprintf(&outbuf[outbuflen], sizeof(outbuf)-outbuflen,
+               "binary data length %ld\n", data_len);
+      COAP_DO_SHOW_OUTPUT_LINE; 
+      /*
+       * Output hex dump of binary data as a continuous entry
+       */
+      outbuf[0] = '\000';
+      snprintf(outbuf, sizeof(outbuf),  "<<");
+      while (data_len--) {
+	outbuflen = strlen(outbuf);
+        snprintf(&outbuf[outbuflen], sizeof(outbuf)-outbuflen,
+                 "%02x", *data++);
+      }
+      outbuflen = strlen(outbuf);
+      snprintf(&outbuf[outbuflen], sizeof(outbuf)-outbuflen,  ">>");
+      data_len = keep_data_len;
+      data = keep_data;
+      outbuflen = strlen(outbuf);
+      snprintf(&outbuf[outbuflen], sizeof(outbuf)-outbuflen,  "\n");
+      COAP_DO_SHOW_OUTPUT_LINE; 
+      /*
+       * Output ascii readable (if possible), immediately under the
+       * hex value of the character output above to help binary debugging
+       */
+      outbuf[0] = '\000';
+      snprintf(outbuf, sizeof(outbuf),  "<<");
       while (data_len--) {
-	fprintf(COAP_DEBUG_FD, "%02x", *data++);
+	outbuflen = strlen(outbuf);
+        snprintf(&outbuf[outbuflen], sizeof(outbuf)-outbuflen,
+                 "%c ", isprint (*data) ? *data : '.');
+        data++;
       }
-      fprintf(COAP_DEBUG_FD, ">>");
+      outbuflen = strlen(outbuf);
+      snprintf(&outbuf[outbuflen], sizeof(outbuf)-outbuflen,  ">>");
     } else {
       if (print_readable(data, data_len, buf, sizeof(buf), 0)) {
-	fprintf(COAP_DEBUG_FD, "'%s'", buf);
+	outbuflen = strlen(outbuf);
+        snprintf(&outbuf[outbuflen], sizeof(outbuf)-outbuflen,  "'%s'", buf);
       }
     }
   }
 
-  fprintf(COAP_DEBUG_FD, "\n");
-  fflush(COAP_DEBUG_FD);
+  outbuflen = strlen(outbuf);
+  snprintf(&outbuf[outbuflen], sizeof(outbuf)-outbuflen,  "\n");
+  COAP_DO_SHOW_OUTPUT_LINE; 
 }
 
 static coap_log_handler_t log_handler = NULL;
@@ -585,7 +653,11 @@ coap_log_impl(coap_log_t level, const char *format, ...) {
     return;
 
   if (log_handler) {
+#if defined(WITH_CONTIKI) || defined(WITH_LWIP)
     char message[128];
+#else
+    char message[8 + 1024 * 2]; /* O/H + Max packet payload size * 2 */
+#endif
     va_list ap;
     va_start(ap, format);
     vsnprintf( message, sizeof(message), format, ap);

src/net.c

@@ -617,9 +617,7 @@ coap_session_send_pdu(coap_session_t *session, coap_pdu_t *pdu) {
     default:
       break;
   }
-  if (LOG_DEBUG <= coap_get_log_level()) {
-    coap_show_pdu(pdu);
-  }
+  coap_show_pdu(LOG_DEBUG, pdu);
   return bytes_written;
 }
 
@@ -2075,7 +2073,7 @@ coap_dispatch(coap_context_t *context, coap_session_t *session,
 	    (int)msg_len, addr, localaddr);
 
 	    */
-    coap_show_pdu(pdu);
+    coap_show_pdu(LOG_DEBUG, pdu);
   }
 #endif
 

tests/test_pdu.c

@@ -300,8 +300,9 @@ t_parse_pdu16(void) {
   result = coap_pdu_parse(COAP_PROTO_UDP, teststr, sizeof(teststr), testpdu);
   CU_ASSERT(result == 0);
 
+  coap_set_show_pdu_output(0);
   coap_set_log_handler(log_handler);
-  coap_show_pdu(testpdu);	/* display PDU */
+  coap_show_pdu(LOG_ERR, testpdu);	/* display PDU */
   coap_set_log_handler(NULL);
 
   coap_delete_pdu(testpdu);

tests/test_wellknown.c

@@ -241,7 +241,7 @@ t_wellknown6(void) {
 
     CU_ASSERT_PTR_NOT_NULL(response);
 
-    /* coap_show_pdu(response); */
+    /* coap_show_pdu(LOG_INFO, response); */
 
     CU_ASSERT(coap_get_block(response, COAP_OPTION_BLOCK2, &block) != 0);