Add TRACE_ROUTING functionality to show the contents of the buffers at each round

Enclave/route.cpp

@@ -8,6 +8,7 @@
 #include "route.hpp"
 
 #define PROFILE_ROUTING
+#define TRACE_ROUTING
 
 RouteState route_state;
 
@@ -15,6 +16,32 @@ RouteState route_state;
 
 #define CEILDIV(x,y) (((x)+(y)-1)/(y))
 
+#ifdef TRACE_ROUTING
+
+// Show (the first 300 of, if there are more) the headers and the first
+// few bytes of the body of each message in the buffer
+static void show_messages(const char *label, const unsigned char *buffer,
+    size_t num)
+{
+    if (label) {
+        printf("%s\n", label);
+    }
+    for (size_t i=0; i<num && i<300; ++i) {
+        const uint32_t *ibuf = (const uint32_t *)buffer;
+        if (g_teems_config.private_routing) {
+            printf("%3d R:%08x S:%08x [%08x]\n", i, ibuf[0], ibuf[1],
+                ibuf[2]);
+        } else {
+            printf("%3d R:%08x P:%08x S:%08x [%08x]\n", i, ibuf[0], ibuf[1],
+                ibuf[2], ibuf[3]);
+        }
+        buffer += g_teems_config.msg_size;
+    }
+    printf("\n");
+}
+
+#endif
+
 // Call this near the end of ecall_config_load, but before
 // comms_init_nodestate. Returns true on success, false on failure.
 bool route_init()
@@ -881,6 +908,9 @@ static void round1a_processing(void *cbpointer) {
             pthread_mutex_unlock(&round1.mutex);
             pthread_mutex_lock(&round1.mutex);
         }
+#ifdef TRACE_ROUTING
+        show_messages("Start of round 1a", round1.buf, round1.inserted);
+#endif
 #ifdef PROFILE_ROUTING
         uint32_t inserted = round1.inserted;
         unsigned long start_round1a = printf_with_rtclock("begin round1a processing (%u)\n", inserted);
@@ -936,6 +966,9 @@ static void round1b_processing(void *cbpointer) {
         }
         pthread_mutex_lock(&round1a_sorted.mutex);
 
+#ifdef TRACE_ROUTING
+        show_messages("Start of round 1b", round1a.buf, round1a.inserted);
+#endif
 #ifdef PROFILE_ROUTING
         uint32_t inserted = round1a.inserted;
         unsigned long start_round1b = printf_with_rtclock("begin round1b processing (%u)\n", inserted);
@@ -1034,6 +1067,9 @@ static void round1c_processing(void *cbpointer) {
         pthread_mutex_lock(&round1a.mutex);
         pthread_mutex_lock(&round1a_sorted.mutex);
 
+#ifdef TRACE_ROUTING
+        show_messages("Start of round 1c", round1a.buf, round1a.inserted);
+#endif
 #ifdef PROFILE_ROUTING
         unsigned long start_round1c = printf_with_rtclock("begin round1c processing (%u)\n", round1a.inserted);
 #endif
@@ -1100,6 +1136,12 @@ static void round1c_processing(void *cbpointer) {
             printf_with_rtclock_diff(start_sort, "end round1b_next oblivious sort (%u,%u)\n", num_round1b_next + num_final_round1a, 2*max_round1b_msgs_to_adj_rtr);
 #endif
         }
+#ifdef TRACE_ROUTING
+        printf("round1a_sorted.inserted = %lu. round1a.inserted = %lu\n",
+            round1a_sorted.inserted, round1a.inserted);
+        show_messages("In round 1c", round1a_sorted.buf,
+            round1a.inserted);
+#endif
 #ifdef PROFILE_ROUTING
         unsigned long start_sort = printf_with_rtclock("begin full oblivious sort (%u,%u)\n", round1a.inserted, route_state.max_round1a_msgs);
 #endif
@@ -1173,6 +1215,9 @@ static void round2_processing(uint8_t my_roles, void *cbpointer, MsgBuffer &prev
 
         // Obliviously tally the number of messages we received in
         // the previous round destined for each storage node
+#ifdef TRACE_ROUTING
+        show_messages("Start of round 2", prevround.buf, prevround.inserted);
+#endif
 #ifdef PROFILE_ROUTING
         unsigned long start_round2 = printf_with_rtclock("begin round2 processing (%u,%u)\n", prevround.inserted, prevround.bufsize);
         unsigned long start_tally = printf_with_rtclock("begin tally (%u)\n", prevround.inserted);
@@ -1278,6 +1323,9 @@ void ecall_routing_proceed(void *cbpointer)
                 pthread_mutex_lock(&ingbuf.mutex);
             }
             // Sort the messages we've received
+#ifdef TRACE_ROUTING
+            show_messages("Start of round 1", ingbuf.buf, ingbuf.inserted);
+#endif
 #ifdef PROFILE_ROUTING
             uint32_t inserted = ingbuf.inserted;
             unsigned long start_round1 = printf_with_rtclock("begin round1 processing (%u)\n", inserted);