X-Git-Url: https://git.librecmc.org/?a=blobdiff_plain;f=src%2Fats-tests%2Fperf_ats_logging.c;h=c9f6b0f3b3d6aa3d48cf655de1969727e8d63aa1;hb=4dcb414e2faabc800577c25dec3b63e3ceaaa84b;hp=643f5524312d62b4885ab6f8ff5f50de07a6c587;hpb=9db84f729ed3dc14c49dc38ec9ba4bbcade14054;p=oweals%2Fgnunet.git diff --git a/src/ats-tests/perf_ats_logging.c b/src/ats-tests/perf_ats_logging.c index 643f55243..c9f6b0f3b 100644 --- a/src/ats-tests/perf_ats_logging.c +++ b/src/ats-tests/perf_ats_logging.c @@ -1,6 +1,6 @@ /* This file is part of GNUnet. - (C) 2010-2013 Christian Grothoff (and other contributing authors) + Copyright (C) 2010-2013 Christian Grothoff (and other contributing authors) GNUnet is free software; you can redistribute it and/or modify it under the terms of the GNU General Public License as published @@ -14,8 +14,8 @@ You should have received a copy of the GNU General Public License along with GNUnet; see the file COPYING. If not, write to the - Free Software Foundation, Inc., 59 Temple Place - Suite 330, - Boston, MA 02111-1307, USA. + Free Software Foundation, Inc., 51 Franklin Street, Fifth Floor, + Boston, MA 02110-1301, USA. */ /** * @file ats/perf_ats_logging.c @@ -31,30 +31,48 @@ "set datafile separator ';' \n" \ "set title \"Throughput between Master and Slaves\" \n" \ "set xlabel \"Time in ms\" \n" \ -"set ylabel \"Bytes/s\" \n" +"set ylabel \"Bytes/s\" \n" \ +"set grid \n" #define RTT_TEMPLATE "#!/usr/bin/gnuplot \n" \ "set datafile separator ';' \n" \ "set title \"Application level roundtrip time between Master and Slaves\" \n" \ "set xlabel \"Time in ms\" \n" \ -"set ylabel \"ms\" \n" +"set ylabel \"ms\" \n" \ +"set grid \n" -#define LOG_ITEMS_PER_PEER 7 -#define LOG_ITEMS_TIME 2 - -#define LOG_ITEMS_BYTES_SENT 1 -#define LOG_ITEMS_MSGS_SENT 2 -#define LOG_ITEMS_THROUGHPUT_SENT 3 -#define LOG_ITEMS_BYTES_RECV 4 -#define LOG_ITEMS_MSGS_RECV 5 -#define LOG_ITEMS_THROUGHPUT_RECV 6 -#define LOG_ITEMS_APP_RTT 7 +#define BW_TEMPLATE "#!/usr/bin/gnuplot \n" \ +"set datafile separator ';' \n" \ +"set title \"Bandwidth inbound and outbound between Master and Slaves\" \n" \ +"set xlabel \"Time in ms\" \n" \ +"set ylabel \"Bytes / s \" \n" \ +"set grid \n" +#define LOG_ITEMS_TIME 2 +#define LOG_ITEMS_PER_PEER 17 + +#define LOG_ITEM_BYTES_SENT 1 +#define LOG_ITEM_MSGS_SENT 2 +#define LOG_ITEM_THROUGHPUT_SENT 3 +#define LOG_ITEM_BYTES_RECV 4 +#define LOG_ITEM_MSGS_RECV 5 +#define LOG_ITEM_THROUGHPUT_RECV 6 +#define LOG_ITEM_APP_RTT 7 +#define LOG_ITEM_ATS_BW_IN 8 +#define LOG_ITEM_ATS_BW_OUT 9 +#define LOG_ITEM_ATS_COSTS_LAN 10 +#define LOG_ITEM_ATS_WAN 11 +#define LOG_ITEM_ATS_WLAN 12 +#define LOG_ITEM_ATS_DELAY 13 +#define LOG_ITEM_ATS_DISTANCE 14 +#define LOG_ITEM_ATS_NETWORKTYPE 15 +#define LOG_ITEM_ATS_UTIL_UP 16 +#define LOG_ITEM_ATS_UTIL_DOWN 17 /** * Logging task */ -static GNUNET_SCHEDULER_TaskIdentifier log_task; +static struct GNUNET_SCHEDULER_Task * log_task; /** * Reference to perf_ats' masters @@ -94,6 +112,16 @@ struct PartnerLoggingTimestep */ unsigned int total_bytes_received; + /** + * Total outbound throughput for master in Bytes / s + */ + unsigned int throughput_sent; + + /** + * Total inbound throughput for master in Bytes / s + */ + unsigned int throughput_recv; + /** * Accumulated RTT for all messages */ @@ -168,6 +196,16 @@ struct PeerLoggingTimestep */ unsigned int total_bytes_received; + /** + * Total outbound throughput for master in Bytes / s + */ + unsigned int total_throughput_send; + + /** + * Total inbound throughput for master in Bytes / s + */ + unsigned int total_throughput_recv; + /** * Logs for slaves */ @@ -235,8 +273,8 @@ write_throughput_gnuplot_script (char * fn, struct LoggingPeer *lp) peer_index = LOG_ITEMS_TIME; GNUNET_asprintf (&data, "plot '%s' using 2:%u with lines title 'Master %u send total', \\\n" \ "'%s' using 2:%u with lines title 'Master %u receive total', \\\n", - fn, peer_index + LOG_ITEMS_THROUGHPUT_SENT, lp->peer->no, - fn, peer_index + LOG_ITEMS_THROUGHPUT_RECV, lp->peer->no); + fn, peer_index + LOG_ITEM_THROUGHPUT_SENT, lp->peer->no, + fn, peer_index + LOG_ITEM_THROUGHPUT_RECV, lp->peer->no); if (GNUNET_SYSERR == GNUNET_DISK_file_write(f, data, strlen(data))) GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot write data to plot file `%s'\n", gfn); GNUNET_free (data); @@ -246,8 +284,8 @@ write_throughput_gnuplot_script (char * fn, struct LoggingPeer *lp) { GNUNET_asprintf (&data, "'%s' using 2:%u with lines title 'Master %u - Slave %u send', \\\n" \ "'%s' using 2:%u with lines title 'Master %u - Slave %u receive'%s\n", - fn, peer_index + LOG_ITEMS_THROUGHPUT_SENT, lp->peer->no, lp->peer->partners[c_s].dest->no, - fn, peer_index + LOG_ITEMS_THROUGHPUT_RECV, lp->peer->no, lp->peer->partners[c_s].dest->no, + fn, peer_index + LOG_ITEM_THROUGHPUT_SENT, lp->peer->no, lp->peer->partners[c_s].dest->no, + fn, peer_index + LOG_ITEM_THROUGHPUT_RECV, lp->peer->no, lp->peer->partners[c_s].dest->no, (c_s < lp->peer->num_partners -1) ? ", \\" : "\n pause -1"); if (GNUNET_SYSERR == GNUNET_DISK_file_write(f, data, strlen(data))) GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot write data to plot file `%s'\n", gfn); @@ -294,7 +332,56 @@ write_rtt_gnuplot_script (char * fn, struct LoggingPeer *lp) { GNUNET_asprintf (&data, "%s'%s' using 2:%u with lines title 'Master %u - Slave %u '%s\n", (0 == c_s) ? "plot " :"", - fn, index + LOG_ITEMS_APP_RTT, lp->peer->no, lp->peer->partners[c_s].dest->no, + fn, index + LOG_ITEM_APP_RTT, lp->peer->no, lp->peer->partners[c_s].dest->no, + (c_s < lp->peer->num_partners -1) ? ", \\" : "\n pause -1"); + if (GNUNET_SYSERR == GNUNET_DISK_file_write(f, data, strlen(data))) + GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot write data to plot file `%s'\n", gfn); + GNUNET_free (data); + index += LOG_ITEMS_PER_PEER; + } + + if (GNUNET_SYSERR == GNUNET_DISK_file_close(f)) + GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot close gnuplot file `%s'\n", gfn); + else + GNUNET_log (GNUNET_ERROR_TYPE_INFO, "Data successfully written to plot file `%s'\n", gfn); + GNUNET_free (gfn); +} + +static void +write_bw_gnuplot_script (char * fn, struct LoggingPeer *lp) +{ + struct GNUNET_DISK_FileHandle *f; + char * gfn; + char *data; + int c_s; + int index; + + GNUNET_asprintf (&gfn, "gnuplot_bw_%s",fn); + f = GNUNET_DISK_file_open (gfn, + GNUNET_DISK_OPEN_WRITE | GNUNET_DISK_OPEN_CREATE, + GNUNET_DISK_PERM_USER_EXEC | GNUNET_DISK_PERM_USER_READ | GNUNET_DISK_PERM_USER_WRITE); + if (NULL == f) + { + GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot open gnuplot file `%s'\n", gfn); + GNUNET_free (gfn); + return; + } + + /* Write header */ + + if (GNUNET_SYSERR == GNUNET_DISK_file_write(f, BW_TEMPLATE, strlen(BW_TEMPLATE))) + GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot write data to plot file `%s'\n", gfn); + + index = LOG_ITEMS_TIME + LOG_ITEMS_PER_PEER; + for (c_s = 0; c_s < lp->peer->num_partners; c_s++) + { + GNUNET_asprintf (&data, "%s"\ + "'%s' using 2:%u with lines title 'BW out master %u - Slave %u ', \\\n" \ + "'%s' using 2:%u with lines title 'BW in master %u - Slave %u '"\ + "%s\n", + (0 == c_s) ? "plot " :"", + fn, index + LOG_ITEM_ATS_BW_OUT, lp->peer->no, lp->peer->partners[c_s].dest->no, + fn, index + LOG_ITEM_ATS_BW_IN, lp->peer->no, lp->peer->partners[c_s].dest->no, (c_s < lp->peer->num_partners -1) ? ", \\" : "\n pause -1"); if (GNUNET_SYSERR == GNUNET_DISK_file_write(f, data, strlen(data))) GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Cannot write data to plot file `%s'\n", gfn); @@ -309,11 +396,12 @@ write_rtt_gnuplot_script (char * fn, struct LoggingPeer *lp) GNUNET_free (gfn); } + static void write_to_file () { struct GNUNET_DISK_FileHandle *f; - struct GNUNET_TIME_Relative delta; + char * filename; char *data; char *slave_string; @@ -322,13 +410,6 @@ write_to_file () struct PartnerLoggingTimestep *plt; int c_m; int c_s; - unsigned int throughput_recv; - unsigned int throughput_send; - unsigned int throughput_recv_slave; - unsigned int throughput_send_slave; - int last_throughput_send; - int last_throughput_recv; - double mult; for (c_m = 0; c_m < num_peers; c_m++) { @@ -345,101 +426,48 @@ write_to_file () return; } - last_throughput_recv = 0; - last_throughput_send = 0; - for (cur_lt = lp[c_m].head; NULL != cur_lt; cur_lt = cur_lt->next) { - if (NULL == cur_lt->prev) - { - delta = GNUNET_TIME_absolute_get_difference (lp[c_m].start, cur_lt->timestamp); - } - else - delta = GNUNET_TIME_absolute_get_difference (cur_lt->prev->timestamp, cur_lt->timestamp); - - /* Multiplication factor for throughput calculation */ - mult = (1.0 * 1000 * 1000) / (delta.rel_value_us); - if (NULL != cur_lt->prev) - { - if (cur_lt->total_bytes_sent - cur_lt->prev->total_bytes_sent > 0) - { - throughput_send = cur_lt->total_bytes_sent - cur_lt->prev->total_bytes_sent; - throughput_send *= mult; - } - else - { - //GNUNET_break (0); - throughput_send = last_throughput_send; /* no msgs received */ - } - - if (cur_lt->total_bytes_received - cur_lt->prev->total_bytes_received > 0) - { - throughput_recv = cur_lt->total_bytes_received - cur_lt->prev->total_bytes_received; - throughput_recv *= mult; - } - else - { - // GNUNET_break (0); - throughput_recv = last_throughput_recv; /* no msgs received */ - } - } - else - { - throughput_send = cur_lt->total_bytes_sent; - throughput_recv = cur_lt->total_bytes_received; - - throughput_send *= mult; - throughput_recv *= mult; - - } - last_throughput_send = throughput_send; - last_throughput_recv = throughput_recv; - - - GNUNET_log(GNUNET_ERROR_TYPE_INFO, + GNUNET_log(GNUNET_ERROR_TYPE_INFO, "Master [%u]: timestamp %llu %llu ; %u %u %u ; %u %u %u\n", lp[c_m].peer->no, cur_lt->timestamp, GNUNET_TIME_absolute_get_difference(lp[c_m].start,cur_lt->timestamp).rel_value_us / 1000, - cur_lt->total_messages_sent, cur_lt->total_bytes_sent, throughput_send, - cur_lt->total_messages_received, cur_lt->total_bytes_received, throughput_recv); + cur_lt->total_messages_sent, cur_lt->total_bytes_sent, cur_lt->total_throughput_send, + cur_lt->total_messages_received, cur_lt->total_bytes_received, cur_lt->total_throughput_recv); slave_string = GNUNET_strdup (";"); for (c_s = 0; c_s < lp[c_m].peer->num_partners; c_s++) { - /* Log partners */ plt = &cur_lt->slaves_log[c_s]; - if (NULL != cur_lt->prev) - { - throughput_send_slave = plt->total_bytes_sent - cur_lt->prev->slaves_log[c_s].total_bytes_sent; - throughput_recv_slave = plt->total_bytes_received - cur_lt->prev->slaves_log[c_s].total_bytes_received; - } - else - { - throughput_send_slave = plt->total_bytes_sent; - throughput_recv_slave = plt->total_bytes_received; - } - throughput_send_slave *= mult; - throughput_recv_slave *= mult; + /* Log partners */ + /* Assembling slave string */ GNUNET_log(GNUNET_ERROR_TYPE_INFO, - "\t Slave [%u]: %u %u %u ; %u %u %u rtt %u delay %u \n", plt->slave->no, - plt->total_messages_sent, plt->total_bytes_sent, throughput_send_slave, - plt->total_messages_received, plt->total_bytes_received, throughput_recv_slave, - plt->app_rtt, plt->ats_delay); - - - GNUNET_asprintf(&slave_string_tmp, "%s%u;%u;%u;%u;%u;%u;%.3f;",slave_string, - plt->total_messages_sent, plt->total_bytes_sent, throughput_send_slave, - plt->total_messages_received, plt->total_bytes_received, throughput_recv_slave, - (double) plt->app_rtt / 1000); + "\t Slave [%u]: %u %u %u ; %u %u %u rtt %u delay %u bw_in %u bw_out %u \n", plt->slave->no, + plt->total_messages_sent, plt->total_bytes_sent, plt->throughput_sent, + plt->total_messages_received, plt->total_bytes_received, plt->throughput_recv, + plt->app_rtt, plt->ats_delay, + plt->bandwidth_in, plt->bandwidth_out); + + GNUNET_asprintf(&slave_string_tmp, "%s%u;%u;%u;%u;%u;%u;%.3f;%u;%u;%u;%u;%u;%u;%u;%u;%u;%u;",slave_string, + plt->total_messages_sent, plt->total_bytes_sent, plt->throughput_sent, + plt->total_messages_received, plt->total_bytes_received, plt->throughput_sent, + (double) plt->app_rtt / 1000, + plt->bandwidth_in,plt->bandwidth_out, + plt->ats_cost_lan, plt->ats_cost_wan, plt->ats_cost_wlan, + plt->ats_delay, plt->ats_distance, plt->ats_network_type, + plt->ats_utilization_up, plt->ats_utilization_down); GNUNET_free (slave_string); slave_string = slave_string_tmp; } /* Assembling master string */ - GNUNET_asprintf (&data, "%llu;%llu;%u;%u;%u;%u;%u;%u;%s\n", + + + + GNUNET_asprintf (&data, "%llu;%llu;%u;%u;%u;%u;%u;%u;;;;;;;;;;;%s\n", cur_lt->timestamp, GNUNET_TIME_absolute_get_difference(lp[c_m].start,cur_lt->timestamp).rel_value_us / 1000, - cur_lt->total_messages_sent, cur_lt->total_bytes_sent, throughput_send, - cur_lt->total_messages_received, cur_lt->total_bytes_received, throughput_recv, + cur_lt->total_messages_sent, cur_lt->total_bytes_sent, cur_lt->total_throughput_send, + cur_lt->total_messages_received, cur_lt->total_bytes_received, cur_lt->total_throughput_recv, slave_string); GNUNET_free (slave_string); @@ -456,6 +484,7 @@ write_to_file () write_throughput_gnuplot_script (filename, lp); write_rtt_gnuplot_script (filename, lp); + write_bw_gnuplot_script (filename, lp); GNUNET_log (GNUNET_ERROR_TYPE_INFO, "Data file successfully written to log file `%s'\n", filename); GNUNET_free (filename); @@ -468,12 +497,15 @@ collect_log_now (void) { struct LoggingPeer *bp; struct PeerLoggingTimestep *mlt; + struct PeerLoggingTimestep *prev_log_mlt; struct PartnerLoggingTimestep *slt; struct PartnerLoggingTimestep *prev_log_slt; struct BenchmarkPartner *p; + struct GNUNET_TIME_Relative delta; int c_s; int c_m; unsigned int app_rtt; + double mult; if (GNUNET_YES != running) return; @@ -481,8 +513,9 @@ collect_log_now (void) for (c_m = 0; c_m < num_peers; c_m++) { bp = &lp[c_m]; - mlt = GNUNET_malloc (sizeof (struct PeerLoggingTimestep)); + mlt = GNUNET_new (struct PeerLoggingTimestep); GNUNET_CONTAINER_DLL_insert_tail(bp->head, bp->tail, mlt); + prev_log_mlt = mlt->prev; /* Collect data */ @@ -493,6 +526,40 @@ collect_log_now (void) mlt->total_bytes_received = bp->peer->total_bytes_received; mlt->total_messages_received = bp->peer->total_messages_received; + /* Throughput */ + if (NULL == prev_log_mlt) + { + /* Get difference to start */ + delta = GNUNET_TIME_absolute_get_difference (lp[c_m].start, mlt->timestamp); + } + else + { + /* Get difference to last timestep */ + delta = GNUNET_TIME_absolute_get_difference (mlt->prev->timestamp, mlt->timestamp); + } + + /* Multiplication factor for throughput calculation */ + mult = (1.0 * 1000 * 1000) / (delta.rel_value_us); + + /* Total throughput */ + if (NULL != prev_log_mlt) + { + if (mlt->total_bytes_sent - mlt->prev->total_bytes_sent > 0) + mlt->total_throughput_send = mult * (mlt->total_bytes_sent - mlt->prev->total_bytes_sent); + else + mlt->total_throughput_send = prev_log_mlt->total_throughput_send; /* no msgs send */ + + if (mlt->total_bytes_received - mlt->prev->total_bytes_received > 0) + mlt->total_throughput_recv = mult * (mlt->total_bytes_received - mlt->prev->total_bytes_received); + else + mlt->total_throughput_recv = prev_log_mlt->total_throughput_recv; /* no msgs received */ + } + else + { + mlt->total_throughput_send = mult * mlt->total_bytes_sent; + mlt->total_throughput_send = mult * mlt->total_bytes_received; + } + mlt->slaves_log = GNUNET_malloc (bp->peer->num_partners * sizeof (struct PartnerLoggingTimestep)); @@ -520,10 +587,11 @@ collect_log_now (void) slt->ats_network_type = p->ats_network_type; slt->ats_utilization_down = p->ats_utilization_down; slt->ats_utilization_up = p->ats_utilization_up; - + slt->bandwidth_in = p->bandwidth_in; + slt->bandwidth_out = p->bandwidth_out; /* Total application level rtt */ - if (NULL == mlt->prev) + if (NULL == prev_log_mlt) { if (0 != slt->total_messages_sent) app_rtt = slt->total_app_rtt / slt->total_messages_sent; @@ -532,7 +600,7 @@ collect_log_now (void) } else { - prev_log_slt = &mlt->prev->slaves_log[c_s]; + prev_log_slt = &prev_log_mlt->slaves_log[c_s]; if ((slt->total_messages_sent - prev_log_slt->total_messages_sent) > 0) app_rtt = (slt->total_app_rtt - prev_log_slt->total_app_rtt) / (slt->total_messages_sent - prev_log_slt->total_messages_sent); @@ -540,6 +608,27 @@ collect_log_now (void) app_rtt = prev_log_slt->app_rtt; /* No messages were */ } slt->app_rtt = app_rtt; + + /* Partner throughput */ + if (NULL != prev_log_mlt) + { + prev_log_slt = &prev_log_mlt->slaves_log[c_s]; + if (slt->total_bytes_sent - prev_log_slt->total_bytes_sent > 0) + slt->throughput_sent = mult * (slt->total_bytes_sent - prev_log_slt->total_bytes_sent); + else + slt->throughput_sent = prev_log_slt->throughput_sent; /* no msgs send */ + + if (slt->total_bytes_received - prev_log_slt->total_bytes_received > 0) + slt->throughput_recv = mult * (slt->total_bytes_received - prev_log_slt->total_bytes_received); + else + slt->throughput_recv = prev_log_slt->throughput_recv; /* no msgs received */ + } + else + { + slt->throughput_sent = mult * slt->total_bytes_sent; + slt->throughput_sent = mult * slt->total_bytes_received; + } + GNUNET_log(GNUNET_ERROR_TYPE_DEBUG, "Master [%u]: slave [%u]\n", bp->peer->no, p->dest->no); @@ -550,7 +639,7 @@ collect_log_now (void) static void collect_log_task (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc) { - log_task = GNUNET_SCHEDULER_NO_TASK; + log_task = NULL; collect_log_now(); @@ -572,9 +661,9 @@ perf_logging_stop () if (GNUNET_YES!= running) return; - if (GNUNET_SCHEDULER_NO_TASK != log_task) + if (NULL != log_task) GNUNET_SCHEDULER_cancel (log_task); - log_task = GNUNET_SCHEDULER_NO_TASK; + log_task = NULL; tc.reason = GNUNET_SCHEDULER_REASON_SHUTDOWN; collect_log_task (NULL, &tc);