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   double pref_bandwidth;
 145   double pref_delay;
 146 };
 147
 148
 149 /**
 150  * A single logging time step for a peer
 151  */
 152 struct PeerLoggingTimestep
 153 {
 154   /**
 155    * Next in DLL
 156    */
 157   struct PeerLoggingTimestep *next;
 158
 159   /**
 160    * Prev in DLL
 161    */
 162   struct PeerLoggingTimestep *prev;
 163
 164   /**
 165    * Logging timestamp
 166    */
 167   struct GNUNET_TIME_Absolute timestamp;
 168
 169   /**
 170    * Total number of messages this peer has sent
 171    */
 172   unsigned int total_messages_sent;
 173
 174   /**
 175    * Total number of bytes this peer has sent
 176    */
 177   unsigned int total_bytes_sent;
 178
 179   /**
 180    * Total number of messages this peer has received
 181    */
 182   unsigned int total_messages_received;
 183
 184   /**
 185    * Total number of bytes this peer has received
 186    */
 187   unsigned int total_bytes_received;
 188
 189   /**
 190    * Total outbound throughput for master in Bytes / s
 191    */
 192   unsigned int total_throughput_send;
 193
 194   /**
 195    * Total inbound throughput for master in Bytes / s
 196    */
 197   unsigned int total_throughput_recv;
 198
 199   /**
 200    * Logs for slaves
 201    */
 202   struct PartnerLoggingTimestep *slaves_log;
 203 };
 204
 205 /**
 206  * Entry for a benchmark peer
 207  */
 208 struct LoggingPeer
 209 {
 210   /**
 211    * Peer
 212    */
 213   struct BenchmarkPeer *peer;
 214
 215   /**
 216    * Start time
 217    */
 218   struct GNUNET_TIME_Absolute start;
 219
 220   /**
 221    * DLL for logging entries: head
 222    */
 223   struct PeerLoggingTimestep *head;
 224
 225   /**
 226    * DLL for logging entries: tail
 227    */
 228   struct PeerLoggingTimestep *tail;
 229 };
 230
 231 struct LoggingHandle
 232 {
 233   /**
 234    * Logging task
 235    */
 236   GNUNET_SCHEDULER_TaskIdentifier log_task;
 237
 238   /**
 239    * Reference to perf_ats' masters
 240    */
 241   int num_masters;
 242   int num_slaves;
 243   int running;
 244   int verbose;
 245   char *name;
 246   struct GNUNET_TIME_Relative frequency;
 247
 248   /**
 249    * Log structure of length num_peers
 250    */
 251   struct LoggingPeer *lp;
 252 };
 253
 254
 255
 256 static void
 257 write_throughput_gnuplot_script (char * fn, struct LoggingPeer *lp, char **fs, int slaves)
 258 {
 259   struct GNUNET_DISK_FileHandle *f;
 260   char * gfn;
 261   char *data;
 262   int c_s;
 263
 264   GNUNET_asprintf (&gfn, "gnuplot_throughput_%s",fn);
 265   fprintf (stderr, "Writing throughput plot for master %u and %u slaves to `%s'\n",
 266       lp->peer->no, slaves, gfn);
 267
 268   f = GNUNET_DISK_file_open (gfn,
 269       GNUNET_DISK_OPEN_WRITE | GNUNET_DISK_OPEN_CREATE,
 270       GNUNET_DISK_PERM_USER_EXEC | GNUNET_DISK_PERM_USER_READ |
 271       GNUNET_DISK_PERM_USER_WRITE);
 272   if (NULL == f)
 273   {
 274     GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot open gnuplot file `%s'\n", gfn);
 275     GNUNET_free (gfn);
 276     return;
 277   }
 278
 279   /* Write header */
 280   if (GNUNET_SYSERR == GNUNET_DISK_file_write(f, THROUGHPUT_TEMPLATE,
 281       strlen(THROUGHPUT_TEMPLATE)))
 282     GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
 283         "Cannot write data to plot file `%s'\n", gfn);
 284
 285   /* Write master data */
 286   GNUNET_asprintf (&data,
 287       "plot '%s' using 2:%u with lines title 'Master %u send total', \\\n" \
 288       "'%s' using 2:%u with lines title 'Master %u receive total', \\\n",
 289       fn, LOG_ITEMS_TIME + LOG_ITEM_THROUGHPUT_SENT, lp->peer->no,
 290       fn, LOG_ITEMS_TIME + LOG_ITEM_THROUGHPUT_RECV, lp->peer->no);
 291   if (GNUNET_SYSERR == GNUNET_DISK_file_write(f, data, strlen(data)))
 292     GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot write data to plot file `%s'\n", gfn);
 293   GNUNET_free (data);
 294
 295   for (c_s = 0; c_s < slaves; c_s++)
 296   {
 297     GNUNET_asprintf (&data, "'%s' using 2:%u with lines title 'Master %u - Slave %u send', \\\n" \
 298         "'%s' using 2:%u with lines title 'Master %u - Slave %u receive'%s\n",
 299         fs[c_s],
 300         LOG_ITEMS_TIME + LOG_ITEM_THROUGHPUT_SENT,
 301         lp->peer->no,
 302         lp->peer->partners[c_s].dest->no,
 303         fs[c_s],
 304         LOG_ITEMS_TIME + LOG_ITEM_THROUGHPUT_RECV,
 305         lp->peer->no,
 306         lp->peer->partners[c_s].dest->no,
 307         (c_s < lp->peer->num_partners -1) ? ", \\" : "\n pause -1");
 308     if (GNUNET_SYSERR == GNUNET_DISK_file_write(f, data, strlen(data)))
 309         GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot write data to plot file `%s'\n", gfn);
 310     GNUNET_free (data);
 311   }
 312
 313   if (GNUNET_SYSERR == GNUNET_DISK_file_close(f))
 314     GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
 315         "Cannot close gnuplot file `%s'\n", gfn);
 316   else
 317     GNUNET_log (GNUNET_ERROR_TYPE_INFO,
 318         "Data successfully written to plot file `%s'\n", gfn);
 319   GNUNET_free (gfn);
 320 }
 321
 322
 323 static void
 324 write_rtt_gnuplot_script (char * fn, struct LoggingPeer *lp, char **fs, int slaves)
 325 {
 326   struct GNUNET_DISK_FileHandle *f;
 327   char * gfn;
 328   char *data;
 329   int c_s;
 330
 331   GNUNET_asprintf (&gfn, "gnuplot_rtt_%s",fn);
 332   fprintf (stderr, "Writing rtt plot for master %u to `%s'\n",
 333       lp->peer->no, gfn);
 334
 335   f = GNUNET_DISK_file_open (gfn,
 336       GNUNET_DISK_OPEN_WRITE | GNUNET_DISK_OPEN_CREATE,
 337       GNUNET_DISK_PERM_USER_EXEC | GNUNET_DISK_PERM_USER_READ |
 338       GNUNET_DISK_PERM_USER_WRITE);
 339   if (NULL == f)
 340   {
 341     GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot open gnuplot file `%s'\n", gfn);
 342     GNUNET_free (gfn);
 343     return;
 344   }
 345
 346   /* Write header */
 347   if (GNUNET_SYSERR == GNUNET_DISK_file_write(f, RTT_TEMPLATE, strlen(RTT_TEMPLATE)))
 348     GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot write data to plot file `%s'\n", gfn);
 349
 350   for (c_s = 0; c_s < slaves; c_s++)
 351   {
 352     GNUNET_asprintf (&data, "%s'%s' using 2:%u with lines title 'Master %u - Slave %u '%s\n",
 353         (0 == c_s) ? "plot " :"",
 354         fs[c_s],
 355         LOG_ITEMS_TIME + LOG_ITEM_APP_RTT,
 356         lp->peer->no,
 357         lp->peer->partners[c_s].dest->no,
 358         (c_s < lp->peer->num_partners -1) ? ", \\" : "\n pause -1");
 359     if (GNUNET_SYSERR == GNUNET_DISK_file_write(f, data, strlen(data)))
 360         GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot write data to plot file `%s'\n", gfn);
 361     GNUNET_free (data);
 362   }
 363
 364   if (GNUNET_SYSERR == GNUNET_DISK_file_close(f))
 365     GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot close gnuplot file `%s'\n", gfn);
 366   else
 367     GNUNET_log (GNUNET_ERROR_TYPE_INFO, "Data successfully written to plot file `%s'\n", gfn);
 368   GNUNET_free (gfn);
 369 }
 370
 371 static void
 372 write_bw_gnuplot_script (char * fn, struct LoggingPeer *lp, char **fs, int slaves)
 373 {
 374   struct GNUNET_DISK_FileHandle *f;
 375   char * gfn;
 376   char *data;
 377   int c_s;
 378
 379   GNUNET_asprintf (&gfn, "gnuplot_bw_%s",fn);
 380   fprintf (stderr, "Writing bandwidth plot for master %u to `%s'\n",
 381       lp->peer->no, gfn);
 382
 383   f = GNUNET_DISK_file_open (gfn,
 384       GNUNET_DISK_OPEN_WRITE | GNUNET_DISK_OPEN_CREATE,
 385       GNUNET_DISK_PERM_USER_EXEC | GNUNET_DISK_PERM_USER_READ |
 386       GNUNET_DISK_PERM_USER_WRITE);
 387   if (NULL == f)
 388   {
 389     GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot open gnuplot file `%s'\n", gfn);
 390     GNUNET_free (gfn);
 391     return;
 392   }
 393
 394   /* Write header */
 395   if (GNUNET_SYSERR == GNUNET_DISK_file_write(f, BW_TEMPLATE, strlen(BW_TEMPLATE)))
 396     GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
 397         "Cannot write data to plot file `%s'\n", gfn);
 398
 399   for (c_s = 0; c_s < slaves; c_s++)
 400   {
 401     GNUNET_asprintf (&data, "%s"\
 402         "'%s' using 2:%u with lines title 'BW out master %u - Slave %u ', \\\n" \
 403         "'%s' using 2:%u with lines title 'BW in master %u - Slave %u '"\
 404         "%s\n",
 405         (0 == c_s) ? "plot " :"",
 406         fs[c_s],
 407         LOG_ITEMS_TIME + LOG_ITEM_ATS_BW_OUT,
 408         lp->peer->no, c_s,
 409         fs[c_s],
 410         LOG_ITEMS_TIME + LOG_ITEM_ATS_BW_IN,
 411         lp->peer->no, c_s,
 412         (c_s < lp->peer->num_partners -1) ? ", \\" : "\n pause -1");
 413     if (GNUNET_SYSERR == GNUNET_DISK_file_write(f, data, strlen(data)))
 414         GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot write data to plot file `%s'\n", gfn);
 415     GNUNET_free (data);
 416   }
 417
 418   if (GNUNET_SYSERR == GNUNET_DISK_file_close(f))
 419     GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot close gnuplot file `%s'\n", gfn);
 420   else
 421     GNUNET_log (GNUNET_ERROR_TYPE_INFO, "Data successfully written to plot file `%s'\n", gfn);
 422   GNUNET_free (gfn);
 423 }
 424
 425
 426 void
 427 GNUNET_ATS_TEST_logging_write_to_file (struct LoggingHandle *l,
 428     char *experiment_name, int plots)
 429 {
 430   struct GNUNET_DISK_FileHandle *f[l->num_slaves];
 431   struct GNUNET_DISK_FileHandle *f_m;
 432   char *tmp_exp_name;
 433   char *filename_master;
 434   char *filename_slaves[l->num_slaves];
 435   char *data;
 436   struct PeerLoggingTimestep *cur_lt;
 437   struct PartnerLoggingTimestep *plt;
 438   struct GNUNET_TIME_Absolute timestamp;
 439   int c_m;
 440   int c_s;
 441
 442
 443   timestamp = GNUNET_TIME_absolute_get();
 444
 445   tmp_exp_name = experiment_name;
 446   for (c_m = 0; c_m < l->num_masters; c_m++)
 447   {
 448     GNUNET_asprintf (&filename_master, "%s_%llu_master%u_%s",
 449         experiment_name, timestamp.abs_value_us, c_m, l->name);
 450     fprintf (stderr, "Writing data for master %u to file `%s'\n",
 451         c_m,filename_master);
 452
 453     f_m = GNUNET_DISK_file_open (filename_master,
 454         GNUNET_DISK_OPEN_WRITE | GNUNET_DISK_OPEN_CREATE,
 455         GNUNET_DISK_PERM_USER_READ | GNUNET_DISK_PERM_USER_WRITE);
 456     if (NULL == f_m)
 457     {
 458       GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot open log file `%s'\n", filename_master);
 459       GNUNET_free (filename_master);
 460       return;
 461     }
 462
 463     GNUNET_asprintf (&data, "# master %u; experiment : %s\n"
 464         "timestamp; timestamp delta; #messages sent; #bytes sent; #throughput sent; #messages received; #bytes received; #throughput received; \n" ,
 465         c_m,  experiment_name);
 466     if (GNUNET_SYSERR == GNUNET_DISK_file_write(f_m, data, strlen(data)))
 467       GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
 468           "Cannot write data to log file `%s'\n",filename_master);
 469     GNUNET_free (data);
 470
 471     for (c_s = 0; c_s < l->lp[c_m].peer->num_partners; c_s++)
 472     {
 473       GNUNET_asprintf (&filename_slaves[c_s], "%s_%llu_master%u_slave_%u_%s",
 474           tmp_exp_name, timestamp.abs_value_us, c_m, c_s, l->name);
 475
 476       fprintf (stderr, "Writing data for master %u slave %u to file `%s'\n",
 477           c_m, c_s, filename_slaves[c_s]);
 478
 479       f[c_s] = GNUNET_DISK_file_open (filename_slaves[c_s],
 480           GNUNET_DISK_OPEN_WRITE | GNUNET_DISK_OPEN_CREATE,
 481           GNUNET_DISK_PERM_USER_READ | GNUNET_DISK_PERM_USER_WRITE);
 482       if (NULL == f[c_s])
 483       {
 484         GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot open log file `%s'\n", filename_slaves[c_s]);
 485         GNUNET_free (filename_slaves[c_s]);
 486         GNUNET_break (GNUNET_OK == GNUNET_DISK_file_close(f_m));
 487         return;
 488       }
 489
 490       /* Header */
 491       GNUNET_asprintf (&data, "# master %u; slave %u ; experiment : %s\n"
 492           "timestamp; timestamp delta; #messages sent; #bytes sent; #throughput sent; #messages received; #bytes received; #throughput received; " \
 493           "rtt; bw in; bw out; ats_cost_lan; ats_cost_wlan; ats_delay; ats_distance; ats_network_type; ats_utilization_up ;ats_utilization_down;" \
 494           "pref bandwidth; pref delay\n",
 495           c_m, c_s, experiment_name);
 496       if (GNUNET_SYSERR == GNUNET_DISK_file_write(f[c_s], data, strlen(data)))
 497         GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
 498             "Cannot write data to log file `%s'\n",filename_slaves[c_s]);
 499       GNUNET_free (data);
 500     }
 501
 502     for (cur_lt = l->lp[c_m].head; NULL != cur_lt; cur_lt = cur_lt->next)
 503     {
 504       if (l->verbose)
 505         fprintf (stderr,
 506            "Master [%u]: timestamp %llu %llu ; %u %u %u ; %u %u %u\n",
 507            l->lp[c_m].peer->no,
 508            (long long unsigned int) cur_lt->timestamp.abs_value_us,
 509            (long long unsigned int) GNUNET_TIME_absolute_get_difference(l->lp[c_m].start,
 510                cur_lt->timestamp).rel_value_us / 1000,
 511            cur_lt->total_messages_sent,
 512            cur_lt->total_bytes_sent,
 513            cur_lt->total_throughput_send,
 514            cur_lt->total_messages_received,
 515            cur_lt->total_bytes_received,
 516            cur_lt->total_throughput_recv);
 517
 518       /* Assembling master string */
 519       GNUNET_asprintf (&data, "%llu;%llu;%u;%u;%u;%u;%u;%u;\n",
 520           (long long unsigned int) cur_lt->timestamp.abs_value_us,
 521           (long long unsigned int) GNUNET_TIME_absolute_get_difference(l->lp[c_m].start,
 522               cur_lt->timestamp).rel_value_us / 1000,
 523           cur_lt->total_messages_sent,
 524           cur_lt->total_bytes_sent,
 525           cur_lt->total_throughput_send,
 526           cur_lt->total_messages_received,
 527           cur_lt->total_bytes_received,
 528           cur_lt->total_throughput_recv);
 529
 530       if (GNUNET_SYSERR == GNUNET_DISK_file_write(f_m, data, strlen(data)))
 531         GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
 532             "Cannot write data to master file %u\n", c_m);
 533       GNUNET_free (data);
 534
 535
 536       for (c_s = 0; c_s < l->lp[c_m].peer->num_partners; c_s++)
 537       {
 538         plt = &cur_lt->slaves_log[c_s];
 539         /* Log partners */
 540
 541         /* Assembling slave string */
 542         GNUNET_asprintf(&data,
 543             "%llu;%llu;%u;%u;%u;%u;%u;%u;%.3f;%u;%u;%u;%u;%u;%u;%u;%u;%u;%u;%.3f;%.3f\n",
 544             (long long unsigned int) cur_lt->timestamp.abs_value_us,
 545             (long long unsigned int) GNUNET_TIME_absolute_get_difference(l->lp[c_m].start,
 546                 cur_lt->timestamp).rel_value_us / 1000,
 547             plt->total_messages_sent,
 548             plt->total_bytes_sent,
 549             plt->throughput_sent,
 550             plt->total_messages_received,
 551             plt->total_bytes_received,
 552             plt->throughput_recv,
 553             (double) plt->app_rtt / 1000,
 554             plt->bandwidth_in,
 555             plt->bandwidth_out,
 556             plt->ats_cost_lan,
 557             plt->ats_cost_wan,
 558             plt->ats_cost_wlan,
 559             plt->ats_delay,
 560             plt->ats_distance,
 561             plt->ats_network_type,
 562             plt->ats_utilization_up,
 563             plt->ats_utilization_down,
 564             plt->pref_bandwidth,
 565             plt->pref_delay);
 566
 567         if (l->verbose)
 568           fprintf (stderr,
 569               "\t Slave [%u]: %u %u %u ; %u %u %u rtt %u delay %u bw_in %u bw_out %u \n",
 570               plt->slave->no,
 571               plt->total_messages_sent,
 572               plt->total_bytes_sent,
 573               plt->throughput_sent,
 574               plt->total_messages_received,
 575               plt->total_bytes_received,
 576               plt->throughput_recv,
 577               plt->app_rtt,
 578               plt->ats_delay,
 579               plt->bandwidth_in,
 580               plt->bandwidth_out);
 581
 582         if (GNUNET_SYSERR == GNUNET_DISK_file_write(f[c_s], data, strlen(data)))
 583           GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
 584               "Cannot write data to log file `%s'\n", filename_slaves[c_s]);
 585         GNUNET_free (data);
 586
 587       }
 588     }
 589
 590     for (c_s = 0; c_s < l->lp[c_m].peer->num_partners; c_s++)
 591     {
 592       if (GNUNET_SYSERR == GNUNET_DISK_file_close(f[c_s]))
 593       {
 594         GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
 595             "Cannot close log file for master[%u] slave[%u]\n", c_m, c_s);
 596         continue;
 597       }
 598       GNUNET_log (GNUNET_ERROR_TYPE_INFO,
 599           "Data file successfully written to log file for `%s'\n",
 600           filename_slaves[c_s]);
 601     }
 602
 603     if (GNUNET_SYSERR == GNUNET_DISK_file_close(f_m))
 604     {
 605       GNUNET_log_strerror_file (GNUNET_ERROR_TYPE_ERROR,
 606                                 "close",
 607                                 filename_master);
 608       GNUNET_free (filename_master);
 609       return;
 610     }
 611     GNUNET_log (GNUNET_ERROR_TYPE_INFO,
 612         "Data file successfully written to log file for master `%s'\n", filename_master);
 613
 614     if (GNUNET_YES == plots)
 615     {
 616       write_throughput_gnuplot_script (filename_master, &l->lp[c_m], filename_slaves, l->num_slaves);
 617       write_rtt_gnuplot_script (filename_master, &l->lp[c_m], filename_slaves, l->num_slaves);
 618       write_bw_gnuplot_script (filename_master, &l->lp[c_m], filename_slaves, l->num_slaves);
 619     }
 620   }
 621   GNUNET_free (filename_master);
 622 }
 623
 624 /**
 625  * Log all data now
 626  *
 627  * @param l logging handle to use
 628  */
 629 void
 630 GNUNET_ATS_TEST_logging_now (struct LoggingHandle *l)
 631 {
 632   struct LoggingPeer *bp;
 633   struct PeerLoggingTimestep *mlt;
 634   struct PeerLoggingTimestep *prev_log_mlt;
 635   struct PartnerLoggingTimestep *slt;
 636   struct PartnerLoggingTimestep *prev_log_slt;
 637   struct BenchmarkPartner *p;
 638   struct GNUNET_TIME_Relative delta;
 639   int c_s;
 640   int c_m;
 641   unsigned int app_rtt;
 642   double mult;
 643
 644   if (GNUNET_YES != l->running)
 645     return;
 646
 647   for (c_m = 0; c_m < l->num_masters; c_m++)
 648   {
 649     bp = &l->lp[c_m];
 650     mlt = GNUNET_new (struct PeerLoggingTimestep);
 651     GNUNET_CONTAINER_DLL_insert_tail(l->lp[c_m].head, l->lp[c_m].tail, mlt);
 652     prev_log_mlt = mlt->prev;
 653
 654     /* Collect data */
 655     /* Current master state */
 656     mlt->timestamp = GNUNET_TIME_absolute_get();
 657     mlt->total_bytes_sent = bp->peer->total_bytes_sent;
 658     mlt->total_messages_sent = bp->peer->total_messages_sent;
 659     mlt->total_bytes_received = bp->peer->total_bytes_received;
 660     mlt->total_messages_received = bp->peer->total_messages_received;
 661
 662     /* Throughput */
 663     if (NULL == prev_log_mlt)
 664      {
 665        /* Get difference to start */
 666        delta = GNUNET_TIME_absolute_get_difference (l->lp[c_m].start, mlt->timestamp);
 667      }
 668      else
 669      {
 670        /* Get difference to last timestep */
 671        delta = GNUNET_TIME_absolute_get_difference (mlt->prev->timestamp, mlt->timestamp);
 672      }
 673
 674      /* Multiplication factor for throughput calculation */
 675      mult = (double) GNUNET_TIME_UNIT_SECONDS.rel_value_us / (delta.rel_value_us);
 676
 677      /* Total throughput */
 678      if (NULL != prev_log_mlt)
 679      {
 680        if (mlt->total_bytes_sent - mlt->prev->total_bytes_sent > 0)
 681        {
 682          mlt->total_throughput_send = mult * (mlt->total_bytes_sent - mlt->prev->total_bytes_sent);
 683        }
 684        else
 685        {
 686          mlt->total_throughput_send = 0;
 687         // mlt->total_throughput_send = prev_log_mlt->total_throughput_send; /* no msgs send */
 688        }
 689
 690        if (mlt->total_bytes_received - mlt->prev->total_bytes_received > 0)
 691        {
 692          mlt->total_throughput_recv = mult * (mlt->total_bytes_received - mlt->prev->total_bytes_received);
 693        }
 694        else
 695        {
 696          mlt->total_throughput_send = 0;
 697          //mlt->total_throughput_recv = prev_log_mlt->total_throughput_recv; /* no msgs received */
 698        }
 699      }
 700      else
 701      {
 702        mlt->total_throughput_send = mult * mlt->total_bytes_sent;
 703        mlt->total_throughput_send = mult * mlt->total_bytes_received;
 704      }
 705
 706     if (GNUNET_YES == l->verbose)
 707     {
 708       GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
 709           "Master[%u] delta: %llu us, bytes (sent/received): %u / %u; throughput send/recv: %u / %u\n", c_m,
 710           delta.rel_value_us,
 711           mlt->total_bytes_sent,
 712           mlt->total_bytes_received,
 713           mlt->total_throughput_send,
 714           mlt->total_throughput_recv);
 715     }
 716
 717     mlt->slaves_log = GNUNET_malloc (bp->peer->num_partners *
 718         sizeof (struct PartnerLoggingTimestep));
 719
 720     for (c_s = 0; c_s < bp->peer->num_partners; c_s++)
 721     {
 722       GNUNET_log (GNUNET_ERROR_TYPE_INFO,
 723           "Collect logging data master[%u] slave [%u]\n", c_m, c_s);
 724
 725       p = &bp->peer->partners[c_s];
 726       slt = &mlt->slaves_log[c_s];
 727
 728       slt->slave = p->dest;
 729       /* Bytes sent from master to this slave */
 730       slt->total_bytes_sent = p->bytes_sent;
 731       /* Messages sent from master to this slave */
 732       slt->total_messages_sent = p->messages_sent;
 733       /* Bytes master received from this slave */
 734       slt->total_bytes_received = p->bytes_received;
 735       /* Messages master received from this slave */
 736       slt->total_messages_received = p->messages_received;
 737       slt->total_app_rtt = p->total_app_rtt;
 738       /* ats performance information */
 739       slt->ats_cost_lan = p->ats_cost_lan;
 740       slt->ats_cost_wan = p->ats_cost_wan;
 741       slt->ats_cost_wlan = p->ats_cost_wlan;
 742       slt->ats_delay = p->ats_delay;
 743       slt->ats_distance = p->ats_distance;
 744       slt->ats_network_type = p->ats_network_type;
 745       slt->ats_utilization_down = p->ats_utilization_down;
 746       slt->ats_utilization_up = p->ats_utilization_up;
 747       slt->bandwidth_in = p->bandwidth_in;
 748       slt->bandwidth_out = p->bandwidth_out;
 749       slt->pref_bandwidth = p->pref_bandwidth;
 750       slt->pref_delay = p->pref_delay;
 751
 752       /* Total application level rtt  */
 753       if (NULL == prev_log_mlt)
 754       {
 755         if (0 != slt->total_messages_sent)
 756           app_rtt = slt->total_app_rtt / slt->total_messages_sent;
 757         else
 758           app_rtt = 0;
 759       }
 760       else
 761       {
 762         prev_log_slt =  &prev_log_mlt->slaves_log[c_s];
 763         if ((slt->total_messages_sent - prev_log_slt->total_messages_sent) > 0)
 764           app_rtt = (slt->total_app_rtt - prev_log_slt->total_app_rtt) /
 765                   (slt->total_messages_sent - prev_log_slt->total_messages_sent);
 766         else
 767         {
 768           app_rtt = prev_log_slt->app_rtt; /* No messages were */
 769         }
 770       }
 771       slt->app_rtt = app_rtt;
 772
 773       /* Partner throughput */
 774       if (NULL != prev_log_mlt)
 775       {
 776         prev_log_slt =  &prev_log_mlt->slaves_log[c_s];
 777         if (slt->total_bytes_sent > prev_log_slt->total_bytes_sent)
 778           slt->throughput_sent = mult * (slt->total_bytes_sent - prev_log_slt->total_bytes_sent);
 779         else
 780           slt->throughput_sent = 0;
 781
 782         if (slt->total_bytes_received > prev_log_slt->total_bytes_received)
 783           slt->throughput_recv = mult *
 784               (slt->total_bytes_received - prev_log_slt->total_bytes_received);
 785         else
 786           slt->throughput_recv = 0;
 787       }
 788       else
 789       {
 790         slt->throughput_sent = mult * slt->total_bytes_sent;
 791         slt->throughput_recv = mult * slt->total_bytes_received;
 792       }
 793
 794       if (GNUNET_YES == l->verbose)
 795       {
 796         GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
 797             "Master [%u] -> Slave [%u]: delta: %llu us, bytes (sent/received): %u / %u; throughput send/recv: %u / %u\n",
 798             c_m, c_s,
 799             delta.rel_value_us,
 800             mlt->total_bytes_sent,
 801             mlt->total_bytes_received,
 802             slt->throughput_sent,
 803             slt->throughput_recv);
 804       }
 805       else
 806         GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
 807           "Master [%u]: slave [%u]\n",
 808           bp->peer->no, p->dest->no);
 809     }
 810   }
 811 }
 812
 813 static void
 814 collect_log_task (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc)
 815 {
 816   struct LoggingHandle *l = cls;
 817   l->log_task = GNUNET_SCHEDULER_NO_TASK;
 818
 819   GNUNET_ATS_TEST_logging_now (l);
 820
 821   if (tc->reason == GNUNET_SCHEDULER_REASON_SHUTDOWN)
 822     return;
 823
 824   l->log_task = GNUNET_SCHEDULER_add_delayed (l->frequency,
 825       &collect_log_task, l);
 826 }
 827
 828 /**
 829  * Stop logging
 830  *
 831  * @param l the logging handle
 832  */
 833 void
 834 GNUNET_ATS_TEST_logging_stop (struct LoggingHandle *l)
 835 {
 836   if (GNUNET_YES!= l->running)
 837     return;
 838
 839   if (GNUNET_SCHEDULER_NO_TASK != l->log_task)
 840     GNUNET_SCHEDULER_cancel (l->log_task);
 841   l->log_task = GNUNET_SCHEDULER_NO_TASK;
 842   l->running = GNUNET_NO;
 843
 844   GNUNET_log(GNUNET_ERROR_TYPE_INFO,
 845       _("Stop logging\n"));
 846 }
 847
 848 /**
 849  * Clean up logging data
 850  *
 851  * @param l the logging handle
 852  */
 853 void
 854 GNUNET_ATS_TEST_logging_clean_up (struct LoggingHandle *l)
 855 {
 856   int c_m;
 857   struct PeerLoggingTimestep *cur;
 858
 859   if (GNUNET_YES == l->running)
 860     GNUNET_ATS_TEST_logging_stop (l);
 861
 862   for (c_m = 0; c_m < l->num_masters; c_m++)
 863   {
 864     while (NULL != (cur = l->lp[c_m].head))
 865     {
 866       GNUNET_CONTAINER_DLL_remove (l->lp[c_m].head, l->lp[c_m].tail, cur);
 867       GNUNET_free (cur->slaves_log);
 868       GNUNET_free (cur);
 869     }
 870   }
 871
 872   GNUNET_free (l->lp);
 873   GNUNET_free (l);
 874 }
 875
 876
 877 /**
 878  * Start logging
 879  *
 880  * @param log_frequency the logging frequency
 881  * @param testname the testname
 882  * @param masters the master peers used for benchmarking
 883  * @param num_masters the number of master peers
 884  * @param num_slaves the number of slave peers
 885  * @param verbose verbose logging
 886  * @return the logging handle or NULL on error
 887  */
 888 struct LoggingHandle *
 889 GNUNET_ATS_TEST_logging_start(struct GNUNET_TIME_Relative log_frequency,
 890     char *testname, struct BenchmarkPeer *masters, int num_masters, int num_slaves,
 891     int verbose)
 892 {
 893   struct LoggingHandle *l;
 894   int c_m;
 895   GNUNET_log(GNUNET_ERROR_TYPE_INFO,
 896       _("Start logging `%s'\n"), testname);
 897
 898   l = GNUNET_new (struct LoggingHandle);
 899   l->num_masters = num_masters;
 900   l->num_slaves = num_slaves;
 901   l->name = testname;
 902   l->frequency = log_frequency;
 903   l->verbose = verbose;
 904   l->lp = GNUNET_malloc (num_masters * sizeof (struct LoggingPeer));
 905
 906   for (c_m = 0; c_m < num_masters; c_m ++)
 907   {
 908     l->lp[c_m].peer = &masters[c_m];
 909     l->lp[c_m].start = GNUNET_TIME_absolute_get();
 910   }
 911
 912   /* Schedule logging task */
 913   l->log_task = GNUNET_SCHEDULER_add_now (&collect_log_task, l);
 914   l->running = GNUNET_YES;
 915
 916   return l;
 917 }
 918 /* end of file ats-testing-log.c */
 919