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         return;
 487       }
 488
 489       /* Header */
 490       GNUNET_asprintf (&data, "# master %u; slave %u ; experiment : %s\n"
 491           "timestamp; timestamp delta; #messages sent; #bytes sent; #throughput sent; #messages received; #bytes received; #throughput received; " \
 492           "rtt; bw in; bw out; ats_cost_lan; ats_cost_wlan; ats_delay; ats_distance; ats_network_type; ats_utilization_up ;ats_utilization_down;" \
 493           "pref bandwidth; pref delay\n",
 494           c_m, c_s, experiment_name);
 495       if (GNUNET_SYSERR == GNUNET_DISK_file_write(f[c_s], data, strlen(data)))
 496         GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
 497             "Cannot write data to log file `%s'\n",filename_slaves[c_s]);
 498       GNUNET_free (data);
 499     }
 500
 501     for (cur_lt = l->lp[c_m].head; NULL != cur_lt; cur_lt = cur_lt->next)
 502     {
 503       if (l->verbose)
 504         fprintf (stderr,
 505            "Master [%u]: timestamp %llu %llu ; %u %u %u ; %u %u %u\n",
 506            l->lp[c_m].peer->no,
 507            (long long unsigned int) cur_lt->timestamp.abs_value_us,
 508            (long long unsigned int) GNUNET_TIME_absolute_get_difference(l->lp[c_m].start,
 509                cur_lt->timestamp).rel_value_us / 1000,
 510            cur_lt->total_messages_sent,
 511            cur_lt->total_bytes_sent,
 512            cur_lt->total_throughput_send,
 513            cur_lt->total_messages_received,
 514            cur_lt->total_bytes_received,
 515            cur_lt->total_throughput_recv);
 516
 517       /* Assembling master string */
 518       GNUNET_asprintf (&data, "%llu;%llu;%u;%u;%u;%u;%u;%u;\n",
 519           (long long unsigned int) cur_lt->timestamp.abs_value_us,
 520           (long long unsigned int) GNUNET_TIME_absolute_get_difference(l->lp[c_m].start,
 521               cur_lt->timestamp).rel_value_us / 1000,
 522           cur_lt->total_messages_sent,
 523           cur_lt->total_bytes_sent,
 524           cur_lt->total_throughput_send,
 525           cur_lt->total_messages_received,
 526           cur_lt->total_bytes_received,
 527           cur_lt->total_throughput_recv);
 528
 529       if (GNUNET_SYSERR == GNUNET_DISK_file_write(f_m, data, strlen(data)))
 530         GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
 531             "Cannot write data to master file %u\n", c_m);
 532       GNUNET_free (data);
 533
 534
 535       for (c_s = 0; c_s < l->lp[c_m].peer->num_partners; c_s++)
 536       {
 537         plt = &cur_lt->slaves_log[c_s];
 538         /* Log partners */
 539
 540         /* Assembling slave string */
 541         GNUNET_asprintf(&data,
 542             "%llu;%llu;%u;%u;%u;%u;%u;%u;%.3f;%u;%u;%u;%u;%u;%u;%u;%u;%u;%u;%.3f;%.3f\n",
 543             (long long unsigned int) cur_lt->timestamp.abs_value_us,
 544             (long long unsigned int) GNUNET_TIME_absolute_get_difference(l->lp[c_m].start,
 545                 cur_lt->timestamp).rel_value_us / 1000,
 546             plt->total_messages_sent,
 547             plt->total_bytes_sent,
 548             plt->throughput_sent,
 549             plt->total_messages_received,
 550             plt->total_bytes_received,
 551             plt->throughput_recv,
 552             (double) plt->app_rtt / 1000,
 553             plt->bandwidth_in,
 554             plt->bandwidth_out,
 555             plt->ats_cost_lan,
 556             plt->ats_cost_wan,
 557             plt->ats_cost_wlan,
 558             plt->ats_delay,
 559             plt->ats_distance,
 560             plt->ats_network_type,
 561             plt->ats_utilization_up,
 562             plt->ats_utilization_down,
 563             plt->pref_bandwidth,
 564             plt->pref_delay);
 565
 566         if (l->verbose)
 567           fprintf (stderr,
 568               "\t Slave [%u]: %u %u %u ; %u %u %u rtt %u delay %u bw_in %u bw_out %u \n",
 569               plt->slave->no,
 570               plt->total_messages_sent,
 571               plt->total_bytes_sent,
 572               plt->throughput_sent,
 573               plt->total_messages_received,
 574               plt->total_bytes_received,
 575               plt->throughput_recv,
 576               plt->app_rtt,
 577               plt->ats_delay,
 578               plt->bandwidth_in,
 579               plt->bandwidth_out);
 580
 581         if (GNUNET_SYSERR == GNUNET_DISK_file_write(f[c_s], data, strlen(data)))
 582           GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
 583               "Cannot write data to log file `%s'\n", filename_slaves[c_s]);
 584         GNUNET_free (data);
 585
 586       }
 587     }
 588
 589     for (c_s = 0; c_s < l->lp[c_m].peer->num_partners; c_s++)
 590     {
 591       if (GNUNET_SYSERR == GNUNET_DISK_file_close(f[c_s]))
 592       {
 593         GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
 594             "Cannot close log file for master[%u] slave[%u]\n", c_m, c_s);
 595         continue;
 596       }
 597       GNUNET_log (GNUNET_ERROR_TYPE_INFO,
 598           "Data file successfully written to log file for `%s'\n",
 599           filename_slaves[c_s]);
 600     }
 601
 602     if (GNUNET_SYSERR == GNUNET_DISK_file_close(f_m))
 603     {
 604       GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
 605           "Cannot close log file `%s'\n", filename_master);
 606       return;
 607     }
 608     GNUNET_log (GNUNET_ERROR_TYPE_INFO,
 609         "Data file successfully written to log file for master `%s'\n", filename_master);
 610
 611     if (GNUNET_YES == plots)
 612     {
 613       write_throughput_gnuplot_script (filename_master, &l->lp[c_m], filename_slaves, l->num_slaves);
 614       write_rtt_gnuplot_script (filename_master, &l->lp[c_m], filename_slaves, l->num_slaves);
 615       write_bw_gnuplot_script (filename_master, &l->lp[c_m], filename_slaves, l->num_slaves);
 616     }
 617   }
 618   GNUNET_free (filename_master);
 619 }
 620
 621 /**
 622  * Log all data now
 623  *
 624  * @param l logging handle to use
 625  */
 626 void
 627 GNUNET_ATS_TEST_logging_now (struct LoggingHandle *l)
 628 {
 629   struct LoggingPeer *bp;
 630   struct PeerLoggingTimestep *mlt;
 631   struct PeerLoggingTimestep *prev_log_mlt;
 632   struct PartnerLoggingTimestep *slt;
 633   struct PartnerLoggingTimestep *prev_log_slt;
 634   struct BenchmarkPartner *p;
 635   struct GNUNET_TIME_Relative delta;
 636   int c_s;
 637   int c_m;
 638   unsigned int app_rtt;
 639   double mult;
 640
 641   if (GNUNET_YES != l->running)
 642     return;
 643
 644   for (c_m = 0; c_m < l->num_masters; c_m++)
 645   {
 646     bp = &l->lp[c_m];
 647     mlt = GNUNET_new (struct PeerLoggingTimestep);
 648     GNUNET_CONTAINER_DLL_insert_tail(l->lp[c_m].head, l->lp[c_m].tail, mlt);
 649     prev_log_mlt = mlt->prev;
 650
 651     /* Collect data */
 652     /* Current master state */
 653     mlt->timestamp = GNUNET_TIME_absolute_get();
 654     mlt->total_bytes_sent = bp->peer->total_bytes_sent;
 655     mlt->total_messages_sent = bp->peer->total_messages_sent;
 656     mlt->total_bytes_received = bp->peer->total_bytes_received;
 657     mlt->total_messages_received = bp->peer->total_messages_received;
 658
 659     /* Throughput */
 660     if (NULL == prev_log_mlt)
 661      {
 662        /* Get difference to start */
 663        delta = GNUNET_TIME_absolute_get_difference (l->lp[c_m].start, mlt->timestamp);
 664      }
 665      else
 666      {
 667        /* Get difference to last timestep */
 668        delta = GNUNET_TIME_absolute_get_difference (mlt->prev->timestamp, mlt->timestamp);
 669      }
 670
 671      /* Multiplication factor for throughput calculation */
 672      mult = (double) GNUNET_TIME_UNIT_SECONDS.rel_value_us / (delta.rel_value_us);
 673
 674      /* Total throughput */
 675      if (NULL != prev_log_mlt)
 676      {
 677        if (mlt->total_bytes_sent - mlt->prev->total_bytes_sent > 0)
 678        {
 679          mlt->total_throughput_send = mult * (mlt->total_bytes_sent - mlt->prev->total_bytes_sent);
 680        }
 681        else
 682        {
 683          mlt->total_throughput_send = 0;
 684         // mlt->total_throughput_send = prev_log_mlt->total_throughput_send; /* no msgs send */
 685        }
 686
 687        if (mlt->total_bytes_received - mlt->prev->total_bytes_received > 0)
 688        {
 689          mlt->total_throughput_recv = mult * (mlt->total_bytes_received - mlt->prev->total_bytes_received);
 690        }
 691        else
 692        {
 693          mlt->total_throughput_send = 0;
 694          //mlt->total_throughput_recv = prev_log_mlt->total_throughput_recv; /* no msgs received */
 695        }
 696      }
 697      else
 698      {
 699        mlt->total_throughput_send = mult * mlt->total_bytes_sent;
 700        mlt->total_throughput_send = mult * mlt->total_bytes_received;
 701      }
 702
 703     if (GNUNET_YES == l->verbose)
 704     {
 705       GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
 706           "Master[%u] delta: %llu us, bytes (sent/received): %u / %u; throughput send/recv: %u / %u\n", c_m,
 707           delta.rel_value_us,
 708           mlt->total_bytes_sent,
 709           mlt->total_bytes_received,
 710           mlt->total_throughput_send,
 711           mlt->total_throughput_recv);
 712     }
 713
 714     mlt->slaves_log = GNUNET_malloc (bp->peer->num_partners *
 715         sizeof (struct PartnerLoggingTimestep));
 716
 717     for (c_s = 0; c_s < bp->peer->num_partners; c_s++)
 718     {
 719       GNUNET_log (GNUNET_ERROR_TYPE_INFO,
 720           "Collect logging data master[%u] slave [%u]\n", c_m, c_s);
 721
 722       p = &bp->peer->partners[c_s];
 723       slt = &mlt->slaves_log[c_s];
 724
 725       slt->slave = p->dest;
 726       /* Bytes sent from master to this slave */
 727       slt->total_bytes_sent = p->bytes_sent;
 728       /* Messages sent from master to this slave */
 729       slt->total_messages_sent = p->messages_sent;
 730       /* Bytes master received from this slave */
 731       slt->total_bytes_received = p->bytes_received;
 732       /* Messages master received from this slave */
 733       slt->total_messages_received = p->messages_received;
 734       slt->total_app_rtt = p->total_app_rtt;
 735       /* ats performance information */
 736       slt->ats_cost_lan = p->ats_cost_lan;
 737       slt->ats_cost_wan = p->ats_cost_wan;
 738       slt->ats_cost_wlan = p->ats_cost_wlan;
 739       slt->ats_delay = p->ats_delay;
 740       slt->ats_distance = p->ats_distance;
 741       slt->ats_network_type = p->ats_network_type;
 742       slt->ats_utilization_down = p->ats_utilization_down;
 743       slt->ats_utilization_up = p->ats_utilization_up;
 744       slt->bandwidth_in = p->bandwidth_in;
 745       slt->bandwidth_out = p->bandwidth_out;
 746       slt->pref_bandwidth = p->pref_bandwidth;
 747       slt->pref_delay = p->pref_delay;
 748
 749       /* Total application level rtt  */
 750       if (NULL == prev_log_mlt)
 751       {
 752         if (0 != slt->total_messages_sent)
 753           app_rtt = slt->total_app_rtt / slt->total_messages_sent;
 754         else
 755           app_rtt = 0;
 756       }
 757       else
 758       {
 759         prev_log_slt =  &prev_log_mlt->slaves_log[c_s];
 760         if ((slt->total_messages_sent - prev_log_slt->total_messages_sent) > 0)
 761           app_rtt = (slt->total_app_rtt - prev_log_slt->total_app_rtt) /
 762                   (slt->total_messages_sent - prev_log_slt->total_messages_sent);
 763         else
 764         {
 765           app_rtt = prev_log_slt->app_rtt; /* No messages were */
 766         }
 767       }
 768       slt->app_rtt = app_rtt;
 769
 770       /* Partner throughput */
 771       if (NULL != prev_log_mlt)
 772       {
 773         prev_log_slt =  &prev_log_mlt->slaves_log[c_s];
 774         if (slt->total_bytes_sent > prev_log_slt->total_bytes_sent)
 775           slt->throughput_sent = mult * (slt->total_bytes_sent - prev_log_slt->total_bytes_sent);
 776         else
 777           slt->throughput_sent = 0;
 778
 779         if (slt->total_bytes_received > prev_log_slt->total_bytes_received)
 780           slt->throughput_recv = mult *
 781               (slt->total_bytes_received - prev_log_slt->total_bytes_received);
 782         else
 783           slt->throughput_recv = 0;
 784       }
 785       else
 786       {
 787         slt->throughput_sent = mult * slt->total_bytes_sent;
 788         slt->throughput_recv = mult * slt->total_bytes_received;
 789       }
 790
 791       if (GNUNET_YES == l->verbose)
 792       {
 793         GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
 794             "Master [%u] -> Slave [%u]: delta: %llu us, bytes (sent/received): %u / %u; throughput send/recv: %u / %u\n",
 795             c_m, c_s,
 796             delta.rel_value_us,
 797             mlt->total_bytes_sent,
 798             mlt->total_bytes_received,
 799             slt->throughput_sent,
 800             slt->throughput_recv);
 801       }
 802       else
 803         GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
 804           "Master [%u]: slave [%u]\n",
 805           bp->peer->no, p->dest->no);
 806     }
 807   }
 808 }
 809
 810 static void
 811 collect_log_task (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc)
 812 {
 813   struct LoggingHandle *l = cls;
 814   l->log_task = GNUNET_SCHEDULER_NO_TASK;
 815
 816   GNUNET_ATS_TEST_logging_now (l);
 817
 818   if (tc->reason == GNUNET_SCHEDULER_REASON_SHUTDOWN)
 819     return;
 820
 821   l->log_task = GNUNET_SCHEDULER_add_delayed (l->frequency,
 822       &collect_log_task, l);
 823 }
 824
 825 /**
 826  * Stop logging
 827  *
 828  * @param l the logging handle
 829  */
 830 void
 831 GNUNET_ATS_TEST_logging_stop (struct LoggingHandle *l)
 832 {
 833   if (GNUNET_YES!= l->running)
 834     return;
 835
 836   if (GNUNET_SCHEDULER_NO_TASK != l->log_task)
 837     GNUNET_SCHEDULER_cancel (l->log_task);
 838   l->log_task = GNUNET_SCHEDULER_NO_TASK;
 839   l->running = GNUNET_NO;
 840
 841   GNUNET_log(GNUNET_ERROR_TYPE_INFO,
 842       _("Stop logging\n"));
 843 }
 844
 845 /**
 846  * Clean up logging data
 847  *
 848  * @param l the logging handle
 849  */
 850 void
 851 GNUNET_ATS_TEST_logging_clean_up (struct LoggingHandle *l)
 852 {
 853   int c_m;
 854   struct PeerLoggingTimestep *cur;
 855
 856   if (GNUNET_YES == l->running)
 857     GNUNET_ATS_TEST_logging_stop (l);
 858
 859   for (c_m = 0; c_m < l->num_masters; c_m++)
 860   {
 861     while (NULL != (cur = l->lp[c_m].head))
 862     {
 863       GNUNET_CONTAINER_DLL_remove (l->lp[c_m].head, l->lp[c_m].tail, cur);
 864       GNUNET_free (cur->slaves_log);
 865       GNUNET_free (cur);
 866     }
 867   }
 868
 869   GNUNET_free (l->lp);
 870   GNUNET_free (l);
 871 }
 872
 873
 874 /**
 875  * Start logging
 876  *
 877  * @param log_frequency the logging frequency
 878  * @param testname the testname
 879  * @param masters the master peers used for benchmarking
 880  * @param num_masters the number of master peers
 881  * @param num_slaves the number of slave peers
 882  * @param verbose verbose logging
 883  * @return the logging handle or NULL on error
 884  */
 885 struct LoggingHandle *
 886 GNUNET_ATS_TEST_logging_start(struct GNUNET_TIME_Relative log_frequency,
 887     char *testname, struct BenchmarkPeer *masters, int num_masters, int num_slaves,
 888     int verbose)
 889 {
 890   struct LoggingHandle *l;
 891   int c_m;
 892   GNUNET_log(GNUNET_ERROR_TYPE_INFO,
 893       _("Start logging `%s'\n"), testname);
 894
 895   l = GNUNET_new (struct LoggingHandle);
 896   l->num_masters = num_masters;
 897   l->num_slaves = num_slaves;
 898   l->name = testname;
 899   l->frequency = log_frequency;
 900   l->verbose = verbose;
 901   l->lp = GNUNET_malloc (num_masters * sizeof (struct LoggingPeer));
 902
 903   for (c_m = 0; c_m < num_masters; c_m ++)
 904   {
 905     l->lp[c_m].peer = &masters[c_m];
 906     l->lp[c_m].start = GNUNET_TIME_absolute_get();
 907   }
 908
 909   /* Schedule logging task */
 910   l->log_task = GNUNET_SCHEDULER_add_now (&collect_log_task, l);
 911   l->running = GNUNET_YES;
 912
 913   return l;
 914 }
 915 /* end of file ats-testing-log.c */
 916