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_name)
 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_name, 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  * Log all data now
 501  *
 502  * @param llogging handle to use
 503  */
 504 void
 505 GNUNET_ATS_TEST_logging_now (struct LoggingHandle *l)
 506 {
 507   struct LoggingPeer *bp;
 508   struct PeerLoggingTimestep *mlt;
 509   struct PeerLoggingTimestep *prev_log_mlt;
 510   struct PartnerLoggingTimestep *slt;
 511   struct PartnerLoggingTimestep *prev_log_slt;
 512   struct BenchmarkPartner *p;
 513   struct GNUNET_TIME_Relative delta;
 514   int c_s;
 515   int c_m;
 516   unsigned int app_rtt;
 517   double mult;
 518
 519   if (GNUNET_YES != l->running)
 520     return;
 521
 522   for (c_m = 0; c_m < l->num_peers; c_m++)
 523   {
 524     bp = &l->lp[c_m];
 525     mlt = GNUNET_new (struct PeerLoggingTimestep);
 526     GNUNET_CONTAINER_DLL_insert_tail(bp->head, bp->tail, mlt);
 527     prev_log_mlt = mlt->prev;
 528
 529     /* Collect data */
 530
 531     /* Current master state */
 532     mlt->timestamp = GNUNET_TIME_absolute_get();
 533     mlt->total_bytes_sent = bp->peer->total_bytes_sent;
 534     mlt->total_messages_sent = bp->peer->total_messages_sent;
 535     mlt->total_bytes_received = bp->peer->total_bytes_received;
 536     mlt->total_messages_received = bp->peer->total_messages_received;
 537
 538     /* Throughput */
 539     if (NULL == prev_log_mlt)
 540      {
 541        /* Get difference to start */
 542        delta = GNUNET_TIME_absolute_get_difference (l->lp[c_m].start, mlt->timestamp);
 543      }
 544      else
 545      {
 546        /* Get difference to last timestep */
 547        delta = GNUNET_TIME_absolute_get_difference (mlt->prev->timestamp, mlt->timestamp);
 548      }
 549
 550      /* Multiplication factor for throughput calculation */
 551      mult = (1.0 * 1000 * 1000) / (delta.rel_value_us);
 552
 553      /* Total throughput */
 554      if (NULL != prev_log_mlt)
 555      {
 556        if (mlt->total_bytes_sent - mlt->prev->total_bytes_sent > 0)
 557          mlt->total_throughput_send = mult * (mlt->total_bytes_sent - mlt->prev->total_bytes_sent);
 558        else
 559          mlt->total_throughput_send = prev_log_mlt->total_throughput_send; /* no msgs send */
 560
 561        if (mlt->total_bytes_received - mlt->prev->total_bytes_received > 0)
 562          mlt->total_throughput_recv = mult * (mlt->total_bytes_received - mlt->prev->total_bytes_received);
 563        else
 564          mlt->total_throughput_recv = prev_log_mlt->total_throughput_recv; /* no msgs received */
 565      }
 566      else
 567      {
 568        mlt->total_throughput_send = mult * mlt->total_bytes_sent;
 569        mlt->total_throughput_send = mult * mlt->total_bytes_received;
 570      }
 571
 572     mlt->slaves_log = GNUNET_malloc (bp->peer->num_partners *
 573         sizeof (struct PartnerLoggingTimestep));
 574
 575     for (c_s = 0; c_s < bp->peer->num_partners; c_s++)
 576     {
 577       p = &bp->peer->partners[c_s];
 578       slt = &mlt->slaves_log[c_s];
 579
 580       slt->slave = p->dest;
 581       /* Bytes sent from master to this slave */
 582       slt->total_bytes_sent = p->bytes_sent;
 583       /* Messages sent from master to this slave */
 584       slt->total_messages_sent = p->messages_sent;
 585       /* Bytes master received from this slave */
 586       slt->total_bytes_received = p->bytes_received;
 587       /* Messages master received from this slave */
 588       slt->total_messages_received = p->messages_received;
 589       slt->total_app_rtt = p->total_app_rtt;
 590       /* ats performance information */
 591       slt->ats_cost_lan = p->ats_cost_lan;
 592       slt->ats_cost_wan = p->ats_cost_wan;
 593       slt->ats_cost_wlan = p->ats_cost_wlan;
 594       slt->ats_delay = p->ats_delay;
 595       slt->ats_distance = p->ats_distance;
 596       slt->ats_network_type = p->ats_network_type;
 597       slt->ats_utilization_down = p->ats_utilization_down;
 598       slt->ats_utilization_up = p->ats_utilization_up;
 599       slt->bandwidth_in = p->bandwidth_in;
 600       slt->bandwidth_out = p->bandwidth_out;
 601
 602       /* Total application level rtt  */
 603       if (NULL == prev_log_mlt)
 604       {
 605         if (0 != slt->total_messages_sent)
 606           app_rtt = slt->total_app_rtt / slt->total_messages_sent;
 607         else
 608           app_rtt = 0;
 609       }
 610       else
 611       {
 612         prev_log_slt =  &prev_log_mlt->slaves_log[c_s];
 613         if ((slt->total_messages_sent - prev_log_slt->total_messages_sent) > 0)
 614           app_rtt = (slt->total_app_rtt - prev_log_slt->total_app_rtt) /
 615                   (slt->total_messages_sent - prev_log_slt->total_messages_sent);
 616         else
 617           app_rtt = prev_log_slt->app_rtt; /* No messages were */
 618       }
 619       slt->app_rtt = app_rtt;
 620
 621       /* Partner throughput */
 622       if (NULL != prev_log_mlt)
 623       {
 624         prev_log_slt =  &prev_log_mlt->slaves_log[c_s];
 625         if (slt->total_bytes_sent - prev_log_slt->total_bytes_sent > 0)
 626           slt->throughput_sent = mult * (slt->total_bytes_sent - prev_log_slt->total_bytes_sent);
 627         else
 628           slt->throughput_sent = prev_log_slt->throughput_sent; /* no msgs send */
 629
 630         if (slt->total_bytes_received - prev_log_slt->total_bytes_received > 0)
 631           slt->throughput_recv = mult * (slt->total_bytes_received - prev_log_slt->total_bytes_received);
 632         else
 633           slt->throughput_recv = prev_log_slt->throughput_recv; /* no msgs received */
 634       }
 635       else
 636       {
 637         slt->throughput_sent = mult * slt->total_bytes_sent;
 638         slt->throughput_sent = mult * slt->total_bytes_received;
 639       }
 640
 641       GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
 642           "Master [%u]: slave [%u]\n",
 643           bp->peer->no, p->dest->no);
 644     }
 645   }
 646 }
 647
 648 static void
 649 collect_log_task (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc)
 650 {
 651   struct LoggingHandle *l = cls;
 652   l->log_task = GNUNET_SCHEDULER_NO_TASK;
 653
 654   GNUNET_ATS_TEST_logging_now (l);
 655
 656   if (tc->reason == GNUNET_SCHEDULER_REASON_SHUTDOWN)
 657     return;
 658
 659   l->log_task = GNUNET_SCHEDULER_add_delayed (l->frequency,
 660       &collect_log_task, l);
 661 }
 662
 663 /**
 664  * Stop logging
 665  *
 666  * @param l the logging handle
 667  */
 668 void
 669 GNUNET_ATS_TEST_logging_stop (struct LoggingHandle *l)
 670 {
 671   struct GNUNET_SCHEDULER_TaskContext tc;
 672   if (GNUNET_YES!= l->running)
 673     return;
 674
 675   if (GNUNET_SCHEDULER_NO_TASK != l->log_task)
 676     GNUNET_SCHEDULER_cancel (l->log_task);
 677   l->log_task = GNUNET_SCHEDULER_NO_TASK;
 678   tc.reason = GNUNET_SCHEDULER_REASON_SHUTDOWN;
 679   collect_log_task (l, &tc);
 680   l->running = GNUNET_NO;
 681
 682   GNUNET_log(GNUNET_ERROR_TYPE_INFO,
 683       _("Stop logging\n"));
 684 }
 685
 686 /**
 687  * Clean up logging data
 688  *
 689  * @param l the logging handle
 690  */
 691 void
 692 GNUNET_ATS_TEST_logging_clean_up (struct LoggingHandle *l)
 693 {
 694   int c_m;
 695   struct PeerLoggingTimestep *cur;
 696
 697   if (GNUNET_YES == l->running)
 698     GNUNET_ATS_TEST_logging_stop (l);
 699
 700   for (c_m = 0; c_m < l->num_peers; c_m++)
 701   {
 702     while (NULL != (cur = l->lp[c_m].head))
 703     {
 704       GNUNET_CONTAINER_DLL_remove (l->lp[c_m].head, l->lp[c_m].tail, cur);
 705       GNUNET_free (cur->slaves_log);
 706       GNUNET_free (cur);
 707     }
 708   }
 709
 710   GNUNET_free (l->lp);
 711   GNUNET_free (l);
 712 }
 713
 714
 715 /**
 716  * Start logging
 717  *
 718  * @param log_frequency the logging frequency
 719  * @param testname the testname
 720  * @param masters the master peers used for benchmarking
 721  * @oaram num_master the number of master peers
 722  * @return the logging handle or NULL on error
 723  */
 724 struct LoggingHandle *
 725 GNUNET_ATS_TEST_logging_start (struct GNUNET_TIME_Relative log_frequency,
 726     char * testname, struct BenchmarkPeer *masters, int num_masters)
 727 {
 728   struct LoggingHandle *l;
 729   int c_m;
 730   GNUNET_log(GNUNET_ERROR_TYPE_INFO,
 731       _("Start logging `%s'\n"), testname);
 732
 733   l = GNUNET_new (struct LoggingHandle);
 734   l->num_peers = num_masters;
 735   l->name = testname;
 736   l->frequency = log_frequency;
 737   l->lp = GNUNET_malloc (num_masters * sizeof (struct LoggingPeer));
 738
 739   for (c_m = 0; c_m < num_masters; c_m ++)
 740   {
 741     l->lp[c_m].peer = &masters[c_m];
 742     l->lp[c_m].start = GNUNET_TIME_absolute_get();
 743   }
 744
 745   /* Schedule logging task */
 746   l->log_task = GNUNET_SCHEDULER_add_now (&collect_log_task, l);
 747   l->running = GNUNET_YES;
 748
 749   return l;
 750 }
 751 /* end of file ats-testing-log.c */
 752