diff options
Diffstat (limited to 'src/core/or/circuitstats.c')
-rw-r--r-- | src/core/or/circuitstats.c | 1952 |
1 files changed, 1952 insertions, 0 deletions
diff --git a/src/core/or/circuitstats.c b/src/core/or/circuitstats.c new file mode 100644 index 0000000000..d275399e97 --- /dev/null +++ b/src/core/or/circuitstats.c @@ -0,0 +1,1952 @@ +/* Copyright (c) 2001 Matej Pfajfar. + * Copyright (c) 2001-2004, Roger Dingledine. + * Copyright (c) 2004-2006, Roger Dingledine, Nick Mathewson. + * Copyright (c) 2007-2018, The Tor Project, Inc. */ +/* See LICENSE for licensing information */ + +/** + * \file circuitstats.c + * + * \brief Maintains and analyzes statistics about circuit built times, so we + * can tell how long we may need to wait for a fast circuit to be constructed. + * + * By keeping these statistics, a client learns when it should time out a slow + * circuit for being too slow, and when it should keep a circuit open in order + * to wait for it to complete. + * + * The information here is kept in a circuit_built_times_t structure, which is + * currently a singleton, but doesn't need to be. It's updated by calls to + * circuit_build_times_count_timeout() from circuituse.c, + * circuit_build_times_count_close() from circuituse.c, and + * circuit_build_times_add_time() from circuitbuild.c, and inspected by other + * calls into this module, mostly from circuitlist.c. Observations are + * persisted to disk via the or_state_t-related calls. + */ + +#define CIRCUITSTATS_PRIVATE + +#include "or/or.h" +#include "or/circuitbuild.h" +#include "or/circuitstats.h" +#include "or/config.h" +#include "or/confparse.h" +#include "or/control.h" +#include "lib/crypt_ops/crypto_rand.h" +#include "or/main.h" +#include "or/networkstatus.h" +#include "or/rendclient.h" +#include "or/rendservice.h" +#include "or/router.h" +#include "or/statefile.h" +#include "or/circuitlist.h" +#include "or/circuituse.h" +#include "lib/math/fp.h" +#include "lib/time/tvdiff.h" +#include "lib/encoding/confline.h" + +#include "or/crypt_path_st.h" +#include "or/origin_circuit_st.h" +#include "or/or_state_st.h" + +#undef log +#include <math.h> + +static void cbt_control_event_buildtimeout_set( + const circuit_build_times_t *cbt, + buildtimeout_set_event_t type); +static void circuit_build_times_scale_circ_counts(circuit_build_times_t *cbt); + +#define CBT_BIN_TO_MS(bin) ((bin)*CBT_BIN_WIDTH + (CBT_BIN_WIDTH/2)) + +/** Global list of circuit build times */ +// XXXX: Add this as a member for entry_guard_t instead of global? +// Then we could do per-guard statistics, as guards are likely to +// vary in their own latency. The downside of this is that guards +// can change frequently, so we'd be building a lot more circuits +// most likely. +static circuit_build_times_t circ_times; + +#ifdef TOR_UNIT_TESTS +/** If set, we're running the unit tests: we should avoid clobbering + * our state file or accessing get_options() or get_or_state() */ +static int unit_tests = 0; +#else +#define unit_tests 0 +#endif /* defined(TOR_UNIT_TESTS) */ + +/** Return a pointer to the data structure describing our current circuit + * build time history and computations. */ +const circuit_build_times_t * +get_circuit_build_times(void) +{ + return &circ_times; +} + +/** As get_circuit_build_times, but return a mutable pointer. */ +circuit_build_times_t * +get_circuit_build_times_mutable(void) +{ + return &circ_times; +} + +/** Return the time to wait before actually closing an under-construction, in + * milliseconds. */ +double +get_circuit_build_close_time_ms(void) +{ + return circ_times.close_ms; +} + +/** Return the time to wait before giving up on an under-construction circuit, + * in milliseconds. */ +double +get_circuit_build_timeout_ms(void) +{ + return circ_times.timeout_ms; +} + +/** + * This function decides if CBT learning should be disabled. It returns + * true if one or more of the following conditions are met: + * + * 1. If the cbtdisabled consensus parameter is set. + * 2. If the torrc option LearnCircuitBuildTimeout is false. + * 3. If we are a directory authority + * 4. If we fail to write circuit build time history to our state file. + * 5. If we are compiled or configured in Tor2web mode + * 6. If we are configured in Single Onion mode + */ +int +circuit_build_times_disabled(const or_options_t *options) +{ + return circuit_build_times_disabled_(options, 0); +} + +/** As circuit_build_times_disabled, but take options as an argument. */ +int +circuit_build_times_disabled_(const or_options_t *options, + int ignore_consensus) +{ + if (unit_tests) { + return 0; + } else { + int consensus_disabled = + ignore_consensus ? 0 : networkstatus_get_param(NULL, "cbtdisabled", + 0, 0, 1); + int config_disabled = !options->LearnCircuitBuildTimeout; + int dirauth_disabled = authdir_mode(options); + int state_disabled = did_last_state_file_write_fail() ? 1 : 0; + /* LearnCircuitBuildTimeout and Tor2web/Single Onion Services are + * incompatible in two ways: + * + * - LearnCircuitBuildTimeout results in a low CBT, which + * Single Onion use of one-hop intro and rendezvous circuits lowers + * much further, producing *far* too many timeouts. + * + * - The adaptive CBT code does not update its timeout estimate + * using build times for single-hop circuits. + * + * If we fix both of these issues someday, we should test + * these modes with LearnCircuitBuildTimeout on again. */ + int tor2web_disabled = rend_client_allow_non_anonymous_connection(options); + int single_onion_disabled = rend_service_allow_non_anonymous_connection( + options); + + if (consensus_disabled || config_disabled || dirauth_disabled || + state_disabled || tor2web_disabled || single_onion_disabled) { +#if 0 + log_debug(LD_CIRC, + "CircuitBuildTime learning is disabled. " + "Consensus=%d, Config=%d, AuthDir=%d, StateFile=%d", + consensus_disabled, config_disabled, dirauth_disabled, + state_disabled); +#endif /* 0 */ + return 1; + } else { +#if 0 + log_debug(LD_CIRC, + "CircuitBuildTime learning is not disabled. " + "Consensus=%d, Config=%d, AuthDir=%d, StateFile=%d", + consensus_disabled, config_disabled, dirauth_disabled, + state_disabled); +#endif /* 0 */ + return 0; + } + } +} + +/** + * Retrieve and bounds-check the cbtmaxtimeouts consensus parameter. + * + * Effect: When this many timeouts happen in the last 'cbtrecentcount' + * circuit attempts, the client should discard all of its history and + * begin learning a fresh timeout value. + */ +static int32_t +circuit_build_times_max_timeouts(void) +{ + int32_t cbt_maxtimeouts; + + cbt_maxtimeouts = networkstatus_get_param(NULL, "cbtmaxtimeouts", + CBT_DEFAULT_MAX_RECENT_TIMEOUT_COUNT, + CBT_MIN_MAX_RECENT_TIMEOUT_COUNT, + CBT_MAX_MAX_RECENT_TIMEOUT_COUNT); + + if (!(get_options()->LearnCircuitBuildTimeout)) { + log_debug(LD_BUG, + "circuit_build_times_max_timeouts() called, cbtmaxtimeouts is" + " %d", + cbt_maxtimeouts); + } + + return cbt_maxtimeouts; +} + +/** + * Retrieve and bounds-check the cbtnummodes consensus parameter. + * + * Effect: This value governs how many modes to use in the weighted + * average calculation of Pareto parameter Xm. A value of 3 introduces + * some bias (2-5% of CDF) under ideal conditions, but allows for better + * performance in the event that a client chooses guard nodes of radically + * different performance characteristics. + */ +static int32_t +circuit_build_times_default_num_xm_modes(void) +{ + int32_t num = networkstatus_get_param(NULL, "cbtnummodes", + CBT_DEFAULT_NUM_XM_MODES, + CBT_MIN_NUM_XM_MODES, + CBT_MAX_NUM_XM_MODES); + + if (!(get_options()->LearnCircuitBuildTimeout)) { + log_debug(LD_BUG, + "circuit_build_times_default_num_xm_modes() called, cbtnummodes" + " is %d", + num); + } + + return num; +} + +/** + * Retrieve and bounds-check the cbtmincircs consensus parameter. + * + * Effect: This is the minimum number of circuits to build before + * computing a timeout. + */ +static int32_t +circuit_build_times_min_circs_to_observe(void) +{ + int32_t num = networkstatus_get_param(NULL, "cbtmincircs", + CBT_DEFAULT_MIN_CIRCUITS_TO_OBSERVE, + CBT_MIN_MIN_CIRCUITS_TO_OBSERVE, + CBT_MAX_MIN_CIRCUITS_TO_OBSERVE); + + if (!(get_options()->LearnCircuitBuildTimeout)) { + log_debug(LD_BUG, + "circuit_build_times_min_circs_to_observe() called, cbtmincircs" + " is %d", + num); + } + + return num; +} + +/** Return true iff <b>cbt</b> has recorded enough build times that we + * want to start acting on the timeout it implies. */ +int +circuit_build_times_enough_to_compute(const circuit_build_times_t *cbt) +{ + return cbt->total_build_times >= circuit_build_times_min_circs_to_observe(); +} + +/** + * Retrieve and bounds-check the cbtquantile consensus parameter. + * + * Effect: This is the position on the quantile curve to use to set the + * timeout value. It is a percent (10-99). + */ +double +circuit_build_times_quantile_cutoff(void) +{ + int32_t num = networkstatus_get_param(NULL, "cbtquantile", + CBT_DEFAULT_QUANTILE_CUTOFF, + CBT_MIN_QUANTILE_CUTOFF, + CBT_MAX_QUANTILE_CUTOFF); + + if (!(get_options()->LearnCircuitBuildTimeout)) { + log_debug(LD_BUG, + "circuit_build_times_quantile_cutoff() called, cbtquantile" + " is %d", + num); + } + + return num/100.0; +} + +/** + * Retrieve and bounds-check the cbtclosequantile consensus parameter. + * + * Effect: This is the position on the quantile curve to use to set the + * timeout value to use to actually close circuits. It is a percent + * (0-99). + */ +static double +circuit_build_times_close_quantile(void) +{ + int32_t param; + /* Cast is safe - circuit_build_times_quantile_cutoff() is capped */ + int32_t min = (int)tor_lround(100*circuit_build_times_quantile_cutoff()); + param = networkstatus_get_param(NULL, "cbtclosequantile", + CBT_DEFAULT_CLOSE_QUANTILE, + CBT_MIN_CLOSE_QUANTILE, + CBT_MAX_CLOSE_QUANTILE); + + if (!(get_options()->LearnCircuitBuildTimeout)) { + log_debug(LD_BUG, + "circuit_build_times_close_quantile() called, cbtclosequantile" + " is %d", param); + } + + if (param < min) { + log_warn(LD_DIR, "Consensus parameter cbtclosequantile is " + "too small, raising to %d", min); + param = min; + } + return param / 100.0; +} + +/** + * Retrieve and bounds-check the cbttestfreq consensus parameter. + * + * Effect: Describes how often in seconds to build a test circuit to + * gather timeout values. Only applies if less than 'cbtmincircs' + * have been recorded. + */ +static int32_t +circuit_build_times_test_frequency(void) +{ + int32_t num = networkstatus_get_param(NULL, "cbttestfreq", + CBT_DEFAULT_TEST_FREQUENCY, + CBT_MIN_TEST_FREQUENCY, + CBT_MAX_TEST_FREQUENCY); + + if (!(get_options()->LearnCircuitBuildTimeout)) { + log_debug(LD_BUG, + "circuit_build_times_test_frequency() called, cbttestfreq is %d", + num); + } + + return num; +} + +/** + * Retrieve and bounds-check the cbtmintimeout consensus parameter. + * + * Effect: This is the minimum allowed timeout value in milliseconds. + * The minimum is to prevent rounding to 0 (we only check once + * per second). + */ +static int32_t +circuit_build_times_min_timeout(void) +{ + int32_t num = networkstatus_get_param(NULL, "cbtmintimeout", + CBT_DEFAULT_TIMEOUT_MIN_VALUE, + CBT_MIN_TIMEOUT_MIN_VALUE, + CBT_MAX_TIMEOUT_MIN_VALUE); + + if (!(get_options()->LearnCircuitBuildTimeout)) { + log_debug(LD_BUG, + "circuit_build_times_min_timeout() called, cbtmintimeout is %d", + num); + } + return num; +} + +/** + * Retrieve and bounds-check the cbtinitialtimeout consensus parameter. + * + * Effect: This is the timeout value to use before computing a timeout, + * in milliseconds. + */ +int32_t +circuit_build_times_initial_timeout(void) +{ + int32_t min = circuit_build_times_min_timeout(); + int32_t param = networkstatus_get_param(NULL, "cbtinitialtimeout", + CBT_DEFAULT_TIMEOUT_INITIAL_VALUE, + CBT_MIN_TIMEOUT_INITIAL_VALUE, + CBT_MAX_TIMEOUT_INITIAL_VALUE); + + if (!(get_options()->LearnCircuitBuildTimeout)) { + log_debug(LD_BUG, + "circuit_build_times_initial_timeout() called, " + "cbtinitialtimeout is %d", + param); + } + + if (param < min) { + log_warn(LD_DIR, "Consensus parameter cbtinitialtimeout is too small, " + "raising to %d", min); + param = min; + } + return param; +} + +/** + * Retrieve and bounds-check the cbtrecentcount consensus parameter. + * + * Effect: This is the number of circuit build times to keep track of + * for deciding if we hit cbtmaxtimeouts and need to reset our state + * and learn a new timeout. + */ +static int32_t +circuit_build_times_recent_circuit_count(networkstatus_t *ns) +{ + int32_t num; + num = networkstatus_get_param(ns, "cbtrecentcount", + CBT_DEFAULT_RECENT_CIRCUITS, + CBT_MIN_RECENT_CIRCUITS, + CBT_MAX_RECENT_CIRCUITS); + + if (!(get_options()->LearnCircuitBuildTimeout)) { + log_debug(LD_BUG, + "circuit_build_times_recent_circuit_count() called, " + "cbtrecentcount is %d", + num); + } + + return num; +} + +/** + * This function is called when we get a consensus update. + * + * It checks to see if we have changed any consensus parameters + * that require reallocation or discard of previous stats. + */ +void +circuit_build_times_new_consensus_params(circuit_build_times_t *cbt, + networkstatus_t *ns) +{ + int32_t num; + + /* + * First check if we're doing adaptive timeouts at all; nothing to + * update if we aren't. + */ + + if (!circuit_build_times_disabled(get_options())) { + num = circuit_build_times_recent_circuit_count(ns); + + if (num > 0) { + if (num != cbt->liveness.num_recent_circs) { + int8_t *recent_circs; + if (cbt->liveness.num_recent_circs > 0) { + log_notice(LD_CIRC, "The Tor Directory Consensus has changed how " + "many circuits we must track to detect network failures " + "from %d to %d.", cbt->liveness.num_recent_circs, num); + } else { + log_notice(LD_CIRC, "Upon receiving a consensus directory, " + "re-enabling circuit-based network failure detection."); + } + + tor_assert(cbt->liveness.timeouts_after_firsthop || + cbt->liveness.num_recent_circs == 0); + + /* + * Technically this is a circular array that we are reallocating + * and memcopying. However, since it only consists of either 1s + * or 0s, and is only used in a statistical test to determine when + * we should discard our history after a sufficient number of 1's + * have been reached, it is fine if order is not preserved or + * elements are lost. + * + * cbtrecentcount should only be changing in cases of severe network + * distress anyway, so memory correctness here is paramount over + * doing acrobatics to preserve the array. + */ + recent_circs = tor_calloc(num, sizeof(int8_t)); + if (cbt->liveness.timeouts_after_firsthop && + cbt->liveness.num_recent_circs > 0) { + memcpy(recent_circs, cbt->liveness.timeouts_after_firsthop, + sizeof(int8_t)*MIN(num, cbt->liveness.num_recent_circs)); + } + + // Adjust the index if it needs it. + if (num < cbt->liveness.num_recent_circs) { + cbt->liveness.after_firsthop_idx = MIN(num-1, + cbt->liveness.after_firsthop_idx); + } + + tor_free(cbt->liveness.timeouts_after_firsthop); + cbt->liveness.timeouts_after_firsthop = recent_circs; + cbt->liveness.num_recent_circs = num; + } + /* else no change, nothing to do */ + } else { /* num == 0 */ + /* + * Weird. This probably shouldn't happen, so log a warning, but try + * to do something sensible anyway. + */ + + log_warn(LD_CIRC, + "The cbtrecentcircs consensus parameter came back zero! " + "This disables adaptive timeouts since we can't keep track of " + "any recent circuits."); + + circuit_build_times_free_timeouts(cbt); + } + } else { + /* + * Adaptive timeouts are disabled; this might be because of the + * LearnCircuitBuildTimes config parameter, and hence permanent, or + * the cbtdisabled consensus parameter, so it may be a new condition. + * Treat it like getting num == 0 above and free the circuit history + * if we have any. + */ + + circuit_build_times_free_timeouts(cbt); + } +} + +/** + * Return the initial default or configured timeout in milliseconds + */ +static double +circuit_build_times_get_initial_timeout(void) +{ + double timeout; + const or_options_t *options = get_options(); + + /* + * Check if we have LearnCircuitBuildTimeout, and if we don't, + * always use CircuitBuildTimeout, no questions asked. + */ + if (!unit_tests && options->CircuitBuildTimeout) { + timeout = options->CircuitBuildTimeout*1000; + if (!circuit_build_times_disabled(options) && + timeout < circuit_build_times_min_timeout()) { + log_warn(LD_CIRC, "Config CircuitBuildTimeout too low. Setting to %ds", + circuit_build_times_min_timeout()/1000); + timeout = circuit_build_times_min_timeout(); + } + } else { + timeout = circuit_build_times_initial_timeout(); + } + + return timeout; +} + +/** + * Reset the build time state. + * + * Leave estimated parameters, timeout and network liveness intact + * for future use. + */ +STATIC void +circuit_build_times_reset(circuit_build_times_t *cbt) +{ + memset(cbt->circuit_build_times, 0, sizeof(cbt->circuit_build_times)); + cbt->total_build_times = 0; + cbt->build_times_idx = 0; + cbt->have_computed_timeout = 0; + + // Reset timeout and close counts + cbt->num_circ_succeeded = 0; + cbt->num_circ_closed = 0; + cbt->num_circ_timeouts = 0; +} + +/** + * Initialize the buildtimes structure for first use. + * + * Sets the initial timeout values based on either the config setting, + * the consensus param, or the default (CBT_DEFAULT_TIMEOUT_INITIAL_VALUE). + */ +void +circuit_build_times_init(circuit_build_times_t *cbt) +{ + memset(cbt, 0, sizeof(*cbt)); + /* + * Check if we really are using adaptive timeouts, and don't keep + * track of this stuff if not. + */ + if (!circuit_build_times_disabled(get_options())) { + cbt->liveness.num_recent_circs = + circuit_build_times_recent_circuit_count(NULL); + cbt->liveness.timeouts_after_firsthop = + tor_calloc(cbt->liveness.num_recent_circs, sizeof(int8_t)); + } else { + cbt->liveness.num_recent_circs = 0; + cbt->liveness.timeouts_after_firsthop = NULL; + } + cbt->close_ms = cbt->timeout_ms = circuit_build_times_get_initial_timeout(); + cbt_control_event_buildtimeout_set(cbt, BUILDTIMEOUT_SET_EVENT_RESET); +} + +/** + * Free the saved timeouts, if the cbtdisabled consensus parameter got turned + * on or something. + */ + +void +circuit_build_times_free_timeouts(circuit_build_times_t *cbt) +{ + if (!cbt) return; + + if (cbt->liveness.timeouts_after_firsthop) { + tor_free(cbt->liveness.timeouts_after_firsthop); + } + + cbt->liveness.num_recent_circs = 0; +} + +#if 0 +/** + * Rewind our build time history by n positions. + */ +static void +circuit_build_times_rewind_history(circuit_build_times_t *cbt, int n) +{ + int i = 0; + + cbt->build_times_idx -= n; + cbt->build_times_idx %= CBT_NCIRCUITS_TO_OBSERVE; + + for (i = 0; i < n; i++) { + cbt->circuit_build_times[(i+cbt->build_times_idx) + %CBT_NCIRCUITS_TO_OBSERVE]=0; + } + + if (cbt->total_build_times > n) { + cbt->total_build_times -= n; + } else { + cbt->total_build_times = 0; + } + + log_info(LD_CIRC, + "Rewound history by %d places. Current index: %d. " + "Total: %d", n, cbt->build_times_idx, cbt->total_build_times); +} +#endif /* 0 */ + +/** + * Mark this circuit as timed out, but change its purpose + * so that it continues to build, allowing us to measure + * its full build time. + */ +void +circuit_build_times_mark_circ_as_measurement_only(origin_circuit_t *circ) +{ + control_event_circuit_status(circ, + CIRC_EVENT_FAILED, + END_CIRC_REASON_TIMEOUT); + circuit_change_purpose(TO_CIRCUIT(circ), + CIRCUIT_PURPOSE_C_MEASURE_TIMEOUT); + /* Record this event to check for too many timeouts + * in a row. This function does not record a time value yet + * (we do that later); it only counts the fact that we did + * have a timeout. We also want to avoid double-counting + * already "relaxed" circuits, which are counted in + * circuit_expire_building(). */ + if (!circ->relaxed_timeout) { + int first_hop_succeeded = circ->cpath && + circ->cpath->state == CPATH_STATE_OPEN; + + circuit_build_times_count_timeout( + get_circuit_build_times_mutable(), + first_hop_succeeded); + } +} + +/** + * Perform the build time work that needs to be done when a circuit + * completes a hop. + * + * This function decides if we should record a circuit's build time + * in our histogram data and other statistics, and if so, records it. + * It also will mark circuits that have already timed out as + * measurement-only circuits, so they can continue to build but + * not get used. + * + * For this, we want to consider circuits that will eventually make + * it to the third hop. For circuits longer than 3 hops, we want to + * record their build time when they reach the third hop, but let + * them continue (and not count them later). For circuits that are + * exactly 3 hops, this will count them when they are completed. We + * do this so that CBT is always gathering statistics on circuits + * of the same length, regardless of their type. + */ +void +circuit_build_times_handle_completed_hop(origin_circuit_t *circ) +{ + struct timeval end; + long timediff; + + /* If circuit build times are disabled, let circuit_expire_building() + * handle it.. */ + if (circuit_build_times_disabled(get_options())) { + return; + } + + /* Is this a circuit for which the timeout applies in a straight-forward + * way? If so, handle it below. If not, just return (and let + * circuit_expire_building() eventually take care of it). + */ + if (!circuit_timeout_want_to_count_circ(circ)) { + return; + } + + tor_gettimeofday(&end); + timediff = tv_mdiff(&circ->base_.timestamp_began, &end); + + /* Check if we would have timed out already. If so, change the + * purpose here. But don't do any timeout handling here if there + * are no circuits opened yet. Save it for circuit_expire_building() + * (to allow it to handle timeout "relaxing" over there). */ + if (timediff > get_circuit_build_timeout_ms() && + circuit_any_opened_circuits_cached()) { + + /* Circuits are allowed to last longer for measurement. + * Switch their purpose and wait. */ + if (circ->base_.purpose != CIRCUIT_PURPOSE_C_MEASURE_TIMEOUT) { + log_info(LD_CIRC, + "Deciding to timeout circuit %"PRIu32"\n", + (circ->global_identifier)); + circuit_build_times_mark_circ_as_measurement_only(circ); + } + } + + /* If the circuit is built to exactly the DEFAULT_ROUTE_LEN, + * add it to our buildtimes. */ + if (circuit_get_cpath_opened_len(circ) == DEFAULT_ROUTE_LEN) { + /* If the circuit build time is much greater than we would have cut + * it off at, we probably had a suspend event along this codepath, + * and we should discard the value. + */ + if (timediff < 0 || + timediff > 2*get_circuit_build_close_time_ms()+1000) { + log_notice(LD_CIRC, "Strange value for circuit build time: %ldmsec. " + "Assuming clock jump. Purpose %d (%s)", timediff, + circ->base_.purpose, + circuit_purpose_to_string(circ->base_.purpose)); + } else { + /* Only count circuit times if the network is live */ + if (circuit_build_times_network_check_live( + get_circuit_build_times())) { + circuit_build_times_add_time(get_circuit_build_times_mutable(), + (build_time_t)timediff); + circuit_build_times_set_timeout(get_circuit_build_times_mutable()); + } + + if (circ->base_.purpose != CIRCUIT_PURPOSE_C_MEASURE_TIMEOUT) { + circuit_build_times_network_circ_success( + get_circuit_build_times_mutable()); + } + } + } +} + +/** + * Add a new build time value <b>time</b> to the set of build times. Time + * units are milliseconds. + * + * circuit_build_times <b>cbt</b> is a circular array, so loop around when + * array is full. + */ +int +circuit_build_times_add_time(circuit_build_times_t *cbt, build_time_t btime) +{ + if (btime <= 0 || btime > CBT_BUILD_TIME_MAX) { + log_warn(LD_BUG, "Circuit build time is too large (%u)." + "This is probably a bug.", btime); + tor_fragile_assert(); + return -1; + } + + log_debug(LD_CIRC, "Adding circuit build time %u", btime); + + cbt->circuit_build_times[cbt->build_times_idx] = btime; + cbt->build_times_idx = (cbt->build_times_idx + 1) % CBT_NCIRCUITS_TO_OBSERVE; + if (cbt->total_build_times < CBT_NCIRCUITS_TO_OBSERVE) + cbt->total_build_times++; + + if ((cbt->total_build_times % CBT_SAVE_STATE_EVERY) == 0) { + /* Save state every n circuit builds */ + if (!unit_tests && !get_options()->AvoidDiskWrites) + or_state_mark_dirty(get_or_state(), 0); + } + + return 0; +} + +/** + * Return maximum circuit build time + */ +static build_time_t +circuit_build_times_max(const circuit_build_times_t *cbt) +{ + int i = 0; + build_time_t max_build_time = 0; + for (i = 0; i < CBT_NCIRCUITS_TO_OBSERVE; i++) { + if (cbt->circuit_build_times[i] > max_build_time + && cbt->circuit_build_times[i] != CBT_BUILD_ABANDONED) + max_build_time = cbt->circuit_build_times[i]; + } + return max_build_time; +} + +#if 0 +/** Return minimum circuit build time */ +build_time_t +circuit_build_times_min(circuit_build_times_t *cbt) +{ + int i = 0; + build_time_t min_build_time = CBT_BUILD_TIME_MAX; + for (i = 0; i < CBT_NCIRCUITS_TO_OBSERVE; i++) { + if (cbt->circuit_build_times[i] && /* 0 <-> uninitialized */ + cbt->circuit_build_times[i] < min_build_time) + min_build_time = cbt->circuit_build_times[i]; + } + if (min_build_time == CBT_BUILD_TIME_MAX) { + log_warn(LD_CIRC, "No build times less than CBT_BUILD_TIME_MAX!"); + } + return min_build_time; +} +#endif /* 0 */ + +/** + * Calculate and return a histogram for the set of build times. + * + * Returns an allocated array of histrogram bins representing + * the frequency of index*CBT_BIN_WIDTH millisecond + * build times. Also outputs the number of bins in nbins. + * + * The return value must be freed by the caller. + */ +static uint32_t * +circuit_build_times_create_histogram(const circuit_build_times_t *cbt, + build_time_t *nbins) +{ + uint32_t *histogram; + build_time_t max_build_time = circuit_build_times_max(cbt); + int i, c; + + *nbins = 1 + (max_build_time / CBT_BIN_WIDTH); + histogram = tor_calloc(*nbins, sizeof(build_time_t)); + + // calculate histogram + for (i = 0; i < CBT_NCIRCUITS_TO_OBSERVE; i++) { + if (cbt->circuit_build_times[i] == 0 + || cbt->circuit_build_times[i] == CBT_BUILD_ABANDONED) + continue; /* 0 <-> uninitialized */ + + c = (cbt->circuit_build_times[i] / CBT_BIN_WIDTH); + histogram[c]++; + } + + return histogram; +} + +/** + * Return the Pareto start-of-curve parameter Xm. + * + * Because we are not a true Pareto curve, we compute this as the + * weighted average of the N most frequent build time bins. N is either + * 1 if we don't have enough circuit build time data collected, or + * determined by the consensus parameter cbtnummodes (default 3). + */ +static build_time_t +circuit_build_times_get_xm(circuit_build_times_t *cbt) +{ + build_time_t i, nbins; + build_time_t *nth_max_bin; + int32_t bin_counts=0; + build_time_t ret = 0; + uint32_t *histogram = circuit_build_times_create_histogram(cbt, &nbins); + int n=0; + int num_modes = circuit_build_times_default_num_xm_modes(); + + tor_assert(nbins > 0); + tor_assert(num_modes > 0); + + // Only use one mode if < 1000 buildtimes. Not enough data + // for multiple. + if (cbt->total_build_times < CBT_NCIRCUITS_TO_OBSERVE) + num_modes = 1; + + nth_max_bin = tor_calloc(num_modes, sizeof(build_time_t)); + + /* Determine the N most common build times */ + for (i = 0; i < nbins; i++) { + if (histogram[i] >= histogram[nth_max_bin[0]]) { + nth_max_bin[0] = i; + } + + for (n = 1; n < num_modes; n++) { + if (histogram[i] >= histogram[nth_max_bin[n]] && + (!histogram[nth_max_bin[n-1]] + || histogram[i] < histogram[nth_max_bin[n-1]])) { + nth_max_bin[n] = i; + } + } + } + + for (n = 0; n < num_modes; n++) { + bin_counts += histogram[nth_max_bin[n]]; + ret += CBT_BIN_TO_MS(nth_max_bin[n])*histogram[nth_max_bin[n]]; + log_info(LD_CIRC, "Xm mode #%d: %u %u", n, CBT_BIN_TO_MS(nth_max_bin[n]), + histogram[nth_max_bin[n]]); + } + + /* bin_counts can become zero if all of our last CBT_NCIRCUITS_TO_OBSERVE + * circuits were abandoned before they completed. This shouldn't happen, + * though. We should have reset/re-learned a lower timeout first. */ + if (bin_counts == 0) { + ret = 0; + log_warn(LD_CIRC, + "No valid circuit build time data out of %d times, %u modes, " + "have_timeout=%d, %lfms", cbt->total_build_times, num_modes, + cbt->have_computed_timeout, cbt->timeout_ms); + goto done; + } + + tor_assert(bin_counts > 0); + + ret /= bin_counts; + + done: + tor_free(histogram); + tor_free(nth_max_bin); + + return ret; +} + +/** + * Output a histogram of current circuit build times to + * the or_state_t state structure. + */ +void +circuit_build_times_update_state(const circuit_build_times_t *cbt, + or_state_t *state) +{ + uint32_t *histogram; + build_time_t i = 0; + build_time_t nbins = 0; + config_line_t **next, *line; + + histogram = circuit_build_times_create_histogram(cbt, &nbins); + // write to state + config_free_lines(state->BuildtimeHistogram); + next = &state->BuildtimeHistogram; + *next = NULL; + + state->TotalBuildTimes = cbt->total_build_times; + state->CircuitBuildAbandonedCount = 0; + + for (i = 0; i < CBT_NCIRCUITS_TO_OBSERVE; i++) { + if (cbt->circuit_build_times[i] == CBT_BUILD_ABANDONED) + state->CircuitBuildAbandonedCount++; + } + + for (i = 0; i < nbins; i++) { + // compress the histogram by skipping the blanks + if (histogram[i] == 0) continue; + *next = line = tor_malloc_zero(sizeof(config_line_t)); + line->key = tor_strdup("CircuitBuildTimeBin"); + tor_asprintf(&line->value, "%d %d", + CBT_BIN_TO_MS(i), histogram[i]); + next = &(line->next); + } + + if (!unit_tests) { + if (!get_options()->AvoidDiskWrites) + or_state_mark_dirty(get_or_state(), 0); + } + + tor_free(histogram); +} + +/** + * Shuffle the build times array. + * + * Adapted from http://en.wikipedia.org/wiki/Fisher-Yates_shuffle + */ +static void +circuit_build_times_shuffle_and_store_array(circuit_build_times_t *cbt, + build_time_t *raw_times, + uint32_t num_times) +{ + uint32_t n = num_times; + if (num_times > CBT_NCIRCUITS_TO_OBSERVE) { + log_notice(LD_CIRC, "The number of circuit times that this Tor version " + "uses to calculate build times is less than the number stored " + "in your state file. Decreasing the circuit time history from " + "%lu to %d.", (unsigned long)num_times, + CBT_NCIRCUITS_TO_OBSERVE); + } + + if (n > INT_MAX-1) { + log_warn(LD_CIRC, "For some insane reasons, you had %lu circuit build " + "observations in your state file. That's far too many; probably " + "there's a bug here.", (unsigned long)n); + n = INT_MAX-1; + } + + /* This code can only be run on a compact array */ + while (n-- > 1) { + int k = crypto_rand_int(n + 1); /* 0 <= k <= n. */ + build_time_t tmp = raw_times[k]; + raw_times[k] = raw_times[n]; + raw_times[n] = tmp; + } + + /* Since the times are now shuffled, take a random CBT_NCIRCUITS_TO_OBSERVE + * subset (ie the first CBT_NCIRCUITS_TO_OBSERVE values) */ + for (n = 0; n < MIN(num_times, CBT_NCIRCUITS_TO_OBSERVE); n++) { + circuit_build_times_add_time(cbt, raw_times[n]); + } +} + +/** + * Filter old synthetic timeouts that were created before the + * new right-censored Pareto calculation was deployed. + * + * Once all clients before 0.2.1.13-alpha are gone, this code + * will be unused. + */ +static int +circuit_build_times_filter_timeouts(circuit_build_times_t *cbt) +{ + int num_filtered=0, i=0; + double timeout_rate = 0; + build_time_t max_timeout = 0; + + timeout_rate = circuit_build_times_timeout_rate(cbt); + max_timeout = (build_time_t)cbt->close_ms; + + for (i = 0; i < CBT_NCIRCUITS_TO_OBSERVE; i++) { + if (cbt->circuit_build_times[i] > max_timeout) { + build_time_t replaced = cbt->circuit_build_times[i]; + num_filtered++; + cbt->circuit_build_times[i] = CBT_BUILD_ABANDONED; + + log_debug(LD_CIRC, "Replaced timeout %d with %d", replaced, + cbt->circuit_build_times[i]); + } + } + + log_info(LD_CIRC, + "We had %d timeouts out of %d build times, " + "and filtered %d above the max of %u", + (int)(cbt->total_build_times*timeout_rate), + cbt->total_build_times, num_filtered, max_timeout); + + return num_filtered; +} + +/** + * Load histogram from <b>state</b>, shuffling the resulting array + * after we do so. Use this result to estimate parameters and + * calculate the timeout. + * + * Return -1 on error. + */ +int +circuit_build_times_parse_state(circuit_build_times_t *cbt, + or_state_t *state) +{ + int tot_values = 0; + uint32_t loaded_cnt = 0, N = 0; + config_line_t *line; + int i; + build_time_t *loaded_times; + int err = 0; + circuit_build_times_init(cbt); + + if (circuit_build_times_disabled(get_options())) { + return 0; + } + + /* build_time_t 0 means uninitialized */ + loaded_times = tor_calloc(state->TotalBuildTimes, sizeof(build_time_t)); + + for (line = state->BuildtimeHistogram; line; line = line->next) { + smartlist_t *args = smartlist_new(); + smartlist_split_string(args, line->value, " ", + SPLIT_SKIP_SPACE|SPLIT_IGNORE_BLANK, 0); + if (smartlist_len(args) < 2) { + log_warn(LD_GENERAL, "Unable to parse circuit build times: " + "Too few arguments to CircuitBuildTime"); + err = 1; + SMARTLIST_FOREACH(args, char*, cp, tor_free(cp)); + smartlist_free(args); + break; + } else { + const char *ms_str = smartlist_get(args,0); + const char *count_str = smartlist_get(args,1); + uint32_t count, k; + build_time_t ms; + int ok; + ms = (build_time_t)tor_parse_ulong(ms_str, 10, 0, + CBT_BUILD_TIME_MAX, &ok, NULL); + if (!ok) { + log_warn(LD_GENERAL, "Unable to parse circuit build times: " + "Unparsable bin number"); + err = 1; + SMARTLIST_FOREACH(args, char*, cp, tor_free(cp)); + smartlist_free(args); + break; + } + count = (uint32_t)tor_parse_ulong(count_str, 10, 0, + UINT32_MAX, &ok, NULL); + if (!ok) { + log_warn(LD_GENERAL, "Unable to parse circuit build times: " + "Unparsable bin count"); + err = 1; + SMARTLIST_FOREACH(args, char*, cp, tor_free(cp)); + smartlist_free(args); + break; + } + + if (loaded_cnt+count+ (unsigned)state->CircuitBuildAbandonedCount + > (unsigned) state->TotalBuildTimes) { + log_warn(LD_CIRC, + "Too many build times in state file. " + "Stopping short before %d", + loaded_cnt+count); + SMARTLIST_FOREACH(args, char*, cp, tor_free(cp)); + smartlist_free(args); + break; + } + + for (k = 0; k < count; k++) { + loaded_times[loaded_cnt++] = ms; + } + N++; + SMARTLIST_FOREACH(args, char*, cp, tor_free(cp)); + smartlist_free(args); + } + } + + log_info(LD_CIRC, + "Adding %d timeouts.", state->CircuitBuildAbandonedCount); + for (i=0; i < state->CircuitBuildAbandonedCount; i++) { + loaded_times[loaded_cnt++] = CBT_BUILD_ABANDONED; + } + + if (loaded_cnt != (unsigned)state->TotalBuildTimes) { + log_warn(LD_CIRC, + "Corrupt state file? Build times count mismatch. " + "Read %d times, but file says %d", loaded_cnt, + state->TotalBuildTimes); + err = 1; + circuit_build_times_reset(cbt); + goto done; + } + + circuit_build_times_shuffle_and_store_array(cbt, loaded_times, loaded_cnt); + + /* Verify that we didn't overwrite any indexes */ + for (i=0; i < CBT_NCIRCUITS_TO_OBSERVE; i++) { + if (!cbt->circuit_build_times[i]) + break; + tot_values++; + } + log_info(LD_CIRC, + "Loaded %d/%d values from %d lines in circuit time histogram", + tot_values, cbt->total_build_times, N); + + if (cbt->total_build_times != tot_values + || cbt->total_build_times > CBT_NCIRCUITS_TO_OBSERVE) { + log_warn(LD_CIRC, + "Corrupt state file? Shuffled build times mismatch. " + "Read %d times, but file says %d", tot_values, + state->TotalBuildTimes); + err = 1; + circuit_build_times_reset(cbt); + goto done; + } + + circuit_build_times_set_timeout(cbt); + + if (!state->CircuitBuildAbandonedCount && cbt->total_build_times) { + circuit_build_times_filter_timeouts(cbt); + } + + done: + tor_free(loaded_times); + return err ? -1 : 0; +} + +/** + * Estimates the Xm and Alpha parameters using + * http://en.wikipedia.org/wiki/Pareto_distribution#Parameter_estimation + * + * The notable difference is that we use mode instead of min to estimate Xm. + * This is because our distribution is frechet-like. We claim this is + * an acceptable approximation because we are only concerned with the + * accuracy of the CDF of the tail. + */ +STATIC int +circuit_build_times_update_alpha(circuit_build_times_t *cbt) +{ + build_time_t *x=cbt->circuit_build_times; + double a = 0; + int n=0,i=0,abandoned_count=0; + build_time_t max_time=0; + + /* http://en.wikipedia.org/wiki/Pareto_distribution#Parameter_estimation */ + /* We sort of cheat here and make our samples slightly more pareto-like + * and less frechet-like. */ + cbt->Xm = circuit_build_times_get_xm(cbt); + + /* If Xm came back 0, then too many circuits were abandoned. */ + if (cbt->Xm == 0) + return 0; + + tor_assert(cbt->Xm > 0); + + for (i=0; i< CBT_NCIRCUITS_TO_OBSERVE; i++) { + if (!x[i]) { + continue; + } + + if (x[i] < cbt->Xm) { + a += tor_mathlog(cbt->Xm); + } else if (x[i] == CBT_BUILD_ABANDONED) { + abandoned_count++; + } else { + a += tor_mathlog(x[i]); + if (x[i] > max_time) + max_time = x[i]; + } + n++; + } + + /* + * We are erring and asserting here because this can only happen + * in codepaths other than startup. The startup state parsing code + * performs this same check, and resets state if it hits it. If we + * hit it at runtime, something serious has gone wrong. + */ + if (n!=cbt->total_build_times) { + log_err(LD_CIRC, "Discrepancy in build times count: %d vs %d", n, + cbt->total_build_times); + } + tor_assert(n==cbt->total_build_times); + + if (max_time <= 0) { + /* This can happen if Xm is actually the *maximum* value in the set. + * It can also happen if we've abandoned every single circuit somehow. + * In either case, tell the caller not to compute a new build timeout. */ + log_warn(LD_BUG, + "Could not determine largest build time (%d). " + "Xm is %dms and we've abandoned %d out of %d circuits.", max_time, + cbt->Xm, abandoned_count, n); + return 0; + } + + a += abandoned_count*tor_mathlog(max_time); + + a -= n*tor_mathlog(cbt->Xm); + // Estimator comes from Eq #4 in: + // "Bayesian estimation based on trimmed samples from Pareto populations" + // by Arturo J. Fernández. We are right-censored only. + a = (n-abandoned_count)/a; + + cbt->alpha = a; + + return 1; +} + +/** + * This is the Pareto Quantile Function. It calculates the point x + * in the distribution such that F(x) = quantile (ie quantile*100% + * of the mass of the density function is below x on the curve). + * + * We use it to calculate the timeout and also to generate synthetic + * values of time for circuits that timeout before completion. + * + * See http://en.wikipedia.org/wiki/Quantile_function, + * http://en.wikipedia.org/wiki/Inverse_transform_sampling and + * http://en.wikipedia.org/wiki/Pareto_distribution#Generating_a_ + * random_sample_from_Pareto_distribution + * That's right. I'll cite wikipedia all day long. + * + * Return value is in milliseconds, clamped to INT32_MAX. + */ +STATIC double +circuit_build_times_calculate_timeout(circuit_build_times_t *cbt, + double quantile) +{ + double ret; + tor_assert(quantile >= 0); + tor_assert(1.0-quantile > 0); + tor_assert(cbt->Xm > 0); + + /* If either alpha or p are 0, we would divide by zero, yielding an + * infinite (double) result; which would be clamped to INT32_MAX. + * Instead, initialise ret to INT32_MAX, and skip over these + * potentially illegal/trapping divides by zero. + */ + ret = INT32_MAX; + + if (cbt->alpha > 0) { + double p; + p = pow(1.0-quantile,1.0/cbt->alpha); + if (p > 0) { + ret = cbt->Xm/p; + } + } + + if (ret > INT32_MAX) { + ret = INT32_MAX; + } + tor_assert(ret > 0); + return ret; +} + +#ifdef TOR_UNIT_TESTS +/** Pareto CDF */ +double +circuit_build_times_cdf(circuit_build_times_t *cbt, double x) +{ + double ret; + tor_assert(cbt->Xm > 0); + ret = 1.0-pow(cbt->Xm/x,cbt->alpha); + tor_assert(0 <= ret && ret <= 1.0); + return ret; +} +#endif /* defined(TOR_UNIT_TESTS) */ + +#ifdef TOR_UNIT_TESTS +/** + * Generate a synthetic time using our distribution parameters. + * + * The return value will be within the [q_lo, q_hi) quantile points + * on the CDF. + */ +build_time_t +circuit_build_times_generate_sample(circuit_build_times_t *cbt, + double q_lo, double q_hi) +{ + double randval = crypto_rand_double(); + build_time_t ret; + double u; + + /* Generate between [q_lo, q_hi) */ + /*XXXX This is what nextafter is supposed to be for; we should use it on the + * platforms that support it. */ + q_hi -= 1.0/(INT32_MAX); + + tor_assert(q_lo >= 0); + tor_assert(q_hi < 1); + tor_assert(q_lo < q_hi); + + u = q_lo + (q_hi-q_lo)*randval; + + tor_assert(0 <= u && u < 1.0); + /* circuit_build_times_calculate_timeout returns <= INT32_MAX */ + ret = (build_time_t) + tor_lround(circuit_build_times_calculate_timeout(cbt, u)); + tor_assert(ret > 0); + return ret; +} +#endif /* defined(TOR_UNIT_TESTS) */ + +#ifdef TOR_UNIT_TESTS +/** + * Estimate an initial alpha parameter by solving the quantile + * function with a quantile point and a specific timeout value. + */ +void +circuit_build_times_initial_alpha(circuit_build_times_t *cbt, + double quantile, double timeout_ms) +{ + // Q(u) = Xm/((1-u)^(1/a)) + // Q(0.8) = Xm/((1-0.8))^(1/a)) = CircBuildTimeout + // CircBuildTimeout = Xm/((1-0.8))^(1/a)) + // CircBuildTimeout = Xm*((1-0.8))^(-1/a)) + // ln(CircBuildTimeout) = ln(Xm)+ln(((1-0.8)))*(-1/a) + // -ln(1-0.8)/(ln(CircBuildTimeout)-ln(Xm))=a + tor_assert(quantile >= 0); + tor_assert(cbt->Xm > 0); + cbt->alpha = tor_mathlog(1.0-quantile)/ + (tor_mathlog(cbt->Xm)-tor_mathlog(timeout_ms)); + tor_assert(cbt->alpha > 0); +} +#endif /* defined(TOR_UNIT_TESTS) */ + +/** + * Returns true if we need circuits to be built + */ +int +circuit_build_times_needs_circuits(const circuit_build_times_t *cbt) +{ + /* Return true if < MIN_CIRCUITS_TO_OBSERVE */ + return !circuit_build_times_enough_to_compute(cbt); +} + +/** + * Returns true if we should build a timeout test circuit + * right now. + */ +int +circuit_build_times_needs_circuits_now(const circuit_build_times_t *cbt) +{ + return circuit_build_times_needs_circuits(cbt) && + approx_time()-cbt->last_circ_at > circuit_build_times_test_frequency(); +} + +/** + * How long should we be unreachable before we think we need to check if + * our published IP address has changed. + */ +#define CIRCUIT_TIMEOUT_BEFORE_RECHECK_IP (60*3) + +/** + * Called to indicate that the network showed some signs of liveness, + * i.e. we received a cell. + * + * This is used by circuit_build_times_network_check_live() to decide + * if we should record the circuit build timeout or not. + * + * This function is called every time we receive a cell. Avoid + * syscalls, events, and other high-intensity work. + */ +void +circuit_build_times_network_is_live(circuit_build_times_t *cbt) +{ + time_t now = approx_time(); + if (cbt->liveness.nonlive_timeouts > 0) { + time_t time_since_live = now - cbt->liveness.network_last_live; + log_notice(LD_CIRC, + "Tor now sees network activity. Restoring circuit build " + "timeout recording. Network was down for %d seconds " + "during %d circuit attempts.", + (int)time_since_live, + cbt->liveness.nonlive_timeouts); + if (time_since_live > CIRCUIT_TIMEOUT_BEFORE_RECHECK_IP) + reschedule_descriptor_update_check(); + } + cbt->liveness.network_last_live = now; + cbt->liveness.nonlive_timeouts = 0; + + /* Tell control.c */ + control_event_network_liveness_update(1); +} + +/** + * Non-destructively scale all of our circuit success, timeout, and close + * counts down by a factor of two. Scaling in this way preserves the + * ratios between succeeded vs timed out vs closed circuits, so that + * our statistics don't change when we scale. + * + * This is used only in the rare event that we build more than + * INT32_MAX circuits. Since the num_circ_* variables are + * uint32_t, we won't even be close to overflowing them. + */ +void +circuit_build_times_scale_circ_counts(circuit_build_times_t *cbt) +{ + cbt->num_circ_succeeded /= 2; + cbt->num_circ_timeouts /= 2; + cbt->num_circ_closed /= 2; +} + +/** + * Called to indicate that we "completed" a circuit. Because this circuit + * succeeded, it doesn't count as a timeout-after-the-first-hop. + * + * (For the purposes of the cbt code, we consider a circuit "completed" if + * it has 3 hops, regardless of its final hop count. We do this because + * we're trying to answer the question, "how long should a circuit take to + * reach the 3-hop count".) + * + * This is used by circuit_build_times_network_check_changed() to determine + * if we had too many recent timeouts and need to reset our learned timeout + * to something higher. + */ +void +circuit_build_times_network_circ_success(circuit_build_times_t *cbt) +{ + // Count circuit success + cbt->num_circ_succeeded++; + + // If we're going to wrap int32, scale everything + if (cbt->num_circ_succeeded >= INT32_MAX) { + circuit_build_times_scale_circ_counts(cbt); + } + + /* Check for NULLness because we might not be using adaptive timeouts */ + if (cbt->liveness.timeouts_after_firsthop && + cbt->liveness.num_recent_circs > 0) { + cbt->liveness.timeouts_after_firsthop[cbt->liveness.after_firsthop_idx] + = 0; + cbt->liveness.after_firsthop_idx++; + cbt->liveness.after_firsthop_idx %= cbt->liveness.num_recent_circs; + } +} + +/** + * A circuit just timed out. If it failed after the first hop, record it + * in our history for later deciding if the network speed has changed. + * + * This is used by circuit_build_times_network_check_changed() to determine + * if we had too many recent timeouts and need to reset our learned timeout + * to something higher. + */ +static void +circuit_build_times_network_timeout(circuit_build_times_t *cbt, + int did_onehop) +{ + // Count circuit timeout + cbt->num_circ_timeouts++; + + // If we're going to wrap int32, scale everything + if (cbt->num_circ_timeouts >= INT32_MAX) { + circuit_build_times_scale_circ_counts(cbt); + } + + /* Check for NULLness because we might not be using adaptive timeouts */ + if (cbt->liveness.timeouts_after_firsthop && + cbt->liveness.num_recent_circs > 0) { + if (did_onehop) { + cbt->liveness.timeouts_after_firsthop[cbt->liveness.after_firsthop_idx] + = 1; + cbt->liveness.after_firsthop_idx++; + cbt->liveness.after_firsthop_idx %= cbt->liveness.num_recent_circs; + } + } +} + +/** + * A circuit was just forcibly closed. If there has been no recent network + * activity at all, but this circuit was launched back when we thought the + * network was live, increment the number of "nonlive" circuit timeouts. + * + * This is used by circuit_build_times_network_check_live() to decide + * if we should record the circuit build timeout or not. + */ +static void +circuit_build_times_network_close(circuit_build_times_t *cbt, + int did_onehop, time_t start_time) +{ + time_t now = time(NULL); + + // Count circuit close + cbt->num_circ_closed++; + + // If we're going to wrap int32, scale everything + if (cbt->num_circ_closed >= INT32_MAX) { + circuit_build_times_scale_circ_counts(cbt); + } + + /* + * Check if this is a timeout that was for a circuit that spent its + * entire existence during a time where we have had no network activity. + */ + if (cbt->liveness.network_last_live < start_time) { + if (did_onehop) { + char last_live_buf[ISO_TIME_LEN+1]; + char start_time_buf[ISO_TIME_LEN+1]; + char now_buf[ISO_TIME_LEN+1]; + format_local_iso_time(last_live_buf, cbt->liveness.network_last_live); + format_local_iso_time(start_time_buf, start_time); + format_local_iso_time(now_buf, now); + log_notice(LD_CIRC, + "A circuit somehow completed a hop while the network was " + "not live. The network was last live at %s, but the circuit " + "launched at %s. It's now %s. This could mean your clock " + "changed.", last_live_buf, start_time_buf, now_buf); + } + cbt->liveness.nonlive_timeouts++; + if (cbt->liveness.nonlive_timeouts == 1) { + log_notice(LD_CIRC, + "Tor has not observed any network activity for the past %d " + "seconds. Disabling circuit build timeout recording.", + (int)(now - cbt->liveness.network_last_live)); + + /* Tell control.c */ + control_event_network_liveness_update(0); + } else { + log_info(LD_CIRC, + "Got non-live timeout. Current count is: %d", + cbt->liveness.nonlive_timeouts); + } + } +} + +/** + * When the network is not live, we do not record circuit build times. + * + * The network is considered not live if there has been at least one + * circuit build that began and ended (had its close_ms measurement + * period expire) since we last received a cell. + * + * Also has the side effect of rewinding the circuit time history + * in the case of recent liveness changes. + */ +int +circuit_build_times_network_check_live(const circuit_build_times_t *cbt) +{ + if (cbt->liveness.nonlive_timeouts > 0) { + return 0; + } + + return 1; +} + +/** + * Returns true if we have seen more than MAX_RECENT_TIMEOUT_COUNT of + * the past RECENT_CIRCUITS time out after the first hop. Used to detect + * if the network connection has changed significantly, and if so, + * resets our circuit build timeout to the default. + * + * Also resets the entire timeout history in this case and causes us + * to restart the process of building test circuits and estimating a + * new timeout. + */ +STATIC int +circuit_build_times_network_check_changed(circuit_build_times_t *cbt) +{ + int total_build_times = cbt->total_build_times; + int timeout_count=0; + int i; + + if (cbt->liveness.timeouts_after_firsthop && + cbt->liveness.num_recent_circs > 0) { + /* how many of our recent circuits made it to the first hop but then + * timed out? */ + for (i = 0; i < cbt->liveness.num_recent_circs; i++) { + timeout_count += cbt->liveness.timeouts_after_firsthop[i]; + } + } + + /* If 80% of our recent circuits are timing out after the first hop, + * we need to re-estimate a new initial alpha and timeout. */ + if (timeout_count < circuit_build_times_max_timeouts()) { + return 0; + } + + circuit_build_times_reset(cbt); + if (cbt->liveness.timeouts_after_firsthop && + cbt->liveness.num_recent_circs > 0) { + memset(cbt->liveness.timeouts_after_firsthop, 0, + sizeof(*cbt->liveness.timeouts_after_firsthop)* + cbt->liveness.num_recent_circs); + } + cbt->liveness.after_firsthop_idx = 0; + +#define MAX_TIMEOUT ((int32_t) (INT32_MAX/2)) + /* Check to see if this has happened before. If so, double the timeout + * to give clients on abysmally bad network connections a shot at access */ + if (cbt->timeout_ms >= circuit_build_times_get_initial_timeout()) { + if (cbt->timeout_ms > MAX_TIMEOUT || cbt->close_ms > MAX_TIMEOUT) { + log_warn(LD_CIRC, "Insanely large circuit build timeout value. " + "(timeout = %fmsec, close = %fmsec)", + cbt->timeout_ms, cbt->close_ms); + } else { + cbt->timeout_ms *= 2; + cbt->close_ms *= 2; + } + } else { + cbt->close_ms = cbt->timeout_ms + = circuit_build_times_get_initial_timeout(); + } +#undef MAX_TIMEOUT + + cbt_control_event_buildtimeout_set(cbt, BUILDTIMEOUT_SET_EVENT_RESET); + + log_notice(LD_CIRC, + "Your network connection speed appears to have changed. Resetting " + "timeout to %lds after %d timeouts and %d buildtimes.", + tor_lround(cbt->timeout_ms/1000), timeout_count, + total_build_times); + + return 1; +} + +/** + * Count the number of timeouts in a set of cbt data. + */ +double +circuit_build_times_timeout_rate(const circuit_build_times_t *cbt) +{ + int i=0,timeouts=0; + for (i = 0; i < CBT_NCIRCUITS_TO_OBSERVE; i++) { + if (cbt->circuit_build_times[i] >= cbt->timeout_ms) { + timeouts++; + } + } + + if (!cbt->total_build_times) + return 0; + + return ((double)timeouts)/cbt->total_build_times; +} + +/** + * Count the number of closed circuits in a set of cbt data. + */ +double +circuit_build_times_close_rate(const circuit_build_times_t *cbt) +{ + int i=0,closed=0; + for (i = 0; i < CBT_NCIRCUITS_TO_OBSERVE; i++) { + if (cbt->circuit_build_times[i] == CBT_BUILD_ABANDONED) { + closed++; + } + } + + if (!cbt->total_build_times) + return 0; + + return ((double)closed)/cbt->total_build_times; +} + +/** + * Store a timeout as a synthetic value. + * + * Returns true if the store was successful and we should possibly + * update our timeout estimate. + */ +int +circuit_build_times_count_close(circuit_build_times_t *cbt, + int did_onehop, + time_t start_time) +{ + if (circuit_build_times_disabled(get_options())) { + cbt->close_ms = cbt->timeout_ms + = circuit_build_times_get_initial_timeout(); + return 0; + } + + /* Record this force-close to help determine if the network is dead */ + circuit_build_times_network_close(cbt, did_onehop, start_time); + + /* Only count timeouts if network is live.. */ + if (!circuit_build_times_network_check_live(cbt)) { + return 0; + } + + circuit_build_times_add_time(cbt, CBT_BUILD_ABANDONED); + return 1; +} + +/** + * Update timeout counts to determine if we need to expire + * our build time history due to excessive timeouts. + * + * We do not record any actual time values at this stage; + * we are only interested in recording the fact that a timeout + * happened. We record the time values via + * circuit_build_times_count_close() and circuit_build_times_add_time(). + */ +void +circuit_build_times_count_timeout(circuit_build_times_t *cbt, + int did_onehop) +{ + if (circuit_build_times_disabled(get_options())) { + cbt->close_ms = cbt->timeout_ms + = circuit_build_times_get_initial_timeout(); + return; + } + + /* Register the fact that a timeout just occurred. */ + circuit_build_times_network_timeout(cbt, did_onehop); + + /* If there are a ton of timeouts, we should reset + * the circuit build timeout. */ + circuit_build_times_network_check_changed(cbt); +} + +/** + * Estimate a new timeout based on history and set our timeout + * variable accordingly. + */ +static int +circuit_build_times_set_timeout_worker(circuit_build_times_t *cbt) +{ + build_time_t max_time; + if (!circuit_build_times_enough_to_compute(cbt)) + return 0; + + if (!circuit_build_times_update_alpha(cbt)) + return 0; + + cbt->timeout_ms = circuit_build_times_calculate_timeout(cbt, + circuit_build_times_quantile_cutoff()); + + cbt->close_ms = circuit_build_times_calculate_timeout(cbt, + circuit_build_times_close_quantile()); + + max_time = circuit_build_times_max(cbt); + + if (cbt->timeout_ms > max_time) { + log_info(LD_CIRC, + "Circuit build timeout of %dms is beyond the maximum build " + "time we have ever observed. Capping it to %dms.", + (int)cbt->timeout_ms, max_time); + cbt->timeout_ms = max_time; + } + + if (max_time < INT32_MAX/2 && cbt->close_ms > 2*max_time) { + log_info(LD_CIRC, + "Circuit build measurement period of %dms is more than twice " + "the maximum build time we have ever observed. Capping it to " + "%dms.", (int)cbt->close_ms, 2*max_time); + cbt->close_ms = 2*max_time; + } + + /* Sometimes really fast guard nodes give us such a steep curve + * that this ends up being not that much greater than timeout_ms. + * Make it be at least 1 min to handle this case. */ + cbt->close_ms = MAX(cbt->close_ms, circuit_build_times_initial_timeout()); + + cbt->have_computed_timeout = 1; + return 1; +} + +/** + * Exposed function to compute a new timeout. Dispatches events and + * also filters out extremely high timeout values. + */ +void +circuit_build_times_set_timeout(circuit_build_times_t *cbt) +{ + long prev_timeout = tor_lround(cbt->timeout_ms/1000); + double timeout_rate; + + /* + * Just return if we aren't using adaptive timeouts + */ + if (circuit_build_times_disabled(get_options())) + return; + + if (!circuit_build_times_set_timeout_worker(cbt)) + return; + + if (cbt->timeout_ms < circuit_build_times_min_timeout()) { + log_info(LD_CIRC, "Set buildtimeout to low value %fms. Setting to %dms", + cbt->timeout_ms, circuit_build_times_min_timeout()); + cbt->timeout_ms = circuit_build_times_min_timeout(); + if (cbt->close_ms < cbt->timeout_ms) { + /* This shouldn't happen because of MAX() in timeout_worker above, + * but doing it just in case */ + cbt->close_ms = circuit_build_times_initial_timeout(); + } + } + + cbt_control_event_buildtimeout_set(cbt, BUILDTIMEOUT_SET_EVENT_COMPUTED); + + timeout_rate = circuit_build_times_timeout_rate(cbt); + + if (prev_timeout > tor_lround(cbt->timeout_ms/1000)) { + log_info(LD_CIRC, + "Based on %d circuit times, it looks like we don't need to " + "wait so long for circuits to finish. We will now assume a " + "circuit is too slow to use after waiting %ld seconds.", + cbt->total_build_times, + tor_lround(cbt->timeout_ms/1000)); + log_info(LD_CIRC, + "Circuit timeout data: %fms, %fms, Xm: %d, a: %f, r: %f", + cbt->timeout_ms, cbt->close_ms, cbt->Xm, cbt->alpha, + timeout_rate); + } else if (prev_timeout < tor_lround(cbt->timeout_ms/1000)) { + log_info(LD_CIRC, + "Based on %d circuit times, it looks like we need to wait " + "longer for circuits to finish. We will now assume a " + "circuit is too slow to use after waiting %ld seconds.", + cbt->total_build_times, + tor_lround(cbt->timeout_ms/1000)); + log_info(LD_CIRC, + "Circuit timeout data: %fms, %fms, Xm: %d, a: %f, r: %f", + cbt->timeout_ms, cbt->close_ms, cbt->Xm, cbt->alpha, + timeout_rate); + } else { + log_info(LD_CIRC, + "Set circuit build timeout to %lds (%fms, %fms, Xm: %d, a: %f," + " r: %f) based on %d circuit times", + tor_lround(cbt->timeout_ms/1000), + cbt->timeout_ms, cbt->close_ms, cbt->Xm, cbt->alpha, timeout_rate, + cbt->total_build_times); + } +} + +#ifdef TOR_UNIT_TESTS +/** Make a note that we're running unit tests (rather than running Tor + * itself), so we avoid clobbering our state file. */ +void +circuitbuild_running_unit_tests(void) +{ + unit_tests = 1; +} +#endif /* defined(TOR_UNIT_TESTS) */ + +void +circuit_build_times_update_last_circ(circuit_build_times_t *cbt) +{ + cbt->last_circ_at = approx_time(); +} + +static void +cbt_control_event_buildtimeout_set(const circuit_build_times_t *cbt, + buildtimeout_set_event_t type) +{ + char *args = NULL; + double qnt; + double timeout_rate = 0.0; + double close_rate = 0.0; + + switch (type) { + case BUILDTIMEOUT_SET_EVENT_RESET: + case BUILDTIMEOUT_SET_EVENT_SUSPENDED: + case BUILDTIMEOUT_SET_EVENT_DISCARD: + qnt = 1.0; + break; + case BUILDTIMEOUT_SET_EVENT_COMPUTED: + case BUILDTIMEOUT_SET_EVENT_RESUME: + default: + qnt = circuit_build_times_quantile_cutoff(); + break; + } + + /* The timeout rate is the ratio of the timeout count over + * the total number of circuits attempted. The total number of + * circuits is (timeouts+succeeded), since every circuit + * either succeeds, or times out. "Closed" circuits are + * MEASURE_TIMEOUT circuits whose measurement period expired. + * All MEASURE_TIMEOUT circuits are counted in the timeouts stat + * before transitioning to MEASURE_TIMEOUT (in + * circuit_build_times_mark_circ_as_measurement_only()). + * MEASURE_TIMEOUT circuits that succeed are *not* counted as + * "succeeded". See circuit_build_times_handle_completed_hop(). + * + * We cast the denominator + * to promote it to double before the addition, to avoid int32 + * overflow. */ + const double total_circuits = + ((double)cbt->num_circ_timeouts) + cbt->num_circ_succeeded; + if (total_circuits >= 1.0) { + timeout_rate = cbt->num_circ_timeouts / total_circuits; + close_rate = cbt->num_circ_closed / total_circuits; + } + + tor_asprintf(&args, "TOTAL_TIMES=%lu " + "TIMEOUT_MS=%lu XM=%lu ALPHA=%f CUTOFF_QUANTILE=%f " + "TIMEOUT_RATE=%f CLOSE_MS=%lu CLOSE_RATE=%f", + (unsigned long)cbt->total_build_times, + (unsigned long)cbt->timeout_ms, + (unsigned long)cbt->Xm, cbt->alpha, qnt, + timeout_rate, + (unsigned long)cbt->close_ms, + close_rate); + + control_event_buildtimeout_set(type, args); + + tor_free(args); +} |