src/ats-tests/ats-testing-log.c

   1 /*
   2  This file is part of GNUnet.
   3  (C) 2010-2013 Christian Grothoff (and other contributing authors)
   4
   5  GNUnet is free software; you can redistribute it and/or modify
   6  it under the terms of the GNU General Public License as published
   7  by the Free Software Foundation; either version 3, or (at your
   8  option) any later version.
   9
  10  GNUnet is distributed in the hope that it will be useful, but
  11  WITHOUT ANY WARRANTY; without even the implied warranty of
  12  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
  13  General Public License for more details.
  14
  15  You should have received a copy of the GNU General Public License
  16  along with GNUnet; see the file COPYING.  If not, write to the
  17  Free Software Foundation, Inc., 59 Temple Place - Suite 330,
  18  Boston, MA 02111-1307, USA.
  19  */
  20 /**
  21  * @file ats-tests/ats-testing-log.c
  22  * @brief ats benchmark: logging for performance tests
  23  * @author Christian Grothoff
  24  * @author Matthias Wachs
  25  */
  26 #include "platform.h"
  27 #include "gnunet_util_lib.h"
  28 #include "ats-testing.h"
  29
  30 #define THROUGHPUT_TEMPLATE "#!/usr/bin/gnuplot \n" \
  31 "set datafile separator ';' \n" \
  32 "set title \"Throughput between Master and Slaves\" \n" \
  33 "set xlabel \"Time in ms\" \n" \
  34 "set ylabel \"Bytes/s\" \n" \
  35 "set grid \n"
  36
  37 #define RTT_TEMPLATE "#!/usr/bin/gnuplot \n" \
  38 "set datafile separator ';' \n" \
  39 "set title \"Application level roundtrip time between Master and Slaves\" \n" \
  40 "set xlabel \"Time in ms\" \n" \
  41 "set ylabel \"ms\" \n" \
  42 "set grid \n"
  43
  44 #define BW_TEMPLATE "#!/usr/bin/gnuplot \n" \
  45 "set datafile separator ';' \n" \
  46 "set title \"Bandwidth inbound and outbound between Master and Slaves\" \n" \
  47 "set xlabel \"Time in ms\" \n" \
  48 "set ylabel \"Bytes / s \" \n" \
  49 "set grid \n"
  50
  51 #define LOG_ITEMS_TIME 2
  52 #define LOG_ITEMS_PER_PEER 17
  53
  54 #define LOG_ITEM_BYTES_SENT 1
  55 #define LOG_ITEM_MSGS_SENT 2
  56 #define LOG_ITEM_THROUGHPUT_SENT 3
  57 #define LOG_ITEM_BYTES_RECV 4
  58 #define LOG_ITEM_MSGS_RECV 5
  59 #define LOG_ITEM_THROUGHPUT_RECV 6
  60 #define LOG_ITEM_APP_RTT 7
  61 #define LOG_ITEM_ATS_BW_IN 8
  62 #define LOG_ITEM_ATS_BW_OUT 9
  63 #define LOG_ITEM_ATS_COSTS_LAN 10
  64 #define LOG_ITEM_ATS_WAN 11
  65 #define LOG_ITEM_ATS_WLAN 12
  66 #define LOG_ITEM_ATS_DELAY 13
  67 #define LOG_ITEM_ATS_DISTANCE 14
  68 #define LOG_ITEM_ATS_NETWORKTYPE 15
  69 #define LOG_ITEM_ATS_UTIL_UP 16
  70 #define LOG_ITEM_ATS_UTIL_DOWN 17
  71
  72 /**
  73  * A single logging time step for a partner
  74  */
  75 struct PartnerLoggingTimestep
  76 {
  77   /**
  78    * Peer
  79    */
  80   struct BenchmarkPeer *slave;
  81
  82   /**
  83    * Total number of messages this peer has sent
  84    */
  85   unsigned int total_messages_sent;
  86
  87   /**
  88    * Total number of bytes this peer has sent
  89    */
  90   unsigned int total_bytes_sent;
  91
  92   /**
  93    * Total number of messages this peer has received
  94    */
  95   unsigned int total_messages_received;
  96
  97   /**
  98    * Total number of bytes this peer has received
  99    */
 100   unsigned int total_bytes_received;
 101
 102   /**
 103    * Total outbound throughput for master in Bytes / s
 104    */
 105   unsigned int throughput_sent;
 106
 107   /**
 108    * Total inbound throughput for master in Bytes / s
 109    */
 110   unsigned int throughput_recv;
 111
 112   /**
 113    * Accumulated RTT for all messages
 114    */
 115   unsigned int total_app_rtt;
 116
 117   /**
 118    * Current application level delay
 119    */
 120   unsigned int app_rtt;
 121
 122   /* Current ATS properties */
 123
 124   uint32_t ats_distance;
 125
 126   uint32_t ats_delay;
 127
 128   uint32_t bandwidth_in;
 129
 130   uint32_t bandwidth_out;
 131
 132   uint32_t ats_utilization_up;
 133
 134   uint32_t ats_utilization_down;
 135
 136   uint32_t ats_network_type;
 137
 138   uint32_t ats_cost_wan;
 139
 140   uint32_t ats_cost_lan;
 141
 142   uint32_t ats_cost_wlan;
 143 };
 144
 145
 146 /**
 147  * A single logging time step for a peer
 148  */
 149 struct PeerLoggingTimestep
 150 {
 151   /**
 152    * Next in DLL
 153    */
 154   struct PeerLoggingTimestep *next;
 155
 156   /**
 157    * Prev in DLL
 158    */
 159   struct PeerLoggingTimestep *prev;
 160
 161   /**
 162    * Logging timestamp
 163    */
 164   struct GNUNET_TIME_Absolute timestamp;
 165
 166   /**
 167    * Total number of messages this peer has sent
 168    */
 169   unsigned int total_messages_sent;
 170
 171   /**
 172    * Total number of bytes this peer has sent
 173    */
 174   unsigned int total_bytes_sent;
 175
 176   /**
 177    * Total number of messages this peer has received
 178    */
 179   unsigned int total_messages_received;
 180
 181   /**
 182    * Total number of bytes this peer has received
 183    */
 184   unsigned int total_bytes_received;
 185
 186   /**
 187    * Total outbound throughput for master in Bytes / s
 188    */
 189   unsigned int total_throughput_send;
 190
 191   /**
 192    * Total inbound throughput for master in Bytes / s
 193    */
 194   unsigned int total_throughput_recv;
 195
 196   /**
 197    * Logs for slaves
 198    */
 199   struct PartnerLoggingTimestep *slaves_log;
 200 };
 201
 202 /**
 203  * Entry for a benchmark peer
 204  */
 205 struct LoggingPeer
 206 {
 207   /**
 208    * Peer
 209    */
 210   struct BenchmarkPeer *peer;
 211
 212   /**
 213    * Start time
 214    */
 215   struct GNUNET_TIME_Absolute start;
 216
 217   /**
 218    * DLL for logging entries: head
 219    */
 220   struct PeerLoggingTimestep *head;
 221
 222   /**
 223    * DLL for logging entries: tail
 224    */
 225   struct PeerLoggingTimestep *tail;
 226 };
 227
 228 struct LoggingHandle
 229 {
 230   /**
 231    * Logging task
 232    */
 233   GNUNET_SCHEDULER_TaskIdentifier log_task;
 234
 235   /**
 236    * Reference to perf_ats' masters
 237    */
 238   int num_peers;
 239   int running;
 240   char *name;
 241   struct GNUNET_TIME_Relative frequency;
 242
 243   /**
 244    * Log structure of length num_peers
 245    */
 246   struct LoggingPeer *lp;
 247
 248 };
 249
 250
 251
 252 static void
 253 write_throughput_gnuplot_script (char * fn, struct LoggingPeer *lp)
 254 {
 255   struct GNUNET_DISK_FileHandle *f;
 256   char * gfn;
 257   char *data;
 258   int c_s;
 259   int peer_index;
 260
 261   GNUNET_asprintf (&gfn, "gnuplot_throughput_%s",fn);
 262   f = GNUNET_DISK_file_open (gfn,
 263       GNUNET_DISK_OPEN_WRITE | GNUNET_DISK_OPEN_CREATE,
 264       GNUNET_DISK_PERM_USER_EXEC | GNUNET_DISK_PERM_USER_READ | GNUNET_DISK_PERM_USER_WRITE);
 265   if (NULL == f)
 266   {
 267     GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot open gnuplot file `%s'\n", gfn);
 268     GNUNET_free (gfn);
 269     return;
 270   }
 271
 272   /* Write header */
 273
 274   if (GNUNET_SYSERR == GNUNET_DISK_file_write(f, THROUGHPUT_TEMPLATE, strlen(THROUGHPUT_TEMPLATE)))
 275     GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot write data to plot file `%s'\n", gfn);
 276
 277   /* Write master data */
 278   peer_index = LOG_ITEMS_TIME;
 279   GNUNET_asprintf (&data, "plot '%s' using 2:%u with lines title 'Master %u send total', \\\n" \
 280                            "'%s' using 2:%u with lines title 'Master %u receive total', \\\n",
 281                            fn, peer_index + LOG_ITEM_THROUGHPUT_SENT, lp->peer->no,
 282                            fn, peer_index + LOG_ITEM_THROUGHPUT_RECV, lp->peer->no);
 283   if (GNUNET_SYSERR == GNUNET_DISK_file_write(f, data, strlen(data)))
 284     GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot write data to plot file `%s'\n", gfn);
 285   GNUNET_free (data);
 286
 287   peer_index = LOG_ITEMS_TIME + LOG_ITEMS_PER_PEER ;
 288   for (c_s = 0; c_s < lp->peer->num_partners; c_s++)
 289   {
 290     GNUNET_asprintf (&data, "'%s' using 2:%u with lines title 'Master %u - Slave %u send', \\\n" \
 291                             "'%s' using 2:%u with lines title 'Master %u - Slave %u receive'%s\n",
 292                             fn, peer_index + LOG_ITEM_THROUGHPUT_SENT, lp->peer->no, lp->peer->partners[c_s].dest->no,
 293                             fn, peer_index + LOG_ITEM_THROUGHPUT_RECV, lp->peer->no, lp->peer->partners[c_s].dest->no,
 294                             (c_s < lp->peer->num_partners -1) ? ", \\" : "\n pause -1");
 295     if (GNUNET_SYSERR == GNUNET_DISK_file_write(f, data, strlen(data)))
 296         GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot write data to plot file `%s'\n", gfn);
 297     GNUNET_free (data);
 298     peer_index += LOG_ITEMS_PER_PEER;
 299   }
 300
 301   if (GNUNET_SYSERR == GNUNET_DISK_file_close(f))
 302     GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot close gnuplot file `%s'\n", gfn);
 303   else
 304     GNUNET_log (GNUNET_ERROR_TYPE_INFO, "Data successfully written to plot file `%s'\n", gfn);
 305
 306   GNUNET_free (gfn);
 307 }
 308
 309
 310 static void
 311 write_rtt_gnuplot_script (char * fn, struct LoggingPeer *lp)
 312 {
 313   struct GNUNET_DISK_FileHandle *f;
 314   char * gfn;
 315   char *data;
 316   int c_s;
 317   int index;
 318
 319   GNUNET_asprintf (&gfn, "gnuplot_rtt_%s",fn);
 320   f = GNUNET_DISK_file_open (gfn,
 321       GNUNET_DISK_OPEN_WRITE | GNUNET_DISK_OPEN_CREATE,
 322       GNUNET_DISK_PERM_USER_EXEC | GNUNET_DISK_PERM_USER_READ | GNUNET_DISK_PERM_USER_WRITE);
 323   if (NULL == f)
 324   {
 325     GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot open gnuplot file `%s'\n", gfn);
 326     GNUNET_free (gfn);
 327     return;
 328   }
 329
 330   /* Write header */
 331
 332   if (GNUNET_SYSERR == GNUNET_DISK_file_write(f, RTT_TEMPLATE, strlen(RTT_TEMPLATE)))
 333     GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot write data to plot file `%s'\n", gfn);
 334
 335   index = LOG_ITEMS_TIME + LOG_ITEMS_PER_PEER;
 336   for (c_s = 0; c_s < lp->peer->num_partners; c_s++)
 337   {
 338     GNUNET_asprintf (&data, "%s'%s' using 2:%u with lines title 'Master %u - Slave %u '%s\n",
 339         (0 == c_s) ? "plot " :"",
 340         fn, index + LOG_ITEM_APP_RTT, lp->peer->no, lp->peer->partners[c_s].dest->no,
 341         (c_s < lp->peer->num_partners -1) ? ", \\" : "\n pause -1");
 342     if (GNUNET_SYSERR == GNUNET_DISK_file_write(f, data, strlen(data)))
 343         GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot write data to plot file `%s'\n", gfn);
 344     GNUNET_free (data);
 345     index += LOG_ITEMS_PER_PEER;
 346   }
 347
 348   if (GNUNET_SYSERR == GNUNET_DISK_file_close(f))
 349     GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot close gnuplot file `%s'\n", gfn);
 350   else
 351     GNUNET_log (GNUNET_ERROR_TYPE_INFO, "Data successfully written to plot file `%s'\n", gfn);
 352   GNUNET_free (gfn);
 353 }
 354
 355 static void
 356 write_bw_gnuplot_script (char * fn, struct LoggingPeer *lp)
 357 {
 358   struct GNUNET_DISK_FileHandle *f;
 359   char * gfn;
 360   char *data;
 361   int c_s;
 362   int index;
 363
 364   GNUNET_asprintf (&gfn, "gnuplot_bw_%s",fn);
 365   f = GNUNET_DISK_file_open (gfn,
 366       GNUNET_DISK_OPEN_WRITE | GNUNET_DISK_OPEN_CREATE,
 367       GNUNET_DISK_PERM_USER_EXEC | GNUNET_DISK_PERM_USER_READ | GNUNET_DISK_PERM_USER_WRITE);
 368   if (NULL == f)
 369   {
 370     GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot open gnuplot file `%s'\n", gfn);
 371     GNUNET_free (gfn);
 372     return;
 373   }
 374
 375   /* Write header */
 376
 377   if (GNUNET_SYSERR == GNUNET_DISK_file_write(f, BW_TEMPLATE, strlen(BW_TEMPLATE)))
 378     GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot write data to plot file `%s'\n", gfn);
 379
 380   index = LOG_ITEMS_TIME + LOG_ITEMS_PER_PEER;
 381   for (c_s = 0; c_s < lp->peer->num_partners; c_s++)
 382   {
 383     GNUNET_asprintf (&data, "%s"\
 384         "'%s' using 2:%u with lines title 'BW out master %u - Slave %u ', \\\n" \
 385         "'%s' using 2:%u with lines title 'BW in master %u - Slave %u '"\
 386         "%s\n",
 387         (0 == c_s) ? "plot " :"",
 388         fn, index + LOG_ITEM_ATS_BW_OUT, lp->peer->no, lp->peer->partners[c_s].dest->no,
 389         fn, index + LOG_ITEM_ATS_BW_IN, lp->peer->no, lp->peer->partners[c_s].dest->no,
 390         (c_s < lp->peer->num_partners -1) ? ", \\" : "\n pause -1");
 391     if (GNUNET_SYSERR == GNUNET_DISK_file_write(f, data, strlen(data)))
 392         GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot write data to plot file `%s'\n", gfn);
 393     GNUNET_free (data);
 394     index += LOG_ITEMS_PER_PEER;
 395   }
 396
 397   if (GNUNET_SYSERR == GNUNET_DISK_file_close(f))
 398     GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot close gnuplot file `%s'\n", gfn);
 399   else
 400     GNUNET_log (GNUNET_ERROR_TYPE_INFO, "Data successfully written to plot file `%s'\n", gfn);
 401   GNUNET_free (gfn);
 402 }
 403
 404
 405 void
 406 GNUNET_ATS_TEST_logging_write_to_file (struct LoggingHandle *l, char *test)
 407 {
 408   struct GNUNET_DISK_FileHandle *f;
 409
 410   char * filename;
 411   char *data;
 412   char *slave_string;
 413   char *slave_string_tmp;
 414   struct PeerLoggingTimestep *cur_lt;
 415   struct PartnerLoggingTimestep *plt;
 416   int c_m;
 417   int c_s;
 418
 419   for (c_m = 0; c_m < l->num_peers; c_m++)
 420   {
 421     GNUNET_asprintf (&filename, "%s_%llu_master_%u_%s_%s.data", test, GNUNET_TIME_absolute_get().abs_value_us,
 422         l->lp[c_m].peer->no, GNUNET_i2s(&l->lp[c_m].peer->id), l->name);
 423
 424     f = GNUNET_DISK_file_open (filename,
 425         GNUNET_DISK_OPEN_WRITE | GNUNET_DISK_OPEN_CREATE,
 426         GNUNET_DISK_PERM_USER_READ | GNUNET_DISK_PERM_USER_WRITE);
 427     if (NULL == f)
 428     {
 429       GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot open log file `%s'\n", filename);
 430       GNUNET_free (filename);
 431       return;
 432     }
 433
 434     for (cur_lt = l->lp[c_m].head; NULL != cur_lt; cur_lt = cur_lt->next)
 435     {
 436        GNUNET_log(GNUNET_ERROR_TYPE_INFO,
 437           "Master [%u]: timestamp %llu %llu ; %u %u %u ; %u %u %u\n", l->lp[c_m].peer->no,
 438           cur_lt->timestamp, GNUNET_TIME_absolute_get_difference(l->lp[c_m].start,cur_lt->timestamp).rel_value_us / 1000,
 439           cur_lt->total_messages_sent, cur_lt->total_bytes_sent, cur_lt->total_throughput_send,
 440           cur_lt->total_messages_received, cur_lt->total_bytes_received, cur_lt->total_throughput_recv);
 441
 442       slave_string = GNUNET_strdup (";");
 443       for (c_s = 0; c_s < l->lp[c_m].peer->num_partners; c_s++)
 444       {
 445         plt = &cur_lt->slaves_log[c_s];
 446         /* Log partners */
 447
 448         /* Assembling slave string */
 449         GNUNET_log(GNUNET_ERROR_TYPE_INFO,
 450             "\t Slave [%u]: %u %u %u ; %u %u %u rtt %u delay %u bw_in %u bw_out %u \n", plt->slave->no,
 451             plt->total_messages_sent, plt->total_bytes_sent, plt->throughput_sent,
 452             plt->total_messages_received, plt->total_bytes_received, plt->throughput_recv,
 453             plt->app_rtt, plt->ats_delay,
 454             plt->bandwidth_in, plt->bandwidth_out);
 455
 456         GNUNET_asprintf(&slave_string_tmp, "%s%u;%u;%u;%u;%u;%u;%.3f;%u;%u;%u;%u;%u;%u;%u;%u;%u;%u;",slave_string,
 457             plt->total_messages_sent, plt->total_bytes_sent,  plt->throughput_sent,
 458             plt->total_messages_received, plt->total_bytes_received,  plt->throughput_sent,
 459             (double) plt->app_rtt / 1000,
 460             plt->bandwidth_in,plt->bandwidth_out,
 461             plt->ats_cost_lan, plt->ats_cost_wan, plt->ats_cost_wlan,
 462             plt->ats_delay, plt->ats_distance, plt->ats_network_type,
 463             plt->ats_utilization_up, plt->ats_utilization_down);
 464         GNUNET_free (slave_string);
 465         slave_string = slave_string_tmp;
 466       }
 467       /* Assembling master string */
 468
 469
 470
 471       GNUNET_asprintf (&data, "%llu;%llu;%u;%u;%u;%u;%u;%u;;;;;;;;;;;%s\n",
 472           cur_lt->timestamp,
 473           GNUNET_TIME_absolute_get_difference(l->lp[c_m].start,cur_lt->timestamp).rel_value_us / 1000,
 474           cur_lt->total_messages_sent, cur_lt->total_bytes_sent,  cur_lt->total_throughput_send,
 475           cur_lt->total_messages_received, cur_lt->total_bytes_received, cur_lt->total_throughput_recv,
 476           slave_string);
 477       GNUNET_free (slave_string);
 478
 479       if (GNUNET_SYSERR == GNUNET_DISK_file_write(f, data, strlen(data)))
 480         GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot write data to log file `%s'\n", filename);
 481       GNUNET_free (data);
 482     }
 483     if (GNUNET_SYSERR == GNUNET_DISK_file_close(f))
 484     {
 485       GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot close log file `%s'\n", filename);
 486       GNUNET_free (filename);
 487       return;
 488     }
 489
 490     write_throughput_gnuplot_script (filename, l->lp);
 491     write_rtt_gnuplot_script (filename, l->lp);
 492     write_bw_gnuplot_script (filename, l->lp);
 493
 494     GNUNET_log (GNUNET_ERROR_TYPE_INFO, "Data file successfully written to log file `%s'\n", filename);
 495     GNUNET_free (filename);
 496   }
 497 }
 498
 499
 500 void
 501 GNUNET_ATS_TEST_logging_now (struct LoggingHandle *l)
 502 {
 503   struct LoggingPeer *bp;
 504   struct PeerLoggingTimestep *mlt;
 505   struct PeerLoggingTimestep *prev_log_mlt;
 506   struct PartnerLoggingTimestep *slt;
 507   struct PartnerLoggingTimestep *prev_log_slt;
 508   struct BenchmarkPartner *p;
 509   struct GNUNET_TIME_Relative delta;
 510   int c_s;
 511   int c_m;
 512   unsigned int app_rtt;
 513   double mult;
 514
 515   if (GNUNET_YES != l->running)
 516     return;
 517
 518   for (c_m = 0; c_m < l->num_peers; c_m++)
 519   {
 520     bp = &l->lp[c_m];
 521     mlt = GNUNET_new (struct PeerLoggingTimestep);
 522     GNUNET_CONTAINER_DLL_insert_tail(bp->head, bp->tail, mlt);
 523     prev_log_mlt = mlt->prev;
 524
 525     /* Collect data */
 526
 527     /* Current master state */
 528     mlt->timestamp = GNUNET_TIME_absolute_get();
 529     mlt->total_bytes_sent = bp->peer->total_bytes_sent;
 530     mlt->total_messages_sent = bp->peer->total_messages_sent;
 531     mlt->total_bytes_received = bp->peer->total_bytes_received;
 532     mlt->total_messages_received = bp->peer->total_messages_received;
 533
 534     /* Throughput */
 535     if (NULL == prev_log_mlt)
 536      {
 537        /* Get difference to start */
 538        delta = GNUNET_TIME_absolute_get_difference (l->lp[c_m].start, mlt->timestamp);
 539      }
 540      else
 541      {
 542        /* Get difference to last timestep */
 543        delta = GNUNET_TIME_absolute_get_difference (mlt->prev->timestamp, mlt->timestamp);
 544      }
 545
 546      /* Multiplication factor for throughput calculation */
 547      mult = (1.0 * 1000 * 1000) / (delta.rel_value_us);
 548
 549      /* Total throughput */
 550      if (NULL != prev_log_mlt)
 551      {
 552        if (mlt->total_bytes_sent - mlt->prev->total_bytes_sent > 0)
 553          mlt->total_throughput_send = mult * (mlt->total_bytes_sent - mlt->prev->total_bytes_sent);
 554        else
 555          mlt->total_throughput_send = prev_log_mlt->total_throughput_send; /* no msgs send */
 556
 557        if (mlt->total_bytes_received - mlt->prev->total_bytes_received > 0)
 558          mlt->total_throughput_recv = mult * (mlt->total_bytes_received - mlt->prev->total_bytes_received);
 559        else
 560          mlt->total_throughput_recv = prev_log_mlt->total_throughput_recv; /* no msgs received */
 561      }
 562      else
 563      {
 564        mlt->total_throughput_send = mult * mlt->total_bytes_sent;
 565        mlt->total_throughput_send = mult * mlt->total_bytes_received;
 566      }
 567
 568     mlt->slaves_log = GNUNET_malloc (bp->peer->num_partners *
 569         sizeof (struct PartnerLoggingTimestep));
 570
 571     for (c_s = 0; c_s < bp->peer->num_partners; c_s++)
 572     {
 573       p = &bp->peer->partners[c_s];
 574       slt = &mlt->slaves_log[c_s];
 575
 576       slt->slave = p->dest;
 577       /* Bytes sent from master to this slave */
 578       slt->total_bytes_sent = p->bytes_sent;
 579       /* Messages sent from master to this slave */
 580       slt->total_messages_sent = p->messages_sent;
 581       /* Bytes master received from this slave */
 582       slt->total_bytes_received = p->bytes_received;
 583       /* Messages master received from this slave */
 584       slt->total_messages_received = p->messages_received;
 585       slt->total_app_rtt = p->total_app_rtt;
 586       /* ats performance information */
 587       slt->ats_cost_lan = p->ats_cost_lan;
 588       slt->ats_cost_wan = p->ats_cost_wan;
 589       slt->ats_cost_wlan = p->ats_cost_wlan;
 590       slt->ats_delay = p->ats_delay;
 591       slt->ats_distance = p->ats_distance;
 592       slt->ats_network_type = p->ats_network_type;
 593       slt->ats_utilization_down = p->ats_utilization_down;
 594       slt->ats_utilization_up = p->ats_utilization_up;
 595       slt->bandwidth_in = p->bandwidth_in;
 596       slt->bandwidth_out = p->bandwidth_out;
 597
 598       /* Total application level rtt  */
 599       if (NULL == prev_log_mlt)
 600       {
 601         if (0 != slt->total_messages_sent)
 602           app_rtt = slt->total_app_rtt / slt->total_messages_sent;
 603         else
 604           app_rtt = 0;
 605       }
 606       else
 607       {
 608         prev_log_slt =  &prev_log_mlt->slaves_log[c_s];
 609         if ((slt->total_messages_sent - prev_log_slt->total_messages_sent) > 0)
 610           app_rtt = (slt->total_app_rtt - prev_log_slt->total_app_rtt) /
 611                   (slt->total_messages_sent - prev_log_slt->total_messages_sent);
 612         else
 613           app_rtt = prev_log_slt->app_rtt; /* No messages were */
 614       }
 615       slt->app_rtt = app_rtt;
 616
 617       /* Partner throughput */
 618       if (NULL != prev_log_mlt)
 619       {
 620         prev_log_slt =  &prev_log_mlt->slaves_log[c_s];
 621         if (slt->total_bytes_sent - prev_log_slt->total_bytes_sent > 0)
 622           slt->throughput_sent = mult * (slt->total_bytes_sent - prev_log_slt->total_bytes_sent);
 623         else
 624           slt->throughput_sent = prev_log_slt->throughput_sent; /* no msgs send */
 625
 626         if (slt->total_bytes_received - prev_log_slt->total_bytes_received > 0)
 627           slt->throughput_recv = mult * (slt->total_bytes_received - prev_log_slt->total_bytes_received);
 628         else
 629           slt->throughput_recv = prev_log_slt->throughput_recv; /* no msgs received */
 630       }
 631       else
 632       {
 633         slt->throughput_sent = mult * slt->total_bytes_sent;
 634         slt->throughput_sent = mult * slt->total_bytes_received;
 635       }
 636
 637       GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
 638           "Master [%u]: slave [%u]\n",
 639           bp->peer->no, p->dest->no);
 640     }
 641   }
 642 }
 643
 644 static void
 645 collect_log_task (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc)
 646 {
 647   struct LoggingHandle *l = cls;
 648   l->log_task = GNUNET_SCHEDULER_NO_TASK;
 649
 650   GNUNET_ATS_TEST_logging_now (l);
 651
 652   if (tc->reason == GNUNET_SCHEDULER_REASON_SHUTDOWN)
 653     return;
 654
 655   l->log_task = GNUNET_SCHEDULER_add_delayed (l->frequency,
 656       &collect_log_task, l);
 657 }
 658
 659 /**
 660  * Stop logging
 661  *
 662  * @param l the logging handle
 663  */
 664 void
 665 GNUNET_ATS_TEST_logging_stop (struct LoggingHandle *l)
 666 {
 667   int c_m;
 668   struct GNUNET_SCHEDULER_TaskContext tc;
 669   struct PeerLoggingTimestep *cur;
 670
 671   if (GNUNET_YES!= l->running)
 672     return;
 673
 674   if (GNUNET_SCHEDULER_NO_TASK != l->log_task)
 675     GNUNET_SCHEDULER_cancel (l->log_task);
 676   l->log_task = GNUNET_SCHEDULER_NO_TASK;
 677   tc.reason = GNUNET_SCHEDULER_REASON_SHUTDOWN;
 678   collect_log_task (l, &tc);
 679
 680   GNUNET_log(GNUNET_ERROR_TYPE_INFO,
 681       _("Stop logging\n"));
 682
 683
 684   for (c_m = 0; c_m < l->num_peers; c_m++)
 685   {
 686     while (NULL != (cur = l->lp[c_m].head))
 687     {
 688       GNUNET_CONTAINER_DLL_remove (l->lp[c_m].head, l->lp[c_m].tail, cur);
 689       GNUNET_free (cur->slaves_log);
 690       GNUNET_free (cur);
 691     }
 692   }
 693
 694   GNUNET_free (l->lp);
 695   GNUNET_free (l);
 696 }
 697
 698
 699 /**
 700  * Start logging
 701  *
 702  * @param log_frequency the logging frequency
 703  * @param testname the testname
 704  * @param masters the master peers used for benchmarking
 705  * @oaram num_master the number of master peers
 706  * @return the logging handle or NULL on error
 707  */
 708 struct LoggingHandle *
 709 GNUNET_ATS_TEST_logging_start (struct GNUNET_TIME_Relative log_frequency,
 710     char * testname, struct BenchmarkPeer *masters, int num_masters)
 711 {
 712   struct LoggingHandle *l;
 713   int c_m;
 714   GNUNET_log(GNUNET_ERROR_TYPE_INFO,
 715       _("Start logging `%s'\n"), testname);
 716
 717   l = GNUNET_new (struct LoggingHandle);
 718   l->num_peers = num_masters;
 719   l->name = testname;
 720   l->frequency = log_frequency;
 721   l->lp = GNUNET_malloc (num_masters * sizeof (struct LoggingPeer));
 722
 723   for (c_m = 0; c_m < num_masters; c_m ++)
 724   {
 725     l->lp[c_m].peer = &masters[c_m];
 726     l->lp[c_m].start = GNUNET_TIME_absolute_get();
 727   }
 728
 729   /* Schedule logging task */
 730   l->log_task = GNUNET_SCHEDULER_add_now (&collect_log_task, l);
 731   l->running = GNUNET_YES;
 732
 733   return l;
 734 }
 735 /* end of file ats-testing-log.c */
 736