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