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

   1 /*
   2  This file is part of GNUnet.
   3  (C) 2010-2013 Christian Grothoff (and other contributing authors)
   4
   5  GNUnet is free software; you can redistribute it and/or modify
   6  it under the terms of the GNU General Public License as published
   7  by the Free Software Foundation; either version 3, or (at your
   8  option) any later version.
   9
  10  GNUnet is distributed in the hope that it will be useful, but
  11  WITHOUT ANY WARRANTY; without even the implied warranty of
  12  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
  13  General Public License for more details.
  14
  15  You should have received a copy of the GNU General Public License
  16  along with GNUnet; see the file COPYING.  If not, write to the
  17  Free Software Foundation, Inc., 59 Temple Place - Suite 330,
  18  Boston, MA 02111-1307, USA.
  19  */
  20 /**
  21  * @file ats-tests/ats-testing-log.c
  22  * @brief ats benchmark: logging for performance tests
  23  * @author Christian Grothoff
  24  * @author Matthias Wachs
  25  */
  26 #include "platform.h"
  27 #include "gnunet_util_lib.h"
  28 #include "ats-testing.h"
  29
  30 #define THROUGHPUT_TEMPLATE "#!/usr/bin/gnuplot \n" \
  31 "set datafile separator ';' \n" \
  32 "set title \"Throughput between Master and Slaves\" \n" \
  33 "set xlabel \"Time in ms\" \n" \
  34 "set ylabel \"Bytes/s\" \n" \
  35 "set grid \n"
  36
  37 #define RTT_TEMPLATE "#!/usr/bin/gnuplot \n" \
  38 "set datafile separator ';' \n" \
  39 "set title \"Application level roundtrip time between Master and Slaves\" \n" \
  40 "set xlabel \"Time in ms\" \n" \
  41 "set ylabel \"ms\" \n" \
  42 "set grid \n"
  43
  44 #define BW_TEMPLATE "#!/usr/bin/gnuplot \n" \
  45 "set datafile separator ';' \n" \
  46 "set title \"Bandwidth inbound and outbound between Master and Slaves\" \n" \
  47 "set xlabel \"Time in ms\" \n" \
  48 "set ylabel \"Bytes / s \" \n" \
  49 "set grid \n"
  50
  51 #define LOG_ITEMS_TIME 2
  52 #define LOG_ITEMS_PER_PEER 17
  53
  54 #define LOG_ITEM_BYTES_SENT 1
  55 #define LOG_ITEM_MSGS_SENT 2
  56 #define LOG_ITEM_THROUGHPUT_SENT 3
  57 #define LOG_ITEM_BYTES_RECV 4
  58 #define LOG_ITEM_MSGS_RECV 5
  59 #define LOG_ITEM_THROUGHPUT_RECV 6
  60 #define LOG_ITEM_APP_RTT 7
  61 #define LOG_ITEM_ATS_BW_IN 8
  62 #define LOG_ITEM_ATS_BW_OUT 9
  63 #define LOG_ITEM_ATS_COSTS_LAN 10
  64 #define LOG_ITEM_ATS_WAN 11
  65 #define LOG_ITEM_ATS_WLAN 12
  66 #define LOG_ITEM_ATS_DELAY 13
  67 #define LOG_ITEM_ATS_DISTANCE 14
  68 #define LOG_ITEM_ATS_NETWORKTYPE 15
  69 #define LOG_ITEM_ATS_UTIL_UP 16
  70 #define LOG_ITEM_ATS_UTIL_DOWN 17
  71
  72 /**
  73  * A single logging time step for a partner
  74  */
  75 struct PartnerLoggingTimestep
  76 {
  77   /**
  78    * Peer
  79    */
  80   struct BenchmarkPeer *slave;
  81
  82   /**
  83    * Total number of messages this peer has sent
  84    */
  85   unsigned int total_messages_sent;
  86
  87   /**
  88    * Total number of bytes this peer has sent
  89    */
  90   unsigned int total_bytes_sent;
  91
  92   /**
  93    * Total number of messages this peer has received
  94    */
  95   unsigned int total_messages_received;
  96
  97   /**
  98    * Total number of bytes this peer has received
  99    */
 100   unsigned int total_bytes_received;
 101
 102   /**
 103    * Total outbound throughput for master in Bytes / s
 104    */
 105   unsigned int throughput_sent;
 106
 107   /**
 108    * Total inbound throughput for master in Bytes / s
 109    */
 110   unsigned int throughput_recv;
 111
 112   /**
 113    * Accumulated RTT for all messages
 114    */
 115   unsigned int total_app_rtt;
 116
 117   /**
 118    * Current application level delay
 119    */
 120   unsigned int app_rtt;
 121
 122   /* Current ATS properties */
 123
 124   uint32_t ats_distance;
 125
 126   uint32_t ats_delay;
 127
 128   uint32_t bandwidth_in;
 129
 130   uint32_t bandwidth_out;
 131
 132   uint32_t ats_utilization_up;
 133
 134   uint32_t ats_utilization_down;
 135
 136   uint32_t ats_network_type;
 137
 138   uint32_t ats_cost_wan;
 139
 140   uint32_t ats_cost_lan;
 141
 142   uint32_t ats_cost_wlan;
 143 };
 144
 145
 146 /**
 147  * A single logging time step for a peer
 148  */
 149 struct PeerLoggingTimestep
 150 {
 151   /**
 152    * Next in DLL
 153    */
 154   struct PeerLoggingTimestep *next;
 155
 156   /**
 157    * Prev in DLL
 158    */
 159   struct PeerLoggingTimestep *prev;
 160
 161   /**
 162    * Logging timestamp
 163    */
 164   struct GNUNET_TIME_Absolute timestamp;
 165
 166   /**
 167    * Total number of messages this peer has sent
 168    */
 169   unsigned int total_messages_sent;
 170
 171   /**
 172    * Total number of bytes this peer has sent
 173    */
 174   unsigned int total_bytes_sent;
 175
 176   /**
 177    * Total number of messages this peer has received
 178    */
 179   unsigned int total_messages_received;
 180
 181   /**
 182    * Total number of bytes this peer has received
 183    */
 184   unsigned int total_bytes_received;
 185
 186   /**
 187    * Total outbound throughput for master in Bytes / s
 188    */
 189   unsigned int total_throughput_send;
 190
 191   /**
 192    * Total inbound throughput for master in Bytes / s
 193    */
 194   unsigned int total_throughput_recv;
 195
 196   /**
 197    * Logs for slaves
 198    */
 199   struct PartnerLoggingTimestep *slaves_log;
 200 };
 201
 202 /**
 203  * Entry for a benchmark peer
 204  */
 205 struct LoggingPeer
 206 {
 207   /**
 208    * Peer
 209    */
 210   struct BenchmarkPeer *peer;
 211
 212   /**
 213    * Start time
 214    */
 215   struct GNUNET_TIME_Absolute start;
 216
 217   /**
 218    * DLL for logging entries: head
 219    */
 220   struct PeerLoggingTimestep *head;
 221
 222   /**
 223    * DLL for logging entries: tail
 224    */
 225   struct PeerLoggingTimestep *tail;
 226 };
 227
 228 struct LoggingHandle
 229 {
 230   /**
 231    * Logging task
 232    */
 233   GNUNET_SCHEDULER_TaskIdentifier log_task;
 234
 235   /**
 236    * Reference to perf_ats' masters
 237    */
 238   int num_peers;
 239   int running;
 240   char *name;
 241   struct GNUNET_TIME_Relative frequency;
 242
 243   /**
 244    * Log structure of length num_peers
 245    */
 246   struct LoggingPeer *lp;
 247 };
 248
 249
 250
 251 static void
 252 write_throughput_gnuplot_script (char * fn, struct LoggingPeer *lp)
 253 {
 254   struct GNUNET_DISK_FileHandle *f;
 255   char * gfn;
 256   char *data;
 257   int c_s;
 258   int peer_index;
 259
 260   GNUNET_asprintf (&gfn, "gnuplot_throughput_%s",fn);
 261   fprintf (stderr, "Writing throughput plot for master %u to `%s'\n",
 262       lp->peer->no, gfn);
 263
 264   f = GNUNET_DISK_file_open (gfn,
 265       GNUNET_DISK_OPEN_WRITE | GNUNET_DISK_OPEN_CREATE,
 266       GNUNET_DISK_PERM_USER_EXEC | 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", gfn);
 271     GNUNET_free (gfn);
 272     return;
 273   }
 274
 275   /* Write header */
 276
 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   peer_index = LOG_ITEMS_TIME;
 284   GNUNET_asprintf (&data,
 285       "plot '%s' using 2:%u with lines title 'Master %u send total', \\\n" \
 286       "'%s' using 2:%u with lines title 'Master %u receive total', \\\n",
 287       fn, peer_index + LOG_ITEM_THROUGHPUT_SENT, lp->peer->no,
 288       fn, peer_index + LOG_ITEM_THROUGHPUT_RECV, lp->peer->no);
 289   if (GNUNET_SYSERR == GNUNET_DISK_file_write(f, data, strlen(data)))
 290     GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot write data to plot file `%s'\n", gfn);
 291   GNUNET_free (data);
 292
 293   peer_index = LOG_ITEMS_TIME + LOG_ITEMS_PER_PEER ;
 294   for (c_s = 0; c_s < lp->peer->num_partners; c_s++)
 295   {
 296     GNUNET_asprintf (&data, "'%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         fn,
 299         peer_index + LOG_ITEM_THROUGHPUT_SENT,
 300         lp->peer->no,
 301         lp->peer->partners[c_s].dest->no,
 302         fn,
 303         peer_index + LOG_ITEM_THROUGHPUT_RECV,
 304         lp->peer->no,
 305         lp->peer->partners[c_s].dest->no,
 306         (c_s < lp->peer->num_partners -1) ? ", \\" : "\n pause -1");
 307     if (GNUNET_SYSERR == GNUNET_DISK_file_write(f, data, strlen(data)))
 308         GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot write data to plot file `%s'\n", gfn);
 309     GNUNET_free (data);
 310     peer_index += LOG_ITEMS_PER_PEER;
 311   }
 312
 313   if (GNUNET_SYSERR == GNUNET_DISK_file_close(f))
 314     GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
 315         "Cannot close gnuplot file `%s'\n", gfn);
 316   else
 317     GNUNET_log (GNUNET_ERROR_TYPE_INFO,
 318         "Data successfully written to plot file `%s'\n", gfn);
 319
 320   GNUNET_free (gfn);
 321 }
 322
 323
 324 static void
 325 write_rtt_gnuplot_script (char * fn, struct LoggingPeer *lp)
 326 {
 327   struct GNUNET_DISK_FileHandle *f;
 328   char * gfn;
 329   char *data;
 330   int c_s;
 331   int index;
 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 | GNUNET_DISK_PERM_USER_READ |
 340       GNUNET_DISK_PERM_USER_WRITE);
 341   if (NULL == f)
 342   {
 343     GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot open gnuplot file `%s'\n", gfn);
 344     GNUNET_free (gfn);
 345     return;
 346   }
 347
 348   /* Write header */
 349
 350   if (GNUNET_SYSERR == GNUNET_DISK_file_write(f, RTT_TEMPLATE, strlen(RTT_TEMPLATE)))
 351     GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot write data to plot file `%s'\n", gfn);
 352
 353   index = LOG_ITEMS_TIME + LOG_ITEMS_PER_PEER;
 354   for (c_s = 0; c_s < lp->peer->num_partners; c_s++)
 355   {
 356     GNUNET_asprintf (&data, "%s'%s' using 2:%u with lines title 'Master %u - Slave %u '%s\n",
 357         (0 == c_s) ? "plot " :"",
 358         fn, index + LOG_ITEM_APP_RTT, lp->peer->no, lp->peer->partners[c_s].dest->no,
 359         (c_s < lp->peer->num_partners -1) ? ", \\" : "\n pause -1");
 360     if (GNUNET_SYSERR == GNUNET_DISK_file_write(f, data, strlen(data)))
 361         GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot write data to plot file `%s'\n", gfn);
 362     GNUNET_free (data);
 363     index += LOG_ITEMS_PER_PEER;
 364   }
 365
 366   if (GNUNET_SYSERR == GNUNET_DISK_file_close(f))
 367     GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot close gnuplot file `%s'\n", gfn);
 368   else
 369     GNUNET_log (GNUNET_ERROR_TYPE_INFO, "Data successfully written to plot file `%s'\n", gfn);
 370   GNUNET_free (gfn);
 371 }
 372
 373 static void
 374 write_bw_gnuplot_script (char * fn, struct LoggingPeer *lp)
 375 {
 376   struct GNUNET_DISK_FileHandle *f;
 377   char * gfn;
 378   char *data;
 379   int c_s;
 380   int index;
 381
 382   GNUNET_asprintf (&gfn, "gnuplot_bw_%s",fn);
 383   fprintf (stderr, "Writing bandwidth plot for master %u to `%s'\n",
 384       lp->peer->no, gfn);
 385
 386   f = GNUNET_DISK_file_open (gfn,
 387       GNUNET_DISK_OPEN_WRITE | GNUNET_DISK_OPEN_CREATE,
 388       GNUNET_DISK_PERM_USER_EXEC | GNUNET_DISK_PERM_USER_READ |
 389       GNUNET_DISK_PERM_USER_WRITE);
 390   if (NULL == f)
 391   {
 392     GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot open gnuplot file `%s'\n", gfn);
 393     GNUNET_free (gfn);
 394     return;
 395   }
 396
 397   /* Write header */
 398   if (GNUNET_SYSERR == GNUNET_DISK_file_write(f, BW_TEMPLATE, strlen(BW_TEMPLATE)))
 399     GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
 400         "Cannot write data to plot file `%s'\n", gfn);
 401
 402   index = LOG_ITEMS_TIME + LOG_ITEMS_PER_PEER;
 403   for (c_s = 0; c_s < lp->peer->num_partners; c_s++)
 404   {
 405     GNUNET_asprintf (&data, "%s"\
 406         "'%s' using 2:%u with lines title 'BW out master %u - Slave %u ', \\\n" \
 407         "'%s' using 2:%u with lines title 'BW in master %u - Slave %u '"\
 408         "%s\n",
 409         (0 == c_s) ? "plot " :"",
 410         fn, index + LOG_ITEM_ATS_BW_OUT, lp->peer->no, lp->peer->partners[c_s].dest->no,
 411         fn, index + LOG_ITEM_ATS_BW_IN, lp->peer->no, lp->peer->partners[c_s].dest->no,
 412         (c_s < lp->peer->num_partners -1) ? ", \\" : "\n pause -1");
 413     if (GNUNET_SYSERR == GNUNET_DISK_file_write(f, data, strlen(data)))
 414         GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot write data to plot file `%s'\n", gfn);
 415     GNUNET_free (data);
 416     index += LOG_ITEMS_PER_PEER;
 417   }
 418
 419   if (GNUNET_SYSERR == GNUNET_DISK_file_close(f))
 420     GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot close gnuplot file `%s'\n", gfn);
 421   else
 422     GNUNET_log (GNUNET_ERROR_TYPE_INFO, "Data successfully written to plot file `%s'\n", gfn);
 423   GNUNET_free (gfn);
 424 }
 425
 426
 427 void
 428 GNUNET_ATS_TEST_logging_write_to_file (struct LoggingHandle *l,
 429     char *experiment_name, int plots)
 430 {
 431   struct GNUNET_DISK_FileHandle *f;
 432   char *tmp_exp_name;
 433   char *filename_data;
 434   char *data;
 435   char *slave_string;
 436   char *slave_string_tmp;
 437   struct PeerLoggingTimestep *cur_lt;
 438   struct PartnerLoggingTimestep *plt;
 439   struct GNUNET_TIME_Absolute timestamp;
 440   int c_m;
 441   int c_s;
 442
 443
 444   timestamp = GNUNET_TIME_absolute_get();
 445
 446   tmp_exp_name = experiment_name;
 447   if (NULL != strchr (experiment_name,  '/'));
 448   {
 449     tmp_exp_name = strchr (experiment_name,  '/');
 450     tmp_exp_name++;
 451   }
 452
 453   for (c_m = 0; c_m < l->num_peers; c_m++)
 454   {
 455     GNUNET_asprintf (&filename_data, "%s_%llu_master_%u_%s_%s", tmp_exp_name,
 456         timestamp.abs_value_us,
 457         l->lp[c_m].peer->no, GNUNET_i2s(&l->lp[c_m].peer->id), l->name);
 458
 459     fprintf (stderr, "Writing master %u to file `%s'\n", c_m, filename_data);
 460
 461     f = GNUNET_DISK_file_open (filename_data,
 462         GNUNET_DISK_OPEN_WRITE | GNUNET_DISK_OPEN_CREATE,
 463         GNUNET_DISK_PERM_USER_READ | GNUNET_DISK_PERM_USER_WRITE);
 464     if (NULL == f)
 465     {
 466       GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot open log file `%s'\n", filename_data);
 467       GNUNET_free (filename_data);
 468       return;
 469     }
 470
 471     GNUNET_asprintf (&data, "# master peers: %u ; slave peers: %u ; experiment : %s\n",
 472         l->num_peers, l->lp[c_m].peer->num_partners, experiment_name);
 473     if (GNUNET_SYSERR == GNUNET_DISK_file_write(f, data, strlen(data)))
 474       GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
 475           "Cannot write data to log file `%s'\n", filename_data);
 476     GNUNET_free (data);
 477
 478     for (cur_lt = l->lp[c_m].head; NULL != cur_lt; cur_lt = cur_lt->next)
 479     {
 480        GNUNET_log(GNUNET_ERROR_TYPE_INFO,
 481           "Master [%u]: timestamp %llu %llu ; %u %u %u ; %u %u %u\n",
 482           l->lp[c_m].peer->no,
 483           cur_lt->timestamp,
 484           GNUNET_TIME_absolute_get_difference(l->lp[c_m].start,
 485               cur_lt->timestamp).rel_value_us / 1000,
 486           cur_lt->total_messages_sent,
 487           cur_lt->total_bytes_sent,
 488           cur_lt->total_throughput_send,
 489           cur_lt->total_messages_received,
 490           cur_lt->total_bytes_received,
 491           cur_lt->total_throughput_recv);
 492
 493       slave_string = GNUNET_strdup (";");
 494       for (c_s = 0; c_s < l->lp[c_m].peer->num_partners; c_s++)
 495       {
 496         plt = &cur_lt->slaves_log[c_s];
 497         /* Log partners */
 498
 499         /* Assembling slave string */
 500         GNUNET_log(GNUNET_ERROR_TYPE_INFO,
 501             "\t Slave [%u]: %u %u %u ; %u %u %u rtt %u delay %u bw_in %u bw_out %u \n",
 502             plt->slave->no,
 503             plt->total_messages_sent,
 504             plt->total_bytes_sent,
 505             plt->throughput_sent,
 506             plt->total_messages_received,
 507             plt->total_bytes_received,
 508             plt->throughput_recv,
 509             plt->app_rtt,
 510             plt->ats_delay,
 511             plt->bandwidth_in,
 512             plt->bandwidth_out);
 513
 514         GNUNET_asprintf(&slave_string_tmp,
 515             "%s%u;%u;%u;%u;%u;%u;%.3f;%u;%u;%u;%u;%u;%u;%u;%u;%u;%u;",
 516             slave_string,
 517             plt->total_messages_sent,
 518             plt->total_bytes_sent,
 519             plt->throughput_sent,
 520             plt->total_messages_received,
 521             plt->total_bytes_received,
 522             plt->throughput_sent,
 523             (double) plt->app_rtt / 1000,
 524             plt->bandwidth_in,
 525             plt->bandwidth_out,
 526             plt->ats_cost_lan,
 527             plt->ats_cost_wan,
 528             plt->ats_cost_wlan,
 529             plt->ats_delay,
 530             plt->ats_distance,
 531             plt->ats_network_type,
 532             plt->ats_utilization_up,
 533             plt->ats_utilization_down);
 534         GNUNET_free (slave_string);
 535         slave_string = slave_string_tmp;
 536       }
 537       /* Assembling master string */
 538       GNUNET_asprintf (&data, "%llu;%llu;%u;%u;%u;%u;%u;%u;;;;;;;;;;;%s\n",
 539           cur_lt->timestamp,
 540           GNUNET_TIME_absolute_get_difference(l->lp[c_m].start,
 541               cur_lt->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           slave_string);
 549       GNUNET_free (slave_string);
 550
 551       if (GNUNET_SYSERR == GNUNET_DISK_file_write(f, data, strlen(data)))
 552         GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
 553             "Cannot write data to log file `%s'\n", filename_data);
 554       GNUNET_free (data);
 555     }
 556     if (GNUNET_SYSERR == GNUNET_DISK_file_close(f))
 557     {
 558       GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
 559           "Cannot close log file `%s'\n", filename_data);
 560       GNUNET_free (filename_data);
 561       return;
 562     }
 563
 564     if (GNUNET_YES == plots)
 565     {
 566       write_throughput_gnuplot_script (filename_data, &l->lp[c_m]);
 567       write_rtt_gnuplot_script (filename_data, &l->lp[c_m]);
 568       write_bw_gnuplot_script (filename_data, &l->lp[c_m]);
 569     }
 570
 571     GNUNET_log (GNUNET_ERROR_TYPE_INFO,
 572         "Data file successfully written to log file `%s'\n", filename_data);
 573     GNUNET_free (filename_data);
 574   }
 575 }
 576
 577 /**
 578  * Log all data now
 579  *
 580  * @param l logging handle to use
 581  */
 582 void
 583 GNUNET_ATS_TEST_logging_now (struct LoggingHandle *l)
 584 {
 585   struct LoggingPeer *bp;
 586   struct PeerLoggingTimestep *mlt;
 587   struct PeerLoggingTimestep *prev_log_mlt;
 588   struct PartnerLoggingTimestep *slt;
 589   struct PartnerLoggingTimestep *prev_log_slt;
 590   struct BenchmarkPartner *p;
 591   struct GNUNET_TIME_Relative delta;
 592   int c_s;
 593   int c_m;
 594   unsigned int app_rtt;
 595   double mult;
 596
 597   if (GNUNET_YES != l->running)
 598     return;
 599
 600   for (c_m = 0; c_m < l->num_peers; c_m++)
 601   {
 602     bp = &l->lp[c_m];
 603     mlt = GNUNET_new (struct PeerLoggingTimestep);
 604     GNUNET_CONTAINER_DLL_insert_tail(l->lp[c_m].head, l->lp[c_m].tail, mlt);
 605     prev_log_mlt = mlt->prev;
 606
 607     /* Collect data */
 608     /* Current master state */
 609     mlt->timestamp = GNUNET_TIME_absolute_get();
 610     mlt->total_bytes_sent = bp->peer->total_bytes_sent;
 611     mlt->total_messages_sent = bp->peer->total_messages_sent;
 612     mlt->total_bytes_received = bp->peer->total_bytes_received;
 613     mlt->total_messages_received = bp->peer->total_messages_received;
 614
 615     /* Throughput */
 616     if (NULL == prev_log_mlt)
 617      {
 618        /* Get difference to start */
 619        delta = GNUNET_TIME_absolute_get_difference (l->lp[c_m].start, mlt->timestamp);
 620      }
 621      else
 622      {
 623        /* Get difference to last timestep */
 624        delta = GNUNET_TIME_absolute_get_difference (mlt->prev->timestamp, mlt->timestamp);
 625      }
 626
 627      /* Multiplication factor for throughput calculation */
 628      mult = (1.0 * 1000 * 1000) / (delta.rel_value_us);
 629
 630      /* Total throughput */
 631      if (NULL != prev_log_mlt)
 632      {
 633        if (mlt->total_bytes_sent - mlt->prev->total_bytes_sent > 0)
 634          mlt->total_throughput_send = mult * (mlt->total_bytes_sent - mlt->prev->total_bytes_sent);
 635        else
 636          mlt->total_throughput_send = prev_log_mlt->total_throughput_send; /* no msgs send */
 637
 638        if (mlt->total_bytes_received - mlt->prev->total_bytes_received > 0)
 639          mlt->total_throughput_recv = mult * (mlt->total_bytes_received - mlt->prev->total_bytes_received);
 640        else
 641          mlt->total_throughput_recv = prev_log_mlt->total_throughput_recv; /* no msgs received */
 642      }
 643      else
 644      {
 645        mlt->total_throughput_send = mult * mlt->total_bytes_sent;
 646        mlt->total_throughput_send = mult * mlt->total_bytes_received;
 647      }
 648
 649     mlt->slaves_log = GNUNET_malloc (bp->peer->num_partners *
 650         sizeof (struct PartnerLoggingTimestep));
 651
 652     for (c_s = 0; c_s < bp->peer->num_partners; c_s++)
 653     {
 654
 655       GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
 656           "Collect logging data master[%u] slave [%u]\n", c_m, c_s);
 657
 658       p = &bp->peer->partners[c_s];
 659       slt = &mlt->slaves_log[c_s];
 660
 661       slt->slave = p->dest;
 662       /* Bytes sent from master to this slave */
 663       slt->total_bytes_sent = p->bytes_sent;
 664       /* Messages sent from master to this slave */
 665       slt->total_messages_sent = p->messages_sent;
 666       /* Bytes master received from this slave */
 667       slt->total_bytes_received = p->bytes_received;
 668       /* Messages master received from this slave */
 669       slt->total_messages_received = p->messages_received;
 670       slt->total_app_rtt = p->total_app_rtt;
 671       /* ats performance information */
 672       slt->ats_cost_lan = p->ats_cost_lan;
 673       slt->ats_cost_wan = p->ats_cost_wan;
 674       slt->ats_cost_wlan = p->ats_cost_wlan;
 675       slt->ats_delay = p->ats_delay;
 676       slt->ats_distance = p->ats_distance;
 677       slt->ats_network_type = p->ats_network_type;
 678       slt->ats_utilization_down = p->ats_utilization_down;
 679       slt->ats_utilization_up = p->ats_utilization_up;
 680       slt->bandwidth_in = p->bandwidth_in;
 681       slt->bandwidth_out = p->bandwidth_out;
 682
 683       /* Total application level rtt  */
 684       if (NULL == prev_log_mlt)
 685       {
 686         if (0 != slt->total_messages_sent)
 687           app_rtt = slt->total_app_rtt / slt->total_messages_sent;
 688         else
 689           app_rtt = 0;
 690       }
 691       else
 692       {
 693         prev_log_slt =  &prev_log_mlt->slaves_log[c_s];
 694         if ((slt->total_messages_sent - prev_log_slt->total_messages_sent) > 0)
 695           app_rtt = (slt->total_app_rtt - prev_log_slt->total_app_rtt) /
 696                   (slt->total_messages_sent - prev_log_slt->total_messages_sent);
 697         else
 698           app_rtt = prev_log_slt->app_rtt; /* No messages were */
 699       }
 700       slt->app_rtt = app_rtt;
 701
 702       /* Partner throughput */
 703       if (NULL != prev_log_mlt)
 704       {
 705         prev_log_slt =  &prev_log_mlt->slaves_log[c_s];
 706         if (slt->total_bytes_sent - prev_log_slt->total_bytes_sent > 0)
 707           slt->throughput_sent = mult * (slt->total_bytes_sent - prev_log_slt->total_bytes_sent);
 708         else
 709           slt->throughput_sent = prev_log_slt->throughput_sent; /* no msgs send */
 710
 711         if (slt->total_bytes_received - prev_log_slt->total_bytes_received > 0)
 712           slt->throughput_recv = mult * (slt->total_bytes_received - prev_log_slt->total_bytes_received);
 713         else
 714           slt->throughput_recv = prev_log_slt->throughput_recv; /* no msgs received */
 715       }
 716       else
 717       {
 718         slt->throughput_sent = mult * slt->total_bytes_sent;
 719         slt->throughput_sent = mult * slt->total_bytes_received;
 720       }
 721
 722       GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
 723           "Master [%u]: slave [%u]\n",
 724           bp->peer->no, p->dest->no);
 725     }
 726   }
 727 }
 728
 729 static void
 730 collect_log_task (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc)
 731 {
 732   struct LoggingHandle *l = cls;
 733   l->log_task = GNUNET_SCHEDULER_NO_TASK;
 734
 735   GNUNET_ATS_TEST_logging_now (l);
 736
 737   if (tc->reason == GNUNET_SCHEDULER_REASON_SHUTDOWN)
 738     return;
 739
 740   l->log_task = GNUNET_SCHEDULER_add_delayed (l->frequency,
 741       &collect_log_task, l);
 742 }
 743
 744 /**
 745  * Stop logging
 746  *
 747  * @param l the logging handle
 748  */
 749 void
 750 GNUNET_ATS_TEST_logging_stop (struct LoggingHandle *l)
 751 {
 752   struct GNUNET_SCHEDULER_TaskContext tc;
 753   if (GNUNET_YES!= l->running)
 754     return;
 755
 756   if (GNUNET_SCHEDULER_NO_TASK != l->log_task)
 757     GNUNET_SCHEDULER_cancel (l->log_task);
 758   l->log_task = GNUNET_SCHEDULER_NO_TASK;
 759   tc.reason = GNUNET_SCHEDULER_REASON_SHUTDOWN;
 760   l->running = GNUNET_NO;
 761
 762   GNUNET_log(GNUNET_ERROR_TYPE_INFO,
 763       _("Stop logging\n"));
 764 }
 765
 766 /**
 767  * Clean up logging data
 768  *
 769  * @param l the logging handle
 770  */
 771 void
 772 GNUNET_ATS_TEST_logging_clean_up (struct LoggingHandle *l)
 773 {
 774   int c_m;
 775   struct PeerLoggingTimestep *cur;
 776
 777   if (GNUNET_YES == l->running)
 778     GNUNET_ATS_TEST_logging_stop (l);
 779
 780   for (c_m = 0; c_m < l->num_peers; c_m++)
 781   {
 782     while (NULL != (cur = l->lp[c_m].head))
 783     {
 784       GNUNET_CONTAINER_DLL_remove (l->lp[c_m].head, l->lp[c_m].tail, cur);
 785       GNUNET_free (cur->slaves_log);
 786       GNUNET_free (cur);
 787     }
 788   }
 789
 790   GNUNET_free (l->lp);
 791   GNUNET_free (l);
 792 }
 793
 794
 795 /**
 796  * Start logging
 797  *
 798  * @param log_frequency the logging frequency
 799  * @param testname the testname
 800  * @param masters the master peers used for benchmarking
 801  * @param num_masters the number of master peers
 802  * @return the logging handle or NULL on error
 803  */
 804 struct LoggingHandle *
 805 GNUNET_ATS_TEST_logging_start(struct GNUNET_TIME_Relative log_frequency,
 806     char *testname, struct BenchmarkPeer *masters, int num_masters)
 807 {
 808   struct LoggingHandle *l;
 809   int c_m;
 810   GNUNET_log(GNUNET_ERROR_TYPE_INFO,
 811       _("Start logging `%s'\n"), testname);
 812
 813   l = GNUNET_new (struct LoggingHandle);
 814   l->num_peers = num_masters;
 815   l->name = testname;
 816   l->frequency = log_frequency;
 817   l->lp = GNUNET_malloc (num_masters * sizeof (struct LoggingPeer));
 818
 819   for (c_m = 0; c_m < num_masters; c_m ++)
 820   {
 821     l->lp[c_m].peer = &masters[c_m];
 822     l->lp[c_m].start = GNUNET_TIME_absolute_get();
 823   }
 824
 825   /* Schedule logging task */
 826   l->log_task = GNUNET_SCHEDULER_add_now (&collect_log_task, l);
 827   l->running = GNUNET_YES;
 828
 829   return l;
 830 }
 831 /* end of file ats-testing-log.c */
 832