Added some logging to help with debugging. This logs the packet-buffer details.

pelab/monitor/ip-mapping.txt

 10.0.0.1 10.1.0.1 elabc-elab0
-10.0.0.2 10.1.0.2 elabc-elab1
-10.0.0.3 10.1.0.3 elabc-elab2
+10.0.0.2 10.4.0.1 elabc-elab1

pelab/reset.sh

@@ -4,9 +4,9 @@
 /usr/testbed/bin/tevc -e tbres/pelab now elabc-elab1 modify dest=10.0.0.1 bandwidth=100000
 /usr/testbed/bin/tevc -e tbres/pelab now elabc-elab0 modify dest=10.0.0.2 lpr=0.0
 /usr/testbed/bin/tevc -e tbres/pelab now elabc-elab1 modify dest=10.0.0.1 lpr=0.0
-/usr/testbed/bin/tevc -e tbres/pelab now planetc-planet0 modify dest=10.1.0.2 delay=5
-/usr/testbed/bin/tevc -e tbres/pelab now planetc-planet1 modify dest=10.1.0.1 delay=5
-/usr/testbed/bin/tevc -e tbres/pelab now planetc-planet0 modify dest=10.1.0.2 bandwidth=10000
-/usr/testbed/bin/tevc -e tbres/pelab now planetc-planet1 modify dest=10.1.0.1 bandwidth=10000
-/usr/testbed/bin/tevc -e tbres/pelab now planetc-planet0 modify dest=10.1.0.2 lpr=0.0
-/usr/testbed/bin/tevc -e tbres/pelab now planetc-planet1 modify dest=10.1.0.1 lpr=0.0
+#/usr/testbed/bin/tevc -e tbres/pelab now planetc-planet0 modify dest=10.1.0.2 delay=5
+#/usr/testbed/bin/tevc -e tbres/pelab now planetc-planet1 modify dest=10.1.0.1 delay=5
+#/usr/testbed/bin/tevc -e tbres/pelab now planetc-planet0 modify dest=10.1.0.2 bandwidth=10000
+#/usr/testbed/bin/tevc -e tbres/pelab now planetc-planet1 modify dest=10.1.0.1 bandwidth=10000
+#/usr/testbed/bin/tevc -e tbres/pelab now planetc-planet0 modify dest=10.1.0.2 lpr=0.0
+#/usr/testbed/bin/tevc -e tbres/pelab now planetc-planet1 modify dest=10.1.0.1 lpr=0.0

pelab/stub/log.c

@@ -74,6 +74,10 @@ static void logPrefix(int flags, struct timeval const * timestamp)
   {
       fprintf(logFile, "DELAY_DETAIL ");
   }
+  if (flags & PACKET_BUFFER_DETAIL)
+  {
+      fprintf(logFile, "PACKET_BUFFER_DETAIL ");
+  }
   if (logTimestamp)
   {
     struct timeval now;

pelab/stub/log.h

@@ -49,31 +49,34 @@ void logWrite(int flags, struct timeval const * timestamp,
 enum LOG_TYPE
 {
   // Information about control messages being sent to the monitor
-  CONTROL_SEND     = 0x1,
+  CONTROL_SEND         = 0x1,
   // Information about control messages being received from the monitor
-  CONTROL_RECEIVE  = 0x2,
+  CONTROL_RECEIVE      = 0x2,
   // Information about sent control messages in a format used in
   // tcptrace graphs.
-  TCPTRACE_SEND    = 0x4,
+  TCPTRACE_SEND        = 0x4,
   // Information about received control messages in a format used in
   // tcptrace graphs.
-  TCPTRACE_RECEIVE = 0x8,
+  TCPTRACE_RECEIVE     = 0x8,
   // Information about sent packets which were sniffed by stub-pcap.
-  SNIFF_SEND       = 0x10,
+  SNIFF_SEND           = 0x10,
   // Information about received packets which were sniffed by stub-pcap.
-  SNIFF_RECEIVE    = 0x20,
+  SNIFF_RECEIVE        = 0x20,
   // Information about writing to peers.
-  PEER_WRITE       = 0x40,
+  PEER_WRITE           = 0x40,
   // Information about reading from peers.
-  PEER_READ        = 0x80,
+  PEER_READ            = 0x80,
   // Which stages are being run in the main loop.
-  MAIN_LOOP        = 0x100,
+  MAIN_LOOP            = 0x100,
   // Database storage and reterieval
-  LOOKUP_DB        = 0x200,
-  DELAY_DETAIL     = 0x400,
+  LOOKUP_DB            = 0x200,
+  // Print fine grained delay data in the log file.
+  DELAY_DETAIL         = 0x400,
+  // Print fine grained packet-buffer control data.
+  PACKET_BUFFER_DETAIL = 0x800,
   // Shortcuts for common cases.
   LOG_NOTHING      = 0x00,
-  LOG_EVERYTHING   = 0x7ff
+  LOG_EVERYTHING   = 0xfff
 };
 
 #ifdef __cplusplus

pelab/stub/stubd.c

@@ -45,6 +45,13 @@ char random_buffer[MAX_PAYLOAD_SIZE];
 
 int total_size = 0;
 
+char * ipToString(unsigned long ip)
+{
+  struct in_addr address;
+  address.s_addr = ip;
+  return inet_ntoa(address);
+}
+
 typedef struct packet_buffer_node_tag
 {
   struct packet_buffer_node_tag * next;
@@ -116,6 +123,8 @@ void packet_buffer_add(char * buffer, int size)
 packet_info packet_buffer_front(void)
 {
   packet_info result;
+  static char * lastAddress = NULL;
+  char * thisAddress = packet_buffer_head->buffer + packet_buffer_index;
   if (packet_buffer_head == NULL)
   {
     printf("packet_buffer_head == NULL in front\n");
@@ -154,6 +163,15 @@ packet_info packet_buffer_front(void)
     result.type = ntohs(result.type);
     base += sizeof(result.type);
   }
+  if (thisAddress != lastAddress)
+  {
+      logWrite(PACKET_BUFFER_DETAIL, NULL,
+	       "Looking at packet: type(%hu) value(%lu) delta(%lu) "
+	       "source_port(%hu) dest_port(%hu) ip(%s)",
+	       result.type, result.value, result.delta, result.source_port,
+	       result.dest_port, ipToString(result.ip));
+  }
+  lastAddress = thisAddress;
   return result;
 }
 
@@ -181,13 +199,6 @@ void packet_buffer_advance(void)
   }
 }
 
-char * ipToString(unsigned long ip)
-{
-  struct in_addr address;
-  address.s_addr = ip;
-  return inet_ntoa(address);
-}
-
 void init_random_buffer(void)
 {
   int i = 0;
@@ -1010,6 +1021,10 @@ int main(int argc, char *argv[]) {
 	{
 	    logflags = logflags | DELAY_DETAIL;
 	}
+	else if (strcmp(optarg, "packet-buffer-detail") == 0)
+	{
+	    logflags = logflags | PACKET_BUFFER_DETAIL;
+	}
 	else
 	{
 	    fprintf(stderr, "Unknown logging option %s\n", optarg);