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

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