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

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