logging on demand + log bandwidth
[oweals/gnunet.git] / src / ats-tests / perf_ats_logging.c
index 30d6e397e298548ccfccd91f4b2fcd370e49d7b7..213958e6b4c858b5b51231b3802551d06b88c259 100644 (file)
 "set ylabel \"ms\" \n"
 
 #define LOG_ITEMS_PER_PEER 7
+#define LOG_ITEMS_TIME 2
+
+#define LOG_ITEMS_BYTES_SENT 1
+#define LOG_ITEMS_MSGS_SENT 2
+#define LOG_ITEMS_THROUGHPUT_SENT 3
+#define LOG_ITEMS_BYTES_RECV 4
+#define LOG_ITEMS_MSGS_RECV 5
+#define LOG_ITEMS_THROUGHPUT_RECV 6
+#define LOG_ITEMS_APP_RTT 7
+
 
 /**
  * Logging task
@@ -89,11 +99,32 @@ struct PartnerLoggingTimestep
    */
   unsigned int total_app_rtt;
 
-
   /**
    * Current application level delay
    */
   unsigned int app_rtt;
+
+  /* Current ATS properties */
+
+  uint32_t ats_distance;
+
+  uint32_t ats_delay;
+
+  uint32_t bandwidth_in;
+
+  uint32_t bandwidth_out;
+
+  uint32_t ats_utilization_up;
+
+  uint32_t ats_utilization_down;
+
+  uint32_t ats_network_type;
+
+  uint32_t ats_cost_wan;
+
+  uint32_t ats_cost_lan;
+
+  uint32_t ats_cost_wlan;
 };
 
 
@@ -182,7 +213,7 @@ write_throughput_gnuplot_script (char * fn, struct LoggingPeer *lp)
   char * gfn;
   char *data;
   int c_s;
-  int index;
+  int peer_index;
 
   GNUNET_asprintf (&gfn, "gnuplot_throughput_%s",fn);
   f = GNUNET_DISK_file_open (gfn,
@@ -201,26 +232,27 @@ write_throughput_gnuplot_script (char * fn, struct LoggingPeer *lp)
     GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot write data to plot file `%s'\n", gfn);
 
   /* Write master data */
+  peer_index = LOG_ITEMS_TIME;
   GNUNET_asprintf (&data, "plot '%s' using 2:%u with lines title 'Master %u send total', \\\n" \
                            "'%s' using 2:%u with lines title 'Master %u receive total', \\\n",
-                           fn, 5, lp->peer->no,
-                           fn, 8, lp->peer->no);
+                           fn, peer_index + LOG_ITEMS_THROUGHPUT_SENT, lp->peer->no,
+                           fn, peer_index + LOG_ITEMS_THROUGHPUT_RECV, lp->peer->no);
   if (GNUNET_SYSERR == GNUNET_DISK_file_write(f, data, strlen(data)))
     GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot write data to plot file `%s'\n", gfn);
   GNUNET_free (data);
 
-  index = 2 + LOG_ITEMS_PER_PEER + 3 ;
+  peer_index = LOG_ITEMS_TIME + LOG_ITEMS_PER_PEER ;
   for (c_s = 0; c_s < lp->peer->num_partners; c_s++)
   {
-    GNUNET_asprintf (&data, "'%s' using 2:%u with lines title 'Master - Slave %u send', \\\n" \
-                            "'%s' using 2:%u with lines title 'Master - Slave %u receive'%s\n",
-                            fn, index, lp->peer->partners[c_s].dest->no,
-                            fn, index+3, lp->peer->partners[c_s].dest->no,
+    GNUNET_asprintf (&data, "'%s' using 2:%u with lines title 'Master %u - Slave %u send', \\\n" \
+                            "'%s' using 2:%u with lines title 'Master %u - Slave %u receive'%s\n",
+                            fn, peer_index + LOG_ITEMS_THROUGHPUT_SENT, lp->peer->no, lp->peer->partners[c_s].dest->no,
+                            fn, peer_index + LOG_ITEMS_THROUGHPUT_RECV, lp->peer->no, lp->peer->partners[c_s].dest->no,
                             (c_s < lp->peer->num_partners -1) ? ", \\" : "\n pause -1");
     if (GNUNET_SYSERR == GNUNET_DISK_file_write(f, data, strlen(data)))
         GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot write data to plot file `%s'\n", gfn);
     GNUNET_free (data);
-    index += LOG_ITEMS_PER_PEER;
+    peer_index += LOG_ITEMS_PER_PEER;
   }
 
   if (GNUNET_SYSERR == GNUNET_DISK_file_close(f))
@@ -257,13 +289,12 @@ write_rtt_gnuplot_script (char * fn, struct LoggingPeer *lp)
   if (GNUNET_SYSERR == GNUNET_DISK_file_write(f, RTT_TEMPLATE, strlen(RTT_TEMPLATE)))
     GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot write data to plot file `%s'\n", gfn);
 
-  /* 1st column: 2 * timestamp _+ 7 * master + 7 */
-  index = 2 + LOG_ITEMS_PER_PEER + LOG_ITEMS_PER_PEER;
+  index = LOG_ITEMS_TIME + LOG_ITEMS_PER_PEER;
   for (c_s = 0; c_s < lp->peer->num_partners; c_s++)
   {
-    GNUNET_asprintf (&data, "%s'%s' using 2:%u with lines title 'Master - Slave %u '%s\n",
+    GNUNET_asprintf (&data, "%s'%s' using 2:%u with lines title 'Master %u - Slave %u '%s\n",
         (0 == c_s) ? "plot " :"",
-        fn, index, lp->peer->partners[c_s].dest->no,
+        fn, index + LOG_ITEMS_APP_RTT, lp->peer->no, lp->peer->partners[c_s].dest->no,
         (c_s < lp->peer->num_partners -1) ? ", \\" : "\n pause -1");
     if (GNUNET_SYSERR == GNUNET_DISK_file_write(f, data, strlen(data)))
         GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot write data to plot file `%s'\n", gfn);
@@ -282,6 +313,7 @@ static void
 write_to_file ()
 {
   struct GNUNET_DISK_FileHandle *f;
+  struct GNUNET_TIME_Relative delta;
   char * filename;
   char *data;
   char *slave_string;
@@ -294,6 +326,8 @@ write_to_file ()
   unsigned int throughput_send;
   unsigned int throughput_recv_slave;
   unsigned int throughput_send_slave;
+  int last_throughput_send;
+  int last_throughput_recv;
   double mult;
 
   for (c_m = 0; c_m < num_peers; c_m++)
@@ -311,22 +345,55 @@ write_to_file ()
       return;
     }
 
+    last_throughput_recv = 0;
+    last_throughput_send = 0;
 
     for (cur_lt = lp[c_m].head; NULL != cur_lt; cur_lt = cur_lt->next)
     {
-      mult = (1.0 * 1000 * 1000) /  (LOGGING_FREQUENCY.rel_value_us);
+      if (NULL == cur_lt->prev)
+      {
+        delta = GNUNET_TIME_absolute_get_difference (lp[c_m].start, cur_lt->timestamp);
+      }
+      else
+        delta = GNUNET_TIME_absolute_get_difference (cur_lt->prev->timestamp, cur_lt->timestamp);
+
+      /* Multiplication factor for throughput calculation */
+      mult = (1.0 * 1000 * 1000) / (delta.rel_value_us);
       if (NULL != cur_lt->prev)
       {
-        throughput_send = cur_lt->total_bytes_sent - cur_lt->prev->total_bytes_sent;
-        throughput_recv = cur_lt->total_bytes_received - cur_lt->prev->total_bytes_received;
+        if (cur_lt->total_bytes_sent - cur_lt->prev->total_bytes_sent > 0)
+        {
+          throughput_send = cur_lt->total_bytes_sent - cur_lt->prev->total_bytes_sent;
+          throughput_send *= mult;
+        }
+        else
+        {
+          //GNUNET_break (0);
+          throughput_send = last_throughput_send; /* no msgs received */
+        }
+
+        if (cur_lt->total_bytes_received - cur_lt->prev->total_bytes_received > 0)
+        {
+          throughput_recv = cur_lt->total_bytes_received - cur_lt->prev->total_bytes_received;
+          throughput_recv *= mult;
+        }
+        else
+        {
+         // GNUNET_break (0);
+          throughput_recv = last_throughput_recv; /* no msgs received */
+        }
       }
       else
       {
         throughput_send = cur_lt->total_bytes_sent;
         throughput_recv = cur_lt->total_bytes_received;
+
+        throughput_send *= mult;
+        throughput_recv *= mult;
+
       }
-      throughput_send *= mult;
-      throughput_recv *= mult;
+      last_throughput_send = throughput_send;
+      last_throughput_recv = throughput_recv;
 
 
       GNUNET_log(GNUNET_ERROR_TYPE_INFO,
@@ -354,9 +421,10 @@ write_to_file ()
         throughput_recv_slave *= mult;
         /* Assembling slave string */
         GNUNET_log(GNUNET_ERROR_TYPE_INFO,
-            "\t Slave [%u]: %u %u %u ; %u %u %u rtt %u \n", plt->slave->no,
+            "\t Slave [%u]: %u %u %u ; %u %u %u rtt %u delay %u \n", plt->slave->no,
             plt->total_messages_sent, plt->total_bytes_sent, throughput_send_slave,
-            plt->total_messages_received, plt->total_bytes_received, throughput_recv_slave, plt->app_rtt);
+            plt->total_messages_received, plt->total_bytes_received, throughput_recv_slave,
+            plt->app_rtt, plt->ats_delay);
 
 
         GNUNET_asprintf(&slave_string_tmp, "%s%u;%u;%u;%u;%u;%u;%.3f;",slave_string,
@@ -395,103 +463,95 @@ write_to_file ()
 }
 
 
-static void
-collect_log_now (struct LoggingPeer *bp)
+void
+collect_log_now (void)
 {
+  struct LoggingPeer *bp;
   struct PeerLoggingTimestep *mlt;
   struct PartnerLoggingTimestep *slt;
   struct PartnerLoggingTimestep *prev_log_slt;
   struct BenchmarkPartner *p;
   int c_s;
+  int c_m;
   unsigned int app_rtt;
 
-  mlt = GNUNET_malloc (sizeof (struct PeerLoggingTimestep));
-  GNUNET_CONTAINER_DLL_insert_tail(bp->head, bp->tail, mlt);
+  if (GNUNET_YES != running)
+    return;
 
-  /* Collect data */
+  for (c_m = 0; c_m < num_peers; c_m++)
+  {
+    bp = &lp[c_m];
+    mlt = GNUNET_malloc (sizeof (struct PeerLoggingTimestep));
+    GNUNET_CONTAINER_DLL_insert_tail(bp->head, bp->tail, mlt);
 
-  /* Current master state */
-  mlt->timestamp = GNUNET_TIME_absolute_get();
-  mlt->total_bytes_sent = bp->peer->total_bytes_sent;
-  mlt->total_messages_sent = bp->peer->total_messages_sent;
-  mlt->total_bytes_received = bp->peer->total_bytes_received;
-  mlt->total_messages_received = bp->peer->total_messages_received;
+    /* Collect data */
 
-  mlt->slaves_log = GNUNET_malloc (bp->peer->num_partners *
-      sizeof (struct PartnerLoggingTimestep));
+    /* Current master state */
+    mlt->timestamp = GNUNET_TIME_absolute_get();
+    mlt->total_bytes_sent = bp->peer->total_bytes_sent;
+    mlt->total_messages_sent = bp->peer->total_messages_sent;
+    mlt->total_bytes_received = bp->peer->total_bytes_received;
+    mlt->total_messages_received = bp->peer->total_messages_received;
 
-  for (c_s = 0; c_s < bp->peer->num_partners; c_s++)
-  {
-    p = &bp->peer->partners[c_s];
-    slt = &mlt->slaves_log[c_s];
-
-    slt->slave = p->dest;
-    /* Bytes sent from master to this slave */
-    slt->total_bytes_sent = p->bytes_sent;
-    /* Messages sent from master to this slave */
-    slt->total_messages_sent = p->messages_sent;
-    /* Bytes master received from this slave */
-    slt->total_bytes_received = p->bytes_received;
-    /* Messages master received from this slave */
-    slt->total_messages_received = p->messages_received;
-    slt->total_app_rtt = p->total_app_rtt;
-
-    /* Total application level rtt  */
-    /*
-    GNUNET_log(GNUNET_ERROR_TYPE_ERROR,
-        "Master [%u]: slave [%u]: partner total rtt %u / %u = %u\n",
-        bp->peer->no, p->dest->no,
-        p->total_app_rtt, p->messages_sent, (p->messages_sent != 0)?p->total_app_rtt / p->messages_sent : 0);
-*/
-    if (NULL == mlt->prev)
+    mlt->slaves_log = GNUNET_malloc (bp->peer->num_partners *
+        sizeof (struct PartnerLoggingTimestep));
+
+    for (c_s = 0; c_s < bp->peer->num_partners; c_s++)
     {
-      if (0 != slt->total_messages_sent)
-        app_rtt = slt->total_app_rtt / slt->total_messages_sent;
+      p = &bp->peer->partners[c_s];
+      slt = &mlt->slaves_log[c_s];
+
+      slt->slave = p->dest;
+      /* Bytes sent from master to this slave */
+      slt->total_bytes_sent = p->bytes_sent;
+      /* Messages sent from master to this slave */
+      slt->total_messages_sent = p->messages_sent;
+      /* Bytes master received from this slave */
+      slt->total_bytes_received = p->bytes_received;
+      /* Messages master received from this slave */
+      slt->total_messages_received = p->messages_received;
+      slt->total_app_rtt = p->total_app_rtt;
+      /* ats performance information */
+      slt->ats_cost_lan = p->ats_cost_lan;
+      slt->ats_cost_wan = p->ats_cost_wan;
+      slt->ats_cost_wlan = p->ats_cost_wlan;
+      slt->ats_delay = p->ats_delay;
+      slt->ats_distance = p->ats_distance;
+      slt->ats_network_type = p->ats_network_type;
+      slt->ats_utilization_down = p->ats_utilization_down;
+      slt->ats_utilization_up = p->ats_utilization_up;
+
+      /* Total application level rtt  */
+      if (NULL == mlt->prev)
+      {
+        if (0 != slt->total_messages_sent)
+          app_rtt = slt->total_app_rtt / slt->total_messages_sent;
+        else
+          app_rtt = 0;
+      }
       else
-        app_rtt = 0;
-    }
-    else
-    {
-      prev_log_slt =  &mlt->prev->slaves_log[c_s];
-/*
-      GNUNET_log(GNUNET_ERROR_TYPE_ERROR,
-          "Master [%u]: slave [%u]: %u - %u = %u  .....   delta messages %u - %u = %u \n",
-          bp->peer->no, p->dest->no,
-          slt->total_app_rtt, prev_log_slt->total_app_rtt, slt->total_app_rtt - prev_log_slt->total_app_rtt,
-          slt->total_messages_sent, prev_log_slt->total_messages_sent, slt->total_messages_sent - prev_log_slt->total_messages_sent
-          );
-*/
-
-      app_rtt = (slt->total_app_rtt - prev_log_slt->total_app_rtt) /
-                (slt->total_messages_sent - prev_log_slt->total_messages_sent);
-
+      {
+        prev_log_slt =  &mlt->prev->slaves_log[c_s];
+        if ((slt->total_messages_sent - prev_log_slt->total_messages_sent) > 0)
+          app_rtt = (slt->total_app_rtt - prev_log_slt->total_app_rtt) /
+                  (slt->total_messages_sent - prev_log_slt->total_messages_sent);
+        else
+          app_rtt = prev_log_slt->app_rtt; /* No messages were */
+      }
+      slt->app_rtt = app_rtt;
+      GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
+          "Master [%u]: slave [%u]\n",
+          bp->peer->no, p->dest->no);
     }
-
-
-    /*
-    GNUNET_log(GNUNET_ERROR_TYPE_ERROR,
-        "Master [%u]: slave [%u]: %u \ncurrent total rtt %u previous total rtt %u delta total rtt %u\n",
-        bp->peer->no, p->dest->no,
-        p->total_app_rtt,
-        slt->total_app_rtt, prev_log_slt->total_app_rtt, (slt->total_app_rtt - prev_log_slt->total_app_rtt) ,
-        app_rtt);*/
-    slt->app_rtt = app_rtt;
-
-    GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-        "Master [%u]: slave [%u]\n",
-        bp->peer->no, p->dest->no);
   }
 }
 
 static void
 collect_log_task (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc)
 {
-  int c_m;
-
   log_task = GNUNET_SCHEDULER_NO_TASK;
 
-  for (c_m = 0; c_m < num_peers; c_m++)
-    collect_log_now (&lp[c_m]);
+  collect_log_now();
 
   if (tc->reason == GNUNET_SCHEDULER_REASON_SHUTDOWN)
     return;