diff --git a/ChangeLog b/ChangeLog index cde48ba0fd..18ae52187a 100644 --- a/ChangeLog +++ b/ChangeLog @@ -21,6 +21,10 @@ Changes in version 0.2.2.1-alpha - 2009-??-?? transferred bytes per port to disk every 24 hours. To enable this, run configure with the --enable-exit-stats option, and set "ExitPortStatistics 1" in your torrc. + - Relays write statistics on how long cells spend in their circuit + queues to disk every 24 hours. To enable this, run configure with + the --enable-buffer-stats option, and set "CellStatistics 1" in your + torrc. o Minor bugfixes - Hidden service clients didn't use a cached service descriptor that diff --git a/configure.in b/configure.in index 844211588d..10b05aeffb 100644 --- a/configure.in +++ b/configure.in @@ -99,6 +99,13 @@ if test "$enable_geoip_stats" = "yes"; then AC_DEFINE(ENABLE_GEOIP_STATS, 1, [Defined if we try to collect per-country statistics]) fi +AC_ARG_ENABLE(buffer-stats, + AS_HELP_STRING(--enable-buffer-stats, enable code for relays to collect buffer statistics)) + +if test "$enable_buffer_stats" = "yes"; then + AC_DEFINE(ENABLE_BUFFER_STATS, 1, [Defined if we try to collect buffer statistics]) +fi + AC_ARG_ENABLE(gcc-warnings, AS_HELP_STRING(--enable-gcc-warnings, enable verbose warnings)) diff --git a/src/or/circuitlist.c b/src/or/circuitlist.c index 252eaf9f8e..5a20e7ebde 100644 --- a/src/or/circuitlist.c +++ b/src/or/circuitlist.c @@ -447,6 +447,11 @@ circuit_free(circuit_t *circ) rend_data_free(ocirc->rend_data); } else { or_circuit_t *ocirc = TO_OR_CIRCUIT(circ); +#ifdef ENABLE_BUFFER_STATS + /* Remember cell statistics for this circuit before deallocating. */ + if (get_options()->CellStatistics) + add_circ_to_buffer_stats(circ, time(NULL)); +#endif mem = ocirc; memlen = sizeof(or_circuit_t); tor_assert(circ->magic == OR_CIRCUIT_MAGIC); diff --git a/src/or/config.c b/src/or/config.c index f1fea13e58..f7a5745262 100644 --- a/src/or/config.c +++ b/src/or/config.c @@ -162,6 +162,7 @@ static config_var_t _option_vars[] = { V(BridgePassword, STRING, NULL), V(BridgeRecordUsageByCountry, BOOL, "1"), V(BridgeRelay, BOOL, "0"), + V(CellStatistics, BOOL, "0"), V(CircuitBuildTimeout, INTERVAL, "1 minute"), V(CircuitIdleTimeout, INTERVAL, "1 hour"), V(ClientDNSRejectInternalAddresses, BOOL,"1"), @@ -1394,6 +1395,16 @@ options_act(or_options_t *old_options) if (options->ExitPortStatistics) log_warn(LD_CONFIG, "ExitPortStatistics enabled, but Tor was built " "without port statistics support."); +#endif +#ifdef ENABLE_BUFFER_STATS + if (options->CellStatistics) + log_notice(LD_CONFIG, "Configured to measure cell statistics. Look " + "for the buffer-stats file that will first be written to " + "the data directory in 24 hours from now."); +#else + if (options->CellStatistics) + log_warn(LD_CONFIG, "CellStatistics enabled, but Tor was built " + "without cell statistics support."); #endif /* Check if we need to parse and add the EntryNodes config option. */ if (options->EntryNodes && diff --git a/src/or/main.c b/src/or/main.c index 97957a5791..4969212798 100644 --- a/src/or/main.c +++ b/src/or/main.c @@ -830,6 +830,9 @@ run_scheduled_events(time_t now) static time_t time_to_clean_caches = 0; static time_t time_to_recheck_bandwidth = 0; static time_t time_to_check_for_expired_networkstatus = 0; +#ifdef ENABLE_BUFFER_STATS + static time_t time_to_dump_buffer_stats = 0; +#endif static time_t time_to_retry_dns_init = 0; or_options_t *options = get_options(); int i; @@ -957,6 +960,14 @@ run_scheduled_events(time_t now) time_to_check_for_expired_networkstatus = now + CHECK_EXPIRED_NS_INTERVAL; } +#ifdef ENABLE_BUFFER_STATS + if (time_to_dump_buffer_stats < now) { + if (get_options()->CellStatistics && time_to_dump_buffer_stats) + dump_buffer_stats(); + time_to_dump_buffer_stats = now + DUMP_BUFFER_STATS_INTERVAL; + } +#endif + /* Remove old information from rephist and the rend cache. */ if (time_to_clean_caches < now) { rep_history_clean(now - options->RephistTrackTime); diff --git a/src/or/or.h b/src/or/or.h index 935ea523df..2954b125bd 100644 --- a/src/or/or.h +++ b/src/or/or.h @@ -23,6 +23,9 @@ #ifndef ENABLE_GEOIP_STATS #define ENABLE_GEOIP_STATS 1 #endif +#ifndef ENABLE_BUFFER_STATS +#define ENABLE_BUFFER_STATS 1 +#endif #endif #ifdef MS_WINDOWS @@ -833,6 +836,9 @@ typedef struct var_cell_t { typedef struct packed_cell_t { struct packed_cell_t *next; /**< Next cell queued on this circuit. */ char body[CELL_NETWORK_SIZE]; /**< Cell as packed for network. */ +#ifdef ENABLE_BUFFER_STATS + struct timeval packed_timeval; /**< When was this cell packed? */ +#endif } packed_cell_t; /** A queue of cells on a circuit, waiting to be added to the @@ -2072,6 +2078,17 @@ typedef struct or_circuit_t { /** True iff this circuit was made with a CREATE_FAST cell. */ unsigned int is_first_hop : 1; + +#ifdef ENABLE_BUFFER_STATS + /** Number of cells that were removed from circuit queue; reset every + * time when writing buffer stats to disk. */ + uint32_t processed_cells; + + /** Total time in milliseconds that cells spent in both app-ward and + * exit-ward queues of this circuit; reset every time when writing + * buffer stats to disk. */ + uint64_t total_cell_waiting_time; +#endif } or_circuit_t; /** Convert a circuit subtype to a circuit_t.*/ @@ -2478,6 +2495,9 @@ typedef struct { /** If true, the user wants us to collect statistics on port usage. */ int ExitPortStatistics; + /** If true, the user wants us to collect cell statistics. */ + int CellStatistics; + /** If true, do not believe anybody who tells us that a domain resolves * to an internal address, or that an internal address has a PTR mapping. * Helps avoid some cross-site attacks. */ @@ -4026,6 +4046,12 @@ void hs_usage_note_fetch_successful(const char *service_id, time_t now); void hs_usage_write_statistics_to_file(time_t now); void hs_usage_free_all(void); +#ifdef ENABLE_BUFFER_STATS +#define DUMP_BUFFER_STATS_INTERVAL (24*60*60) +void add_circ_to_buffer_stats(circuit_t *circ, time_t end_of_interval); +void dump_buffer_stats(void); +#endif + /********************************* rendclient.c ***************************/ void rend_client_introcirc_has_opened(origin_circuit_t *circ); diff --git a/src/or/relay.c b/src/or/relay.c index 3ce05c8858..e5ba6f4035 100644 --- a/src/or/relay.c +++ b/src/or/relay.c @@ -1592,7 +1592,13 @@ cell_queue_append(cell_queue_t *queue, packed_cell_t *cell) void cell_queue_append_packed_copy(cell_queue_t *queue, const cell_t *cell) { - cell_queue_append(queue, packed_cell_copy(cell)); + packed_cell_t *copy = packed_cell_copy(cell); +#ifdef ENABLE_BUFFER_STATS + /* Remember the exact time when this cell was put in the queue. */ + if (get_options()->CellStatistics) + tor_gettimeofday(©->packed_timeval); +#endif + cell_queue_append(queue, copy); } /** Remove and free every cell in queue. */ @@ -1801,6 +1807,19 @@ connection_or_flush_from_first_active_circuit(or_connection_t *conn, int max, packed_cell_t *cell = cell_queue_pop(queue); tor_assert(*next_circ_on_conn_p(circ,conn)); +#ifdef ENABLE_BUFFER_STATS + /* Calculate the exact time that this cell has spent in the queue. */ + if (get_options()->CellStatistics && !CIRCUIT_IS_ORIGIN(circ)) { + struct timeval flushed_from_queue; + uint32_t cell_waiting_time; + or_circuit_t *orcirc = TO_OR_CIRCUIT(circ); + tor_gettimeofday(&flushed_from_queue); + cell_waiting_time = (uint32_t) + (tv_udiff(&cell->packed_timeval, &flushed_from_queue) / 1000); + orcirc->total_cell_waiting_time += cell_waiting_time; + orcirc->processed_cells++; + } +#endif connection_write_to_buf(cell->body, CELL_NETWORK_SIZE, TO_CONN(conn)); packed_cell_free(cell); diff --git a/src/or/rephist.c b/src/or/rephist.c index f1f502cad2..a7f525e542 100644 --- a/src/or/rephist.c +++ b/src/or/rephist.c @@ -2576,3 +2576,174 @@ hs_usage_write_statistics_to_file(time_t now) tor_free(fname); } +/*** cell statistics ***/ + +#ifdef ENABLE_BUFFER_STATS +/** Start of the current buffer stats interval. */ +time_t start_of_buffer_stats_interval; + +typedef struct circ_buffer_stats_t { + uint32_t processed_cells; + double mean_num_cells_in_queue; + double mean_time_cells_in_queue; + uint32_t local_circ_id; +} circ_buffer_stats_t; + +/** Holds stats. */ +smartlist_t *circuits_for_buffer_stats = NULL; + +/** Remember cell statistics for circuit circ at time + * end_of_interval and reset cell counters in case the circuit + * remains open in the next measurement interval. */ +void +add_circ_to_buffer_stats(circuit_t *circ, time_t end_of_interval) +{ + circ_buffer_stats_t *stat; + time_t start_of_interval; + int interval_length; + or_circuit_t *orcirc; + if (CIRCUIT_IS_ORIGIN(circ)) + return; + orcirc = TO_OR_CIRCUIT(circ); + if (!orcirc->processed_cells) + return; + if (!circuits_for_buffer_stats) + circuits_for_buffer_stats = smartlist_create(); + start_of_interval = circ->timestamp_created > + start_of_buffer_stats_interval ? + circ->timestamp_created : + start_of_buffer_stats_interval; + interval_length = (int) (end_of_interval - start_of_interval); + stat = tor_malloc_zero(sizeof(circ_buffer_stats_t)); + stat->processed_cells = orcirc->processed_cells; + /* 1000.0 for s -> ms; 2.0 because of app-ward and exit-ward queues */ + stat->mean_num_cells_in_queue = interval_length == 0 ? 0.0 : + (double) orcirc->total_cell_waiting_time / + (double) interval_length / 1000.0 / 2.0; + stat->mean_time_cells_in_queue = + (double) orcirc->total_cell_waiting_time / + (double) orcirc->processed_cells; + smartlist_add(circuits_for_buffer_stats, stat); + orcirc->total_cell_waiting_time = 0; + orcirc->processed_cells = 0; +} + +/** Sorting helper: return -1, 1, or 0 based on comparison of two + * circ_buffer_stats_t */ +static int +_buffer_stats_compare_entries(const void **_a, const void **_b) +{ + const circ_buffer_stats_t *a = *_a, *b = *_b; + if (a->processed_cells < b->processed_cells) + return 1; + else if (a->processed_cells > b->processed_cells) + return -1; + else + return 0; +} + +/** Append buffer statistics to local file. */ +void +dump_buffer_stats(void) +{ + time_t now = time(NULL); + char *filename; + char written[ISO_TIME_LEN+1]; + open_file_t *open_file = NULL; + FILE *out; +#define SHARES 10 + int processed_cells[SHARES], circs_in_share[SHARES], + number_of_circuits, i; + double queued_cells[SHARES], time_in_queue[SHARES]; + smartlist_t *str_build = smartlist_create(); + char *str = NULL; + char buf[32]; + circuit_t *circ; + /* add current circuits to stats */ + for (circ = _circuit_get_global_list(); circ; circ = circ->next) + add_circ_to_buffer_stats(circ, now); + /* calculate deciles */ + memset(processed_cells, 0, SHARES * sizeof(int)); + memset(circs_in_share, 0, SHARES * sizeof(int)); + memset(queued_cells, 0, SHARES * sizeof(double)); + memset(time_in_queue, 0, SHARES * sizeof(double)); + smartlist_sort(circuits_for_buffer_stats, + _buffer_stats_compare_entries); + number_of_circuits = smartlist_len(circuits_for_buffer_stats); + i = 0; + SMARTLIST_FOREACH_BEGIN(circuits_for_buffer_stats, + circ_buffer_stats_t *, stat) + { + int share = i++ * SHARES / number_of_circuits; + processed_cells[share] += stat->processed_cells; + queued_cells[share] += stat->mean_num_cells_in_queue; + time_in_queue[share] += stat->mean_time_cells_in_queue; + circs_in_share[share]++; + } + SMARTLIST_FOREACH_END(stat); + /* clear buffer stats history */ + SMARTLIST_FOREACH(circuits_for_buffer_stats, circ_buffer_stats_t *, + stat, tor_free(stat)); + smartlist_clear(circuits_for_buffer_stats); + /* write to file */ + filename = get_datadir_fname("buffer-stats"); + out = start_writing_to_stdio_file(filename, OPEN_FLAGS_APPEND, + 0600, &open_file); + if (!out) + goto done; + format_iso_time(written, now); + if (fprintf(out, "written %s (%d s)\n", written, + DUMP_BUFFER_STATS_INTERVAL) < 0) + goto done; + for (i = 0; i < SHARES; i++) { + tor_snprintf(buf, sizeof(buf), "%d", !circs_in_share[i] ? 0 : + processed_cells[i] / circs_in_share[i]); + smartlist_add(str_build, tor_strdup(buf)); + } + str = smartlist_join_strings(str_build, ",", 0, NULL); + if (fprintf(out, "processed-cells %s\n", str) < 0) + goto done; + tor_free(str); + SMARTLIST_FOREACH(str_build, char *, c, tor_free(c)); + smartlist_clear(str_build); + for (i = 0; i < SHARES; i++) { + tor_snprintf(buf, sizeof(buf), "%.2f", circs_in_share[i] == 0 ? 0.0 : + queued_cells[i] / (double) circs_in_share[i]); + smartlist_add(str_build, tor_strdup(buf)); + } + str = smartlist_join_strings(str_build, ",", 0, NULL); + if (fprintf(out, "queued-cells %s\n", str) < 0) + goto done; + tor_free(str); + SMARTLIST_FOREACH(str_build, char *, c, tor_free(c)); + smartlist_clear(str_build); + for (i = 0; i < SHARES; i++) { + tor_snprintf(buf, sizeof(buf), "%.0f", circs_in_share[i] == 0 ? 0.0 : + time_in_queue[i] / (double) circs_in_share[i]); + smartlist_add(str_build, tor_strdup(buf)); + } + str = smartlist_join_strings(str_build, ",", 0, NULL); + if (fprintf(out, "time-in-queue %s\n", str) < 0) + goto done; + tor_free(str); + SMARTLIST_FOREACH(str_build, char *, c, tor_free(c)); + smartlist_free(str_build); + str_build = NULL; + if (fprintf(out, "number-of-circuits-per-share %d\n", + (number_of_circuits + SHARES - 1) / SHARES) < 0) + goto done; + finish_writing_to_file(open_file); + open_file = NULL; + done: + if (open_file) + abort_writing_to_file(open_file); + tor_free(filename); + if (str_build) { + SMARTLIST_FOREACH(str_build, char *, c, tor_free(c)); + smartlist_free(str_build); + } + tor_free(str); +#undef SHARES +} +#endif +