Merge pull request #3404 from Lotterleben/aodvv2_debug_cleanup

aodvv2: tidy debug output, remove VDEBUG(), add LOG()

sys/net/routing/aodvv2/aodv.c

@@ -38,11 +38,15 @@ static void _deep_free_msg_container(struct msg_container *msg_container);
 static void _write_packet(struct rfc5444_writer *wr __attribute__ ((unused)),
                           struct rfc5444_writer_target *iface __attribute__((unused)),
                           void *buffer, size_t length);
+static void print_json_pkt_sent(struct writer_target *wt);
 
-#if ENABLE_DEBUG
+#if AODV_DEBUG
 char addr_str[IPV6_MAX_ADDR_STR_LEN];
 static struct netaddr_str nbuf;
 #endif
+#if TEST_SETUP
+static struct netaddr_str nbuf_origaddr, nbuf_targaddr, nbuf_nexthop;
+#endif
 
 static char aodv_rcv_stack_buf[THREAD_STACKSIZE_MAIN];
 static char aodv_snd_stack_buf[THREAD_STACKSIZE_MAIN];
@@ -132,7 +136,6 @@ void *fib_signal_handler_thread(void *arg)
     fib_register_rp((uint8_t*) &aodvv2_prefix, aodvv2_prefix_len);
 
     while (true) {
-        AODV_DEBUG("%s()\n", __func__);
         msg_t msg;
         msg_receive(&msg);
 
@@ -166,7 +169,7 @@ void *fib_signal_handler_thread(void *arg)
                                                   * merely to make the compiler shut up */
                 };
 
-                DEBUG("\tstarting route discovery towards %s... \n",
+                AODV_DEBUG("\tstarting route discovery towards %s... \n",
                       ipv6_addr_to_str(addr_str, IPV6_MAX_ADDR_STR_LEN, &dest));
                 aodv_send_rreq(&rreq_data);
             }
@@ -184,8 +187,6 @@ void aodv_send_rreq(struct aodvv2_packet_data *packet_data)
     /* Make sure only one thread is dispatching a RREQ at a time */
     mutex_lock(&rreq_mutex);
 
-    AODV_DEBUG("%s()\n", __func__);
-
     struct aodvv2_packet_data *pd = malloc(sizeof(struct aodvv2_packet_data));
     memcpy(pd, packet_data, sizeof(struct aodvv2_packet_data));
 
@@ -213,8 +214,6 @@ void aodv_send_rrep(struct aodvv2_packet_data *packet_data, struct netaddr *next
     /* Make sure only one thread is dispatching a RREP at a time */
     mutex_lock(&rrep_mutex);
 
-    AODV_DEBUG("%s()\n", __func__);
-
     struct aodvv2_packet_data *pd = malloc(sizeof(struct aodvv2_packet_data));
     memcpy(pd, packet_data, sizeof(struct aodvv2_packet_data));
 
@@ -245,8 +244,6 @@ void aodv_send_rerr(struct unreachable_node unreachable_nodes[], size_t len, str
     /* Make sure only one thread is dispatching a RERR at a time */
     mutex_lock(&rerr_mutex);
 
-    AODV_DEBUG("%s()\n", __func__);
-
     struct rerr_data *rerrd = malloc(sizeof(struct rerr_data));
     *rerrd = (struct rerr_data) {
         .unreachable_nodes = unreachable_nodes,
@@ -313,10 +310,8 @@ static void *_aodv_sender_thread(void *arg)
 
     msg_t msgq[RCV_MSG_Q_SIZE];
     msg_init_queue(msgq, RCV_MSG_Q_SIZE);
-    AODV_DEBUG("_aodv_sender_thread initialized.\n");
 
     while (true) {
-        AODV_DEBUG("%s()\n", __func__);
         msg_t msg;
         msg_receive(&msg);
         struct msg_container *mc = (struct msg_container *) msg.content.ptr;
@@ -335,7 +330,7 @@ static void *_aodv_sender_thread(void *arg)
                              rerr_data->hoplimit, rerr_data->next_hop);
         }
         else {
-            DEBUG("ERROR: Couldn't identify Message\n");
+            AODV_DEBUG("ERROR: Couldn't identify Message\n");
         }
         _deep_free_msg_container(mc);
     }
@@ -348,7 +343,6 @@ static void *_aodv_receiver_thread(void *arg)
 {
     (void) arg;
 
-    AODV_DEBUG("%s()\n", __func__);
     uint32_t fromlen;
     char buf_rcv[UDP_BUFFER_SIZE];
     msg_t msg_q[RCV_MSG_Q_SIZE];
@@ -362,12 +356,11 @@ static void *_aodv_receiver_thread(void *arg)
     int sock_rcv = socket_base_socket(PF_INET6, SOCK_DGRAM, IPPROTO_UDP);
 
     if (-1 == socket_base_bind(sock_rcv, &sa_rcv, sizeof(sa_rcv))) {
-        DEBUG("Error: bind to receive socket failed!\n");
+        AODV_DEBUG("Error: bind to receive socket failed!\n");
         socket_base_close(sock_rcv);
         return NULL;
     }
 
-    AODV_DEBUG("ready to receive data\n");
     while (true) {
         int32_t rcv_size = socket_base_recvfrom(sock_rcv, (void *)buf_rcv, UDP_BUFFER_SIZE, 0,
                                         &sa_rcv, &fromlen);
@@ -376,11 +369,6 @@ static void *_aodv_receiver_thread(void *arg)
             AODV_DEBUG("ERROR receiving data!\n");
         }
 
-        AODV_DEBUG("_aodv_receiver_thread() %s:",
-              ipv6_addr_to_str(addr_str, IPV6_MAX_ADDR_STR_LEN, &_v6_addr_local));
-        DEBUG(" UDP packet received from %s\n",
-              ipv6_addr_to_str(addr_str, IPV6_MAX_ADDR_STR_LEN, &sa_rcv.sin6_addr));
-
         struct netaddr _sender;
         ipv6_addr_t_to_netaddr(&sa_rcv.sin6_addr, &_sender);
 
@@ -411,13 +399,14 @@ static void _write_packet(struct rfc5444_writer *wr __attribute__ ((unused)),
      * and print to console */
     abuf_hexdump(&_hexbuf, "\t", buffer, length);
     rfc5444_print_direct(&_hexbuf, buffer, length);
-    DEBUG("%s", abuf_getptr(&_hexbuf));
+    /* DEBUG("%s", abuf_getptr(&_hexbuf)); */
     abuf_clear(&_hexbuf);
 
     /* fetch the address the packet is supposed to be sent to (i.e. to a
      * specific node or the multicast address) from the writer_target struct
      * iface* is stored in. This is a bit hacky, but it does the trick. */
     wt = container_of(iface, struct writer_target, interface);
+    print_json_pkt_sent(wt);
     netaddr_to_ipv6_addr_t(&wt->target_addr, &sa_wp.sin6_addr);
 
     /* When originating a RREQ, add it to our RREQ table/update its predecessor */
@@ -437,6 +426,36 @@ static void _write_packet(struct rfc5444_writer *wr __attribute__ ((unused)),
     AODV_DEBUG("%d bytes sent.\n", bytes_sent);
 }
 
+/* Print the json representation of a sent packet to stdout for debugging */
+static void print_json_pkt_sent(struct writer_target *wt)
+{
+#if TEST_SETUP
+    // note: what if the content at wt has changed until this is printed? memcpy the entire thing?
+    int msg_type = wt->type;
+    if (msg_type == RFC5444_MSGTYPE_RREQ) {
+    printf("{\"log_type\": \"sent_rreq\", \"log_data\": {"
+        "\"orig_addr\": \"%s\", \"targ_addr\": \"%s\", \"orig_seqnum\": %d, \"metric\": %d}}\n",
+        netaddr_to_string(&nbuf_origaddr, &wt->packet_data.origNode.addr),
+        netaddr_to_string(&nbuf_targaddr, &wt->packet_data.targNode.addr),
+        wt->packet_data.origNode.seqnum, wt->packet_data.origNode.metric);
+    }
+    if (msg_type == RFC5444_MSGTYPE_RREP) {
+    printf("{\"log_type\": \"sent_rrep\", \"log_data\": {"
+        "\"next_hop\": \"%s\",\"orig_addr\": \"%s\", \"orig_seqnum\": %d,"
+        " \"targ_addr\": \"%s\"}}\n",
+                netaddr_to_string(&nbuf_nexthop, &wt->target_addr),
+                netaddr_to_string(&nbuf_origaddr, &wt->packet_data.origNode.addr),
+                wt->packet_data.origNode.seqnum,
+                netaddr_to_string(&nbuf_targaddr, &wt->packet_data.targNode.addr));
+    }
+    if (msg_type == RFC5444_MSGTYPE_RERR) {
+        /* TODO */
+    }
+#else
+    (void) wt; /* silence compiler */
+#endif
+}
+
 /* free the matryoshka doll of cobbled-together structs that the sender_thread receives */
 static void _deep_free_msg_container(struct msg_container *mc)
 {

sys/net/routing/aodvv2/routingtable.c

@@ -28,6 +28,7 @@
 
 /* helper functions */
 static void _reset_entry_if_stale(uint8_t i);
+static void print_json_added_rt_entry(struct aodvv2_routing_entry_t *entry);
 
 static struct aodvv2_routing_entry_t routing_table[AODVV2_MAX_ROUTING_ENTRIES];
 static timex_t null_time, max_seqnum_lifetime, active_interval, max_idletime, validity_t;
@@ -59,6 +60,8 @@ struct netaddr *routingtable_get_next_hop(struct netaddr *dest, aodvv2_metric_t
 
 void routingtable_add_entry(struct aodvv2_routing_entry_t *entry)
 {
+    print_json_added_rt_entry(entry);
+
     /* only add if we don't already know the address */
     if (routingtable_get_entry(&(entry->addr), entry->metricType)) {
         return;
@@ -238,6 +241,32 @@ void routingtable_fill_routing_entry_t_rrep(struct aodvv2_packet_data *packet_da
     rt_entry->state = ROUTE_STATE_ACTIVE;
 }
 
+#if TEST_SETUP
+/* Write JSON representation of rt_entry to json_str */
+static void routingtable_entry_to_json(struct aodvv2_routing_entry_t *rt_entry, char* json_str)
+{
+
+    struct netaddr_str nbuf_addr, nbuf_nexthop;
+
+    sprintf(json_str,"{\"addr\": \"%s\", \"next_hop\": \"%s\", \"seqnum\": %d,"
+                     "\"metric\": %d, \"state\": %d}",
+                     netaddr_to_string(&nbuf_addr, &rt_entry->addr),
+                     netaddr_to_string(&nbuf_nexthop, &rt_entry->nextHopAddr),
+                     rt_entry->seqnum, rt_entry->metric, rt_entry->state);
+}
+#endif
+
+static void print_json_added_rt_entry(struct aodvv2_routing_entry_t *entry)
+{
+#if TEST_SETUP
+    char rt_entry_json [500];
+    routingtable_entry_to_json(entry, rt_entry_json);
+    printf("{\"log_type\": \"added_rt_entry\", \"log_data\": %s}\n", rt_entry_json);
+#else
+    (void) entry; /* silence compiler */
+#endif
+}
+
 void print_routingtable(void)
 {
     printf("===== BEGIN ROUTING TABLE ===================\n");