1 /* Copyright (c) 2001 Matej Pfajfar.
2 * Copyright (c) 2001-2004, Roger Dingledine.
3 * Copyright (c) 2004-2006, Roger Dingledine, Nick Mathewson.
4 * Copyright (c) 2007-2019, The Tor Project, Inc. */
5 /* See LICENSE for licensing information */
10 * \brief Maintains and analyzes statistics about circuit built times, so we
11 * can tell how long we may need to wait for a fast circuit to be constructed.
13 * By keeping these statistics, a client learns when it should time out a slow
14 * circuit for being too slow, and when it should keep a circuit open in order
15 * to wait for it to complete.
17 * The information here is kept in a circuit_built_times_t structure, which is
18 * currently a singleton, but doesn't need to be. It's updated by calls to
19 * circuit_build_times_count_timeout() from circuituse.c,
20 * circuit_build_times_count_close() from circuituse.c, and
21 * circuit_build_times_add_time() from circuitbuild.c, and inspected by other
22 * calls into this module, mostly from circuitlist.c. Observations are
23 * persisted to disk via the or_state_t-related calls.
26 #define CIRCUITSTATS_PRIVATE
28 #include "core/or/or.h"
29 #include "core/or/circuitbuild.h"
30 #include "core/or/circuitstats.h"
31 #include "app/config/config.h"
32 #include "app/config/confparse.h"
33 #include "feature/control/control.h"
34 #include "lib/crypt_ops/crypto_rand.h"
35 #include "core/mainloop/mainloop.h"
36 #include "feature/nodelist/networkstatus.h"
37 #include "feature/rend/rendclient.h"
38 #include "feature/rend/rendservice.h"
39 #include "feature/relay/router.h"
40 #include "app/config/statefile.h"
41 #include "core/or/circuitlist.h"
42 #include "core/or/circuituse.h"
43 #include "lib/math/fp.h"
44 #include "lib/time/tvdiff.h"
45 #include "lib/encoding/confline.h"
46 #include "feature/dirauth/authmode.h"
48 #include "core/or/crypt_path_st.h"
49 #include "core/or/origin_circuit_st.h"
50 #include "app/config/or_state_st.h"
55 static void cbt_control_event_buildtimeout_set(
56 const circuit_build_times_t
*cbt
,
57 buildtimeout_set_event_t type
);
58 static void circuit_build_times_scale_circ_counts(circuit_build_times_t
*cbt
);
60 #define CBT_BIN_TO_MS(bin) ((bin)*CBT_BIN_WIDTH + (CBT_BIN_WIDTH/2))
62 /** Global list of circuit build times */
63 // XXXX: Add this as a member for entry_guard_t instead of global?
64 // Then we could do per-guard statistics, as guards are likely to
65 // vary in their own latency. The downside of this is that guards
66 // can change frequently, so we'd be building a lot more circuits
68 static circuit_build_times_t circ_times
;
71 /** If set, we're running the unit tests: we should avoid clobbering
72 * our state file or accessing get_options() or get_or_state() */
73 static int unit_tests
= 0;
76 #endif /* defined(TOR_UNIT_TESTS) */
78 /** Return a pointer to the data structure describing our current circuit
79 * build time history and computations. */
80 const circuit_build_times_t
*
81 get_circuit_build_times(void)
86 /** As get_circuit_build_times, but return a mutable pointer. */
87 circuit_build_times_t
*
88 get_circuit_build_times_mutable(void)
93 /** Return the time to wait before actually closing an under-construction, in
96 get_circuit_build_close_time_ms(void)
98 return circ_times
.close_ms
;
101 /** Return the time to wait before giving up on an under-construction circuit,
102 * in milliseconds. */
104 get_circuit_build_timeout_ms(void)
106 return circ_times
.timeout_ms
;
110 * This function decides if CBT learning should be disabled. It returns
111 * true if one or more of the following conditions are met:
113 * 1. If the cbtdisabled consensus parameter is set.
114 * 2. If the torrc option LearnCircuitBuildTimeout is false.
115 * 3. If we are a directory authority
116 * 4. If we fail to write circuit build time history to our state file.
117 * 5. If we are configured in Single Onion mode
120 circuit_build_times_disabled(const or_options_t
*options
)
122 return circuit_build_times_disabled_(options
, 0);
125 /** As circuit_build_times_disabled, but take options as an argument. */
127 circuit_build_times_disabled_(const or_options_t
*options
,
128 int ignore_consensus
)
133 int consensus_disabled
=
134 ignore_consensus
? 0 : networkstatus_get_param(NULL
, "cbtdisabled",
136 int config_disabled
= !options
->LearnCircuitBuildTimeout
;
137 int dirauth_disabled
= authdir_mode(options
);
138 int state_disabled
= did_last_state_file_write_fail() ? 1 : 0;
139 /* LearnCircuitBuildTimeout and Single Onion Services are
140 * incompatible in two ways:
142 * - LearnCircuitBuildTimeout results in a low CBT, which
143 * Single Onion use of one-hop intro and rendezvous circuits lowers
144 * much further, producing *far* too many timeouts.
146 * - The adaptive CBT code does not update its timeout estimate
147 * using build times for single-hop circuits.
149 * If we fix both of these issues someday, we should test
150 * these modes with LearnCircuitBuildTimeout on again. */
151 int single_onion_disabled
= rend_service_allow_non_anonymous_connection(
154 if (consensus_disabled
|| config_disabled
|| dirauth_disabled
||
155 state_disabled
|| single_onion_disabled
) {
158 "CircuitBuildTime learning is disabled. "
159 "Consensus=%d, Config=%d, AuthDir=%d, StateFile=%d",
160 consensus_disabled
, config_disabled
, dirauth_disabled
,
167 "CircuitBuildTime learning is not disabled. "
168 "Consensus=%d, Config=%d, AuthDir=%d, StateFile=%d",
169 consensus_disabled
, config_disabled
, dirauth_disabled
,
178 * Retrieve and bounds-check the cbtmaxtimeouts consensus parameter.
180 * Effect: When this many timeouts happen in the last 'cbtrecentcount'
181 * circuit attempts, the client should discard all of its history and
182 * begin learning a fresh timeout value.
185 circuit_build_times_max_timeouts(void)
187 int32_t cbt_maxtimeouts
;
189 cbt_maxtimeouts
= networkstatus_get_param(NULL
, "cbtmaxtimeouts",
190 CBT_DEFAULT_MAX_RECENT_TIMEOUT_COUNT
,
191 CBT_MIN_MAX_RECENT_TIMEOUT_COUNT
,
192 CBT_MAX_MAX_RECENT_TIMEOUT_COUNT
);
194 if (!(get_options()->LearnCircuitBuildTimeout
)) {
196 "circuit_build_times_max_timeouts() called, cbtmaxtimeouts is"
201 return cbt_maxtimeouts
;
205 * Retrieve and bounds-check the cbtnummodes consensus parameter.
207 * Effect: This value governs how many modes to use in the weighted
208 * average calculation of Pareto parameter Xm. Analysis of pairs of
209 * geographically near, far, and mixed guaeds has shown that a value of
210 * 10 introduces some allows for the actual timeout rate to be within
211 * 2-7% of the cutoff quantile, for quantiles between 60-80%.
214 circuit_build_times_default_num_xm_modes(void)
216 int32_t num
= networkstatus_get_param(NULL
, "cbtnummodes",
217 CBT_DEFAULT_NUM_XM_MODES
,
218 CBT_MIN_NUM_XM_MODES
,
219 CBT_MAX_NUM_XM_MODES
);
221 if (!(get_options()->LearnCircuitBuildTimeout
)) {
223 "circuit_build_times_default_num_xm_modes() called, cbtnummodes"
232 * Retrieve and bounds-check the cbtmincircs consensus parameter.
234 * Effect: This is the minimum number of circuits to build before
235 * computing a timeout.
238 circuit_build_times_min_circs_to_observe(void)
240 int32_t num
= networkstatus_get_param(NULL
, "cbtmincircs",
241 CBT_DEFAULT_MIN_CIRCUITS_TO_OBSERVE
,
242 CBT_MIN_MIN_CIRCUITS_TO_OBSERVE
,
243 CBT_MAX_MIN_CIRCUITS_TO_OBSERVE
);
245 if (!(get_options()->LearnCircuitBuildTimeout
)) {
247 "circuit_build_times_min_circs_to_observe() called, cbtmincircs"
255 /** Return true iff <b>cbt</b> has recorded enough build times that we
256 * want to start acting on the timeout it implies. */
258 circuit_build_times_enough_to_compute(const circuit_build_times_t
*cbt
)
260 return cbt
->total_build_times
>= circuit_build_times_min_circs_to_observe();
264 * Retrieve and bounds-check the cbtquantile consensus parameter.
266 * Effect: This is the position on the quantile curve to use to set the
267 * timeout value. It is a percent (10-99).
270 circuit_build_times_quantile_cutoff(void)
272 int32_t num
= networkstatus_get_param(NULL
, "cbtquantile",
273 CBT_DEFAULT_QUANTILE_CUTOFF
,
274 CBT_MIN_QUANTILE_CUTOFF
,
275 CBT_MAX_QUANTILE_CUTOFF
);
277 if (!(get_options()->LearnCircuitBuildTimeout
)) {
279 "circuit_build_times_quantile_cutoff() called, cbtquantile"
288 * Retrieve and bounds-check the cbtclosequantile consensus parameter.
290 * Effect: This is the position on the quantile curve to use to set the
291 * timeout value to use to actually close circuits. It is a percent
295 circuit_build_times_close_quantile(void)
298 /* Cast is safe - circuit_build_times_quantile_cutoff() is capped */
299 int32_t min
= (int)tor_lround(100*circuit_build_times_quantile_cutoff());
300 param
= networkstatus_get_param(NULL
, "cbtclosequantile",
301 CBT_DEFAULT_CLOSE_QUANTILE
,
302 CBT_MIN_CLOSE_QUANTILE
,
303 CBT_MAX_CLOSE_QUANTILE
);
305 if (!(get_options()->LearnCircuitBuildTimeout
)) {
307 "circuit_build_times_close_quantile() called, cbtclosequantile"
312 log_warn(LD_DIR
, "Consensus parameter cbtclosequantile is "
313 "too small, raising to %d", min
);
316 return param
/ 100.0;
320 * Retrieve and bounds-check the cbttestfreq consensus parameter.
322 * Effect: Describes how often in seconds to build a test circuit to
323 * gather timeout values. Only applies if less than 'cbtmincircs'
324 * have been recorded.
327 circuit_build_times_test_frequency(void)
329 int32_t num
= networkstatus_get_param(NULL
, "cbttestfreq",
330 CBT_DEFAULT_TEST_FREQUENCY
,
331 CBT_MIN_TEST_FREQUENCY
,
332 CBT_MAX_TEST_FREQUENCY
);
334 if (!(get_options()->LearnCircuitBuildTimeout
)) {
336 "circuit_build_times_test_frequency() called, cbttestfreq is %d",
344 * Retrieve and bounds-check the cbtmintimeout consensus parameter.
346 * Effect: This is the minimum allowed timeout value in milliseconds.
347 * The minimum is to prevent rounding to 0 (we only check once
351 circuit_build_times_min_timeout(void)
353 int32_t num
= networkstatus_get_param(NULL
, "cbtmintimeout",
354 CBT_DEFAULT_TIMEOUT_MIN_VALUE
,
355 CBT_MIN_TIMEOUT_MIN_VALUE
,
356 CBT_MAX_TIMEOUT_MIN_VALUE
);
358 if (!(get_options()->LearnCircuitBuildTimeout
)) {
360 "circuit_build_times_min_timeout() called, cbtmintimeout is %d",
367 * Retrieve and bounds-check the cbtinitialtimeout consensus parameter.
369 * Effect: This is the timeout value to use before computing a timeout,
373 circuit_build_times_initial_timeout(void)
375 int32_t min
= circuit_build_times_min_timeout();
376 int32_t param
= networkstatus_get_param(NULL
, "cbtinitialtimeout",
377 CBT_DEFAULT_TIMEOUT_INITIAL_VALUE
,
378 CBT_MIN_TIMEOUT_INITIAL_VALUE
,
379 CBT_MAX_TIMEOUT_INITIAL_VALUE
);
381 if (!(get_options()->LearnCircuitBuildTimeout
)) {
383 "circuit_build_times_initial_timeout() called, "
384 "cbtinitialtimeout is %d",
389 log_warn(LD_DIR
, "Consensus parameter cbtinitialtimeout is too small, "
390 "raising to %d", min
);
397 * Retrieve and bounds-check the cbtrecentcount consensus parameter.
399 * Effect: This is the number of circuit build times to keep track of
400 * for deciding if we hit cbtmaxtimeouts and need to reset our state
401 * and learn a new timeout.
404 circuit_build_times_recent_circuit_count(networkstatus_t
*ns
)
407 num
= networkstatus_get_param(ns
, "cbtrecentcount",
408 CBT_DEFAULT_RECENT_CIRCUITS
,
409 CBT_MIN_RECENT_CIRCUITS
,
410 CBT_MAX_RECENT_CIRCUITS
);
412 if (!(get_options()->LearnCircuitBuildTimeout
)) {
414 "circuit_build_times_recent_circuit_count() called, "
415 "cbtrecentcount is %d",
423 * This function is called when we get a consensus update.
425 * It checks to see if we have changed any consensus parameters
426 * that require reallocation or discard of previous stats.
429 circuit_build_times_new_consensus_params(circuit_build_times_t
*cbt
,
435 * First check if we're doing adaptive timeouts at all; nothing to
436 * update if we aren't.
439 if (!circuit_build_times_disabled(get_options())) {
440 num
= circuit_build_times_recent_circuit_count(ns
);
443 if (num
!= cbt
->liveness
.num_recent_circs
) {
444 int8_t *recent_circs
;
445 if (cbt
->liveness
.num_recent_circs
> 0) {
446 log_notice(LD_CIRC
, "The Tor Directory Consensus has changed how "
447 "many circuits we must track to detect network failures "
448 "from %d to %d.", cbt
->liveness
.num_recent_circs
, num
);
450 log_notice(LD_CIRC
, "Upon receiving a consensus directory, "
451 "re-enabling circuit-based network failure detection.");
454 tor_assert(cbt
->liveness
.timeouts_after_firsthop
||
455 cbt
->liveness
.num_recent_circs
== 0);
458 * Technically this is a circular array that we are reallocating
459 * and memcopying. However, since it only consists of either 1s
460 * or 0s, and is only used in a statistical test to determine when
461 * we should discard our history after a sufficient number of 1's
462 * have been reached, it is fine if order is not preserved or
465 * cbtrecentcount should only be changing in cases of severe network
466 * distress anyway, so memory correctness here is paramount over
467 * doing acrobatics to preserve the array.
469 recent_circs
= tor_calloc(num
, sizeof(int8_t));
470 if (cbt
->liveness
.timeouts_after_firsthop
&&
471 cbt
->liveness
.num_recent_circs
> 0) {
472 memcpy(recent_circs
, cbt
->liveness
.timeouts_after_firsthop
,
473 sizeof(int8_t)*MIN(num
, cbt
->liveness
.num_recent_circs
));
476 // Adjust the index if it needs it.
477 if (num
< cbt
->liveness
.num_recent_circs
) {
478 cbt
->liveness
.after_firsthop_idx
= MIN(num
-1,
479 cbt
->liveness
.after_firsthop_idx
);
482 tor_free(cbt
->liveness
.timeouts_after_firsthop
);
483 cbt
->liveness
.timeouts_after_firsthop
= recent_circs
;
484 cbt
->liveness
.num_recent_circs
= num
;
486 /* else no change, nothing to do */
487 } else { /* num == 0 */
489 * Weird. This probably shouldn't happen, so log a warning, but try
490 * to do something sensible anyway.
494 "The cbtrecentcircs consensus parameter came back zero! "
495 "This disables adaptive timeouts since we can't keep track of "
496 "any recent circuits.");
498 circuit_build_times_free_timeouts(cbt
);
502 * Adaptive timeouts are disabled; this might be because of the
503 * LearnCircuitBuildTimes config parameter, and hence permanent, or
504 * the cbtdisabled consensus parameter, so it may be a new condition.
505 * Treat it like getting num == 0 above and free the circuit history
509 circuit_build_times_free_timeouts(cbt
);
514 * Return the initial default or configured timeout in milliseconds
517 circuit_build_times_get_initial_timeout(void)
520 const or_options_t
*options
= get_options();
523 * Check if we have LearnCircuitBuildTimeout, and if we don't,
524 * always use CircuitBuildTimeout, no questions asked.
526 if (!unit_tests
&& options
->CircuitBuildTimeout
) {
527 timeout
= options
->CircuitBuildTimeout
*1000;
528 if (!circuit_build_times_disabled(options
) &&
529 timeout
< circuit_build_times_min_timeout()) {
530 log_warn(LD_CIRC
, "Config CircuitBuildTimeout too low. Setting to %ds",
531 circuit_build_times_min_timeout()/1000);
532 timeout
= circuit_build_times_min_timeout();
535 timeout
= circuit_build_times_initial_timeout();
542 * Reset the build time state.
544 * Leave estimated parameters, timeout and network liveness intact
548 circuit_build_times_reset(circuit_build_times_t
*cbt
)
550 memset(cbt
->circuit_build_times
, 0, sizeof(cbt
->circuit_build_times
));
551 cbt
->total_build_times
= 0;
552 cbt
->build_times_idx
= 0;
553 cbt
->have_computed_timeout
= 0;
555 // Reset timeout and close counts
556 cbt
->num_circ_succeeded
= 0;
557 cbt
->num_circ_closed
= 0;
558 cbt
->num_circ_timeouts
= 0;
562 * Initialize the buildtimes structure for first use.
564 * Sets the initial timeout values based on either the config setting,
565 * the consensus param, or the default (CBT_DEFAULT_TIMEOUT_INITIAL_VALUE).
568 circuit_build_times_init(circuit_build_times_t
*cbt
)
570 memset(cbt
, 0, sizeof(*cbt
));
572 * Check if we really are using adaptive timeouts, and don't keep
573 * track of this stuff if not.
575 if (!circuit_build_times_disabled(get_options())) {
576 cbt
->liveness
.num_recent_circs
=
577 circuit_build_times_recent_circuit_count(NULL
);
578 cbt
->liveness
.timeouts_after_firsthop
=
579 tor_calloc(cbt
->liveness
.num_recent_circs
, sizeof(int8_t));
581 cbt
->liveness
.num_recent_circs
= 0;
582 cbt
->liveness
.timeouts_after_firsthop
= NULL
;
584 cbt
->close_ms
= cbt
->timeout_ms
= circuit_build_times_get_initial_timeout();
585 cbt_control_event_buildtimeout_set(cbt
, BUILDTIMEOUT_SET_EVENT_RESET
);
589 * Free the saved timeouts, if the cbtdisabled consensus parameter got turned
594 circuit_build_times_free_timeouts(circuit_build_times_t
*cbt
)
598 if (cbt
->liveness
.timeouts_after_firsthop
) {
599 tor_free(cbt
->liveness
.timeouts_after_firsthop
);
602 cbt
->liveness
.num_recent_circs
= 0;
607 * Rewind our build time history by n positions.
610 circuit_build_times_rewind_history(circuit_build_times_t
*cbt
, int n
)
614 cbt
->build_times_idx
-= n
;
615 cbt
->build_times_idx
%= CBT_NCIRCUITS_TO_OBSERVE
;
617 for (i
= 0; i
< n
; i
++) {
618 cbt
->circuit_build_times
[(i
+cbt
->build_times_idx
)
619 %CBT_NCIRCUITS_TO_OBSERVE
]=0;
622 if (cbt
->total_build_times
> n
) {
623 cbt
->total_build_times
-= n
;
625 cbt
->total_build_times
= 0;
629 "Rewound history by %d places. Current index: %d. "
630 "Total: %d", n
, cbt
->build_times_idx
, cbt
->total_build_times
);
635 * Mark this circuit as timed out, but change its purpose
636 * so that it continues to build, allowing us to measure
637 * its full build time.
640 circuit_build_times_mark_circ_as_measurement_only(origin_circuit_t
*circ
)
642 control_event_circuit_status(circ
,
644 END_CIRC_REASON_TIMEOUT
);
645 circuit_change_purpose(TO_CIRCUIT(circ
),
646 CIRCUIT_PURPOSE_C_MEASURE_TIMEOUT
);
647 /* Record this event to check for too many timeouts
648 * in a row. This function does not record a time value yet
649 * (we do that later); it only counts the fact that we did
650 * have a timeout. We also want to avoid double-counting
651 * already "relaxed" circuits, which are counted in
652 * circuit_expire_building(). */
653 if (!circ
->relaxed_timeout
) {
654 int first_hop_succeeded
= circ
->cpath
&&
655 circ
->cpath
->state
== CPATH_STATE_OPEN
;
657 circuit_build_times_count_timeout(
658 get_circuit_build_times_mutable(),
659 first_hop_succeeded
);
664 * Perform the build time work that needs to be done when a circuit
667 * This function decides if we should record a circuit's build time
668 * in our histogram data and other statistics, and if so, records it.
669 * It also will mark circuits that have already timed out as
670 * measurement-only circuits, so they can continue to build but
673 * For this, we want to consider circuits that will eventually make
674 * it to the third hop. For circuits longer than 3 hops, we want to
675 * record their build time when they reach the third hop, but let
676 * them continue (and not count them later). For circuits that are
677 * exactly 3 hops, this will count them when they are completed. We
678 * do this so that CBT is always gathering statistics on circuits
679 * of the same length, regardless of their type.
682 circuit_build_times_handle_completed_hop(origin_circuit_t
*circ
)
687 /* If circuit build times are disabled, let circuit_expire_building()
689 if (circuit_build_times_disabled(get_options())) {
693 /* Is this a circuit for which the timeout applies in a straight-forward
694 * way? If so, handle it below. If not, just return (and let
695 * circuit_expire_building() eventually take care of it).
697 if (!circuit_timeout_want_to_count_circ(circ
)) {
701 tor_gettimeofday(&end
);
702 timediff
= tv_mdiff(&circ
->base_
.timestamp_began
, &end
);
704 /* Check if we would have timed out already. If so, change the
705 * purpose here. But don't do any timeout handling here if there
706 * are no circuits opened yet. Save it for circuit_expire_building()
707 * (to allow it to handle timeout "relaxing" over there). */
708 if (timediff
> get_circuit_build_timeout_ms() &&
709 circuit_any_opened_circuits_cached()) {
711 /* Circuits are allowed to last longer for measurement.
712 * Switch their purpose and wait. */
713 if (circ
->base_
.purpose
!= CIRCUIT_PURPOSE_C_MEASURE_TIMEOUT
) {
715 "Deciding to timeout circuit %"PRIu32
"\n",
716 (circ
->global_identifier
));
717 circuit_build_times_mark_circ_as_measurement_only(circ
);
721 /* If the circuit is built to exactly the DEFAULT_ROUTE_LEN,
722 * add it to our buildtimes. */
723 if (circuit_get_cpath_opened_len(circ
) == DEFAULT_ROUTE_LEN
) {
724 /* If the circuit build time is much greater than we would have cut
725 * it off at, we probably had a suspend event along this codepath,
726 * and we should discard the value.
729 timediff
> 2*get_circuit_build_close_time_ms()+1000) {
730 log_notice(LD_CIRC
, "Strange value for circuit build time: %ldmsec. "
731 "Assuming clock jump. Purpose %d (%s)", timediff
,
733 circuit_purpose_to_string(circ
->base_
.purpose
));
735 /* Only count circuit times if the network is live */
736 if (circuit_build_times_network_check_live(
737 get_circuit_build_times())) {
738 circuit_build_times_add_time(get_circuit_build_times_mutable(),
739 (build_time_t
)timediff
);
740 circuit_build_times_set_timeout(get_circuit_build_times_mutable());
743 if (circ
->base_
.purpose
!= CIRCUIT_PURPOSE_C_MEASURE_TIMEOUT
) {
744 circuit_build_times_network_circ_success(
745 get_circuit_build_times_mutable());
752 * Add a new build time value <b>time</b> to the set of build times. Time
753 * units are milliseconds.
755 * circuit_build_times <b>cbt</b> is a circular array, so loop around when
759 circuit_build_times_add_time(circuit_build_times_t
*cbt
, build_time_t btime
)
761 if (btime
<= 0 || btime
> CBT_BUILD_TIME_MAX
) {
762 log_warn(LD_BUG
, "Circuit build time is too large (%u)."
763 "This is probably a bug.", btime
);
764 tor_fragile_assert();
768 log_debug(LD_CIRC
, "Adding circuit build time %u", btime
);
770 cbt
->circuit_build_times
[cbt
->build_times_idx
] = btime
;
771 cbt
->build_times_idx
= (cbt
->build_times_idx
+ 1) % CBT_NCIRCUITS_TO_OBSERVE
;
772 if (cbt
->total_build_times
< CBT_NCIRCUITS_TO_OBSERVE
)
773 cbt
->total_build_times
++;
775 if ((cbt
->total_build_times
% CBT_SAVE_STATE_EVERY
) == 0) {
776 /* Save state every n circuit builds */
777 if (!unit_tests
&& !get_options()->AvoidDiskWrites
)
778 or_state_mark_dirty(get_or_state(), 0);
785 * Return maximum circuit build time
788 circuit_build_times_max(const circuit_build_times_t
*cbt
)
791 build_time_t max_build_time
= 0;
792 for (i
= 0; i
< CBT_NCIRCUITS_TO_OBSERVE
; i
++) {
793 if (cbt
->circuit_build_times
[i
] > max_build_time
794 && cbt
->circuit_build_times
[i
] != CBT_BUILD_ABANDONED
)
795 max_build_time
= cbt
->circuit_build_times
[i
];
797 return max_build_time
;
801 /** Return minimum circuit build time */
803 circuit_build_times_min(circuit_build_times_t
*cbt
)
806 build_time_t min_build_time
= CBT_BUILD_TIME_MAX
;
807 for (i
= 0; i
< CBT_NCIRCUITS_TO_OBSERVE
; i
++) {
808 if (cbt
->circuit_build_times
[i
] && /* 0 <-> uninitialized */
809 cbt
->circuit_build_times
[i
] < min_build_time
)
810 min_build_time
= cbt
->circuit_build_times
[i
];
812 if (min_build_time
== CBT_BUILD_TIME_MAX
) {
813 log_warn(LD_CIRC
, "No build times less than CBT_BUILD_TIME_MAX!");
815 return min_build_time
;
820 * Calculate and return a histogram for the set of build times.
822 * Returns an allocated array of histrogram bins representing
823 * the frequency of index*CBT_BIN_WIDTH millisecond
824 * build times. Also outputs the number of bins in nbins.
826 * The return value must be freed by the caller.
829 circuit_build_times_create_histogram(const circuit_build_times_t
*cbt
,
833 build_time_t max_build_time
= circuit_build_times_max(cbt
);
836 *nbins
= 1 + (max_build_time
/ CBT_BIN_WIDTH
);
837 histogram
= tor_calloc(*nbins
, sizeof(build_time_t
));
839 // calculate histogram
840 for (i
= 0; i
< CBT_NCIRCUITS_TO_OBSERVE
; i
++) {
841 if (cbt
->circuit_build_times
[i
] == 0
842 || cbt
->circuit_build_times
[i
] == CBT_BUILD_ABANDONED
)
843 continue; /* 0 <-> uninitialized */
845 c
= (cbt
->circuit_build_times
[i
] / CBT_BIN_WIDTH
);
853 * Return the Pareto start-of-curve parameter Xm.
855 * Because we are not a true Pareto curve, we compute this as the
856 * weighted average of the 10 most frequent build time bins. This
857 * heuristic allowed for the actual timeout rate to be closest
858 * to the chosen quantile cutoff, for quantiles 60-80%, out of
859 * many variant approaches (see #40157 for analysis).
862 circuit_build_times_get_xm(circuit_build_times_t
*cbt
)
864 build_time_t nbins
= 0;
865 build_time_t
*nth_max_bin
;
866 build_time_t xm_total
= 0;
869 int num_modes
= circuit_build_times_default_num_xm_modes();
870 uint32_t *histogram
= circuit_build_times_create_histogram(cbt
, &nbins
);
872 tor_assert(nbins
> 0);
873 tor_assert(num_modes
> 0);
875 nth_max_bin
= tor_calloc(num_modes
, sizeof(build_time_t
));
877 /* Determine the N most common build times, by selecting the
878 * nth largest mode, counting it, and removing it from the histogram. */
879 for (int n
= 0; n
< num_modes
; n
++) {
881 for (build_time_t i
= 0; i
< nbins
; i
++) {
882 if (histogram
[i
] > histogram
[nth_max_bin
[n
]]) {
888 xm_counts
+= histogram
[nth_max_bin
[n
]];
889 xm_total
+= CBT_BIN_TO_MS(nth_max_bin
[n
])*histogram
[nth_max_bin
[n
]];
891 /* Prevent from re-counting this value */
892 histogram
[nth_max_bin
[n
]] = 0;
895 /* xm_counts can become zero if all of our last CBT_NCIRCUITS_TO_OBSERVE
896 * circuits were abandoned before they completed. This shouldn't happen,
897 * though. We should have reset/re-learned a lower timeout first. */
898 if (xm_counts
== 0) {
900 "No valid circuit build time data out of %d times, %u modes, "
901 "have_timeout=%d, %lfms", cbt
->total_build_times
, num_modes
,
902 cbt
->have_computed_timeout
, cbt
->timeout_ms
);
906 Xm
= xm_total
/ xm_counts
;
910 tor_free(nth_max_bin
);
916 * Output a histogram of current circuit build times to
917 * the or_state_t state structure.
920 circuit_build_times_update_state(const circuit_build_times_t
*cbt
,
925 build_time_t nbins
= 0;
926 config_line_t
**next
, *line
;
928 histogram
= circuit_build_times_create_histogram(cbt
, &nbins
);
930 config_free_lines(state
->BuildtimeHistogram
);
931 next
= &state
->BuildtimeHistogram
;
934 state
->TotalBuildTimes
= cbt
->total_build_times
;
935 state
->CircuitBuildAbandonedCount
= 0;
937 for (i
= 0; i
< CBT_NCIRCUITS_TO_OBSERVE
; i
++) {
938 if (cbt
->circuit_build_times
[i
] == CBT_BUILD_ABANDONED
)
939 state
->CircuitBuildAbandonedCount
++;
942 for (i
= 0; i
< nbins
; i
++) {
943 // compress the histogram by skipping the blanks
944 if (histogram
[i
] == 0) continue;
945 *next
= line
= tor_malloc_zero(sizeof(config_line_t
));
946 line
->key
= tor_strdup("CircuitBuildTimeBin");
947 tor_asprintf(&line
->value
, "%d %d",
948 CBT_BIN_TO_MS(i
), histogram
[i
]);
949 next
= &(line
->next
);
953 if (!get_options()->AvoidDiskWrites
)
954 or_state_mark_dirty(get_or_state(), 0);
961 * Shuffle the build times array.
963 * Adapted from http://en.wikipedia.org/wiki/Fisher-Yates_shuffle
966 circuit_build_times_shuffle_and_store_array(circuit_build_times_t
*cbt
,
967 build_time_t
*raw_times
,
970 uint32_t n
= num_times
;
971 if (num_times
> CBT_NCIRCUITS_TO_OBSERVE
) {
972 log_notice(LD_CIRC
, "The number of circuit times that this Tor version "
973 "uses to calculate build times is less than the number stored "
974 "in your state file. Decreasing the circuit time history from "
975 "%lu to %d.", (unsigned long)num_times
,
976 CBT_NCIRCUITS_TO_OBSERVE
);
980 log_warn(LD_CIRC
, "For some insane reasons, you had %lu circuit build "
981 "observations in your state file. That's far too many; probably "
982 "there's a bug here.", (unsigned long)n
);
986 /* This code can only be run on a compact array */
988 int k
= crypto_rand_int(n
+ 1); /* 0 <= k <= n. */
989 build_time_t tmp
= raw_times
[k
];
990 raw_times
[k
] = raw_times
[n
];
994 /* Since the times are now shuffled, take a random CBT_NCIRCUITS_TO_OBSERVE
995 * subset (ie the first CBT_NCIRCUITS_TO_OBSERVE values) */
996 for (n
= 0; n
< MIN(num_times
, CBT_NCIRCUITS_TO_OBSERVE
); n
++) {
997 circuit_build_times_add_time(cbt
, raw_times
[n
]);
1002 * Load histogram from <b>state</b>, shuffling the resulting array
1003 * after we do so. Use this result to estimate parameters and
1004 * calculate the timeout.
1006 * Return -1 on error.
1009 circuit_build_times_parse_state(circuit_build_times_t
*cbt
,
1013 uint32_t loaded_cnt
= 0, N
= 0;
1014 config_line_t
*line
;
1016 build_time_t
*loaded_times
;
1018 circuit_build_times_init(cbt
);
1020 if (circuit_build_times_disabled(get_options())) {
1024 /* build_time_t 0 means uninitialized */
1025 loaded_times
= tor_calloc(state
->TotalBuildTimes
, sizeof(build_time_t
));
1027 for (line
= state
->BuildtimeHistogram
; line
; line
= line
->next
) {
1028 smartlist_t
*args
= smartlist_new();
1029 smartlist_split_string(args
, line
->value
, " ",
1030 SPLIT_SKIP_SPACE
|SPLIT_IGNORE_BLANK
, 0);
1031 if (smartlist_len(args
) < 2) {
1032 log_warn(LD_GENERAL
, "Unable to parse circuit build times: "
1033 "Too few arguments to CircuitBuildTime");
1035 SMARTLIST_FOREACH(args
, char*, cp
, tor_free(cp
));
1036 smartlist_free(args
);
1039 const char *ms_str
= smartlist_get(args
,0);
1040 const char *count_str
= smartlist_get(args
,1);
1044 ms
= (build_time_t
)tor_parse_ulong(ms_str
, 10, 0,
1045 CBT_BUILD_TIME_MAX
, &ok
, NULL
);
1047 log_warn(LD_GENERAL
, "Unable to parse circuit build times: "
1048 "Unparsable bin number");
1050 SMARTLIST_FOREACH(args
, char*, cp
, tor_free(cp
));
1051 smartlist_free(args
);
1054 count
= (uint32_t)tor_parse_ulong(count_str
, 10, 0,
1055 UINT32_MAX
, &ok
, NULL
);
1057 log_warn(LD_GENERAL
, "Unable to parse circuit build times: "
1058 "Unparsable bin count");
1060 SMARTLIST_FOREACH(args
, char*, cp
, tor_free(cp
));
1061 smartlist_free(args
);
1065 if (loaded_cnt
+count
+ (unsigned)state
->CircuitBuildAbandonedCount
1066 > (unsigned) state
->TotalBuildTimes
) {
1068 "Too many build times in state file. "
1069 "Stopping short before %d",
1071 SMARTLIST_FOREACH(args
, char*, cp
, tor_free(cp
));
1072 smartlist_free(args
);
1076 for (k
= 0; k
< count
; k
++) {
1077 loaded_times
[loaded_cnt
++] = ms
;
1080 SMARTLIST_FOREACH(args
, char*, cp
, tor_free(cp
));
1081 smartlist_free(args
);
1086 "Adding %d timeouts.", state
->CircuitBuildAbandonedCount
);
1087 for (i
=0; i
< state
->CircuitBuildAbandonedCount
; i
++) {
1088 loaded_times
[loaded_cnt
++] = CBT_BUILD_ABANDONED
;
1091 if (loaded_cnt
!= (unsigned)state
->TotalBuildTimes
) {
1093 "Corrupt state file? Build times count mismatch. "
1094 "Read %d times, but file says %d", loaded_cnt
,
1095 state
->TotalBuildTimes
);
1097 circuit_build_times_reset(cbt
);
1101 circuit_build_times_shuffle_and_store_array(cbt
, loaded_times
, loaded_cnt
);
1103 /* Verify that we didn't overwrite any indexes */
1104 for (i
=0; i
< CBT_NCIRCUITS_TO_OBSERVE
; i
++) {
1105 if (!cbt
->circuit_build_times
[i
])
1110 "Loaded %d/%d values from %d lines in circuit time histogram",
1111 tot_values
, cbt
->total_build_times
, N
);
1113 if (cbt
->total_build_times
!= tot_values
1114 || cbt
->total_build_times
> CBT_NCIRCUITS_TO_OBSERVE
) {
1116 "Corrupt state file? Shuffled build times mismatch. "
1117 "Read %d times, but file says %d", tot_values
,
1118 state
->TotalBuildTimes
);
1120 circuit_build_times_reset(cbt
);
1124 circuit_build_times_set_timeout(cbt
);
1127 tor_free(loaded_times
);
1128 return err
? -1 : 0;
1132 * Estimates the Xm and Alpha parameters using
1133 * http://en.wikipedia.org/wiki/Pareto_distribution#Parameter_estimation
1135 * The notable difference is that we use mode instead of min to estimate Xm.
1136 * This is because our distribution is frechet-like. We claim this is
1137 * an acceptable approximation because we are only concerned with the
1138 * accuracy of the CDF of the tail.
1141 circuit_build_times_update_alpha(circuit_build_times_t
*cbt
)
1143 build_time_t
*x
=cbt
->circuit_build_times
;
1145 int n
=0,i
=0,abandoned_count
=0;
1147 /* http://en.wikipedia.org/wiki/Pareto_distribution#Parameter_estimation */
1148 /* We sort of cheat here and make our samples slightly more pareto-like
1149 * and less frechet-like. */
1150 cbt
->Xm
= circuit_build_times_get_xm(cbt
);
1152 /* If Xm came back 0, then too many circuits were abandoned. */
1156 tor_assert(cbt
->Xm
> 0);
1158 for (i
=0; i
< CBT_NCIRCUITS_TO_OBSERVE
; i
++) {
1163 if (x
[i
] < cbt
->Xm
) {
1164 a
+= tor_mathlog(cbt
->Xm
);
1166 } else if (x
[i
] == CBT_BUILD_ABANDONED
) {
1169 a
+= tor_mathlog(x
[i
]);
1175 * We are erring and asserting here because this can only happen
1176 * in codepaths other than startup. The startup state parsing code
1177 * performs this same check, and resets state if it hits it. If we
1178 * hit it at runtime, something serious has gone wrong.
1180 if (n
!=cbt
->total_build_times
-abandoned_count
) {
1181 log_err(LD_CIRC
, "Discrepancy in build times count: %d vs %d", n
,
1182 cbt
->total_build_times
);
1184 tor_assert_nonfatal(n
==cbt
->total_build_times
-abandoned_count
);
1186 /* This is the "Maximum Likelihood Estimator" for parameter alpha of a Pareto
1187 * Distribution. See:
1188 * https://en.wikipedia.org/wiki/Pareto_distribution#Estimation_of_parameters
1190 * The division in the estimator is done with subtraction outside the ln(),
1191 * with the sum occurring in the for loop above.
1193 * This done is to avoid the precision issues of logs of small values.
1195 a
-= n
*tor_mathlog(cbt
->Xm
);
1204 * This is the Pareto Quantile Function. It calculates the point x
1205 * in the distribution such that F(x) = quantile (ie quantile*100%
1206 * of the mass of the density function is below x on the curve).
1208 * We use it to calculate the timeout and also to generate synthetic
1209 * values of time for circuits that timeout before completion.
1211 * See http://en.wikipedia.org/wiki/Quantile_function,
1212 * http://en.wikipedia.org/wiki/Inverse_transform_sampling and
1213 * http://en.wikipedia.org/wiki/Pareto_distribution#Generating_a_
1214 * random_sample_from_Pareto_distribution
1215 * That's right. I'll cite wikipedia all day long.
1217 * Return value is in milliseconds, clamped to INT32_MAX.
1220 circuit_build_times_calculate_timeout(circuit_build_times_t
*cbt
,
1224 tor_assert(quantile
>= 0);
1225 tor_assert(1.0-quantile
> 0);
1226 tor_assert(cbt
->Xm
> 0);
1228 /* If either alpha or p are 0, we would divide by zero, yielding an
1229 * infinite (double) result; which would be clamped to INT32_MAX.
1230 * Instead, initialise ret to INT32_MAX, and skip over these
1231 * potentially illegal/trapping divides by zero.
1235 if (cbt
->alpha
> 0) {
1237 p
= pow(1.0-quantile
,1.0/cbt
->alpha
);
1243 if (ret
> INT32_MAX
) {
1246 tor_assert(ret
> 0);
1250 #ifdef TOR_UNIT_TESTS
1253 circuit_build_times_cdf(circuit_build_times_t
*cbt
, double x
)
1256 tor_assert(cbt
->Xm
> 0);
1257 ret
= 1.0-pow(cbt
->Xm
/x
,cbt
->alpha
);
1258 tor_assert(0 <= ret
&& ret
<= 1.0);
1261 #endif /* defined(TOR_UNIT_TESTS) */
1263 #ifdef TOR_UNIT_TESTS
1265 * Generate a synthetic time using our distribution parameters.
1267 * The return value will be within the [q_lo, q_hi) quantile points
1271 circuit_build_times_generate_sample(circuit_build_times_t
*cbt
,
1272 double q_lo
, double q_hi
)
1274 double randval
= crypto_rand_double();
1278 /* Generate between [q_lo, q_hi) */
1279 /*XXXX This is what nextafter is supposed to be for; we should use it on the
1280 * platforms that support it. */
1281 q_hi
-= 1.0/(INT32_MAX
);
1283 tor_assert(q_lo
>= 0);
1284 tor_assert(q_hi
< 1);
1285 tor_assert(q_lo
< q_hi
);
1287 u
= q_lo
+ (q_hi
-q_lo
)*randval
;
1289 tor_assert(0 <= u
&& u
< 1.0);
1290 /* circuit_build_times_calculate_timeout returns <= INT32_MAX */
1291 ret
= (build_time_t
)
1292 tor_lround(circuit_build_times_calculate_timeout(cbt
, u
));
1293 tor_assert(ret
> 0);
1296 #endif /* defined(TOR_UNIT_TESTS) */
1298 #ifdef TOR_UNIT_TESTS
1300 * Estimate an initial alpha parameter by solving the quantile
1301 * function with a quantile point and a specific timeout value.
1304 circuit_build_times_initial_alpha(circuit_build_times_t
*cbt
,
1305 double quantile
, double timeout_ms
)
1307 // Q(u) = Xm/((1-u)^(1/a))
1308 // Q(0.8) = Xm/((1-0.8))^(1/a)) = CircBuildTimeout
1309 // CircBuildTimeout = Xm/((1-0.8))^(1/a))
1310 // CircBuildTimeout = Xm*((1-0.8))^(-1/a))
1311 // ln(CircBuildTimeout) = ln(Xm)+ln(((1-0.8)))*(-1/a)
1312 // -ln(1-0.8)/(ln(CircBuildTimeout)-ln(Xm))=a
1313 tor_assert(quantile
>= 0);
1314 tor_assert(cbt
->Xm
> 0);
1315 cbt
->alpha
= tor_mathlog(1.0-quantile
)/
1316 (tor_mathlog(cbt
->Xm
)-tor_mathlog(timeout_ms
));
1317 tor_assert(cbt
->alpha
> 0);
1319 #endif /* defined(TOR_UNIT_TESTS) */
1322 * Returns true if we need circuits to be built
1325 circuit_build_times_needs_circuits(const circuit_build_times_t
*cbt
)
1327 /* Return true if < MIN_CIRCUITS_TO_OBSERVE */
1328 return !circuit_build_times_enough_to_compute(cbt
);
1332 * Returns true if we should build a timeout test circuit
1336 circuit_build_times_needs_circuits_now(const circuit_build_times_t
*cbt
)
1338 return circuit_build_times_needs_circuits(cbt
) &&
1339 approx_time()-cbt
->last_circ_at
> circuit_build_times_test_frequency();
1343 * How long should we be unreachable before we think we need to check if
1344 * our published IP address has changed.
1346 #define CIRCUIT_TIMEOUT_BEFORE_RECHECK_IP (60*3)
1349 * Called to indicate that the network showed some signs of liveness,
1350 * i.e. we received a cell.
1352 * This is used by circuit_build_times_network_check_live() to decide
1353 * if we should record the circuit build timeout or not.
1355 * This function is called every time we receive a cell. Avoid
1356 * syscalls, events, and other high-intensity work.
1359 circuit_build_times_network_is_live(circuit_build_times_t
*cbt
)
1361 time_t now
= approx_time();
1362 if (cbt
->liveness
.nonlive_timeouts
> 0) {
1363 time_t time_since_live
= now
- cbt
->liveness
.network_last_live
;
1365 "Tor now sees network activity. Restoring circuit build "
1366 "timeout recording. Network was down for %d seconds "
1367 "during %d circuit attempts.",
1368 (int)time_since_live
,
1369 cbt
->liveness
.nonlive_timeouts
);
1370 if (time_since_live
> CIRCUIT_TIMEOUT_BEFORE_RECHECK_IP
)
1371 reschedule_descriptor_update_check();
1373 cbt
->liveness
.network_last_live
= now
;
1374 cbt
->liveness
.nonlive_timeouts
= 0;
1376 /* Tell control.c */
1377 control_event_network_liveness_update(1);
1381 * Non-destructively scale all of our circuit success, timeout, and close
1382 * counts down by a factor of two. Scaling in this way preserves the
1383 * ratios between succeeded vs timed out vs closed circuits, so that
1384 * our statistics don't change when we scale.
1386 * This is used only in the rare event that we build more than
1387 * INT32_MAX circuits. Since the num_circ_* variables are
1388 * uint32_t, we won't even be close to overflowing them.
1391 circuit_build_times_scale_circ_counts(circuit_build_times_t
*cbt
)
1393 cbt
->num_circ_succeeded
/= 2;
1394 cbt
->num_circ_timeouts
/= 2;
1395 cbt
->num_circ_closed
/= 2;
1399 * Called to indicate that we "completed" a circuit. Because this circuit
1400 * succeeded, it doesn't count as a timeout-after-the-first-hop.
1402 * (For the purposes of the cbt code, we consider a circuit "completed" if
1403 * it has 3 hops, regardless of its final hop count. We do this because
1404 * we're trying to answer the question, "how long should a circuit take to
1405 * reach the 3-hop count".)
1407 * This is used by circuit_build_times_network_check_changed() to determine
1408 * if we had too many recent timeouts and need to reset our learned timeout
1409 * to something higher.
1412 circuit_build_times_network_circ_success(circuit_build_times_t
*cbt
)
1414 // Count circuit success
1415 cbt
->num_circ_succeeded
++;
1417 // If we're going to wrap int32, scale everything
1418 if (cbt
->num_circ_succeeded
>= INT32_MAX
) {
1419 circuit_build_times_scale_circ_counts(cbt
);
1422 /* Check for NULLness because we might not be using adaptive timeouts */
1423 if (cbt
->liveness
.timeouts_after_firsthop
&&
1424 cbt
->liveness
.num_recent_circs
> 0) {
1425 cbt
->liveness
.timeouts_after_firsthop
[cbt
->liveness
.after_firsthop_idx
]
1427 cbt
->liveness
.after_firsthop_idx
++;
1428 cbt
->liveness
.after_firsthop_idx
%= cbt
->liveness
.num_recent_circs
;
1433 * A circuit just timed out. If it failed after the first hop, record it
1434 * in our history for later deciding if the network speed has changed.
1436 * This is used by circuit_build_times_network_check_changed() to determine
1437 * if we had too many recent timeouts and need to reset our learned timeout
1438 * to something higher.
1441 circuit_build_times_network_timeout(circuit_build_times_t
*cbt
,
1444 // Count circuit timeout
1445 cbt
->num_circ_timeouts
++;
1447 // If we're going to wrap int32, scale everything
1448 if (cbt
->num_circ_timeouts
>= INT32_MAX
) {
1449 circuit_build_times_scale_circ_counts(cbt
);
1452 /* Check for NULLness because we might not be using adaptive timeouts */
1453 if (cbt
->liveness
.timeouts_after_firsthop
&&
1454 cbt
->liveness
.num_recent_circs
> 0) {
1456 cbt
->liveness
.timeouts_after_firsthop
[cbt
->liveness
.after_firsthop_idx
]
1458 cbt
->liveness
.after_firsthop_idx
++;
1459 cbt
->liveness
.after_firsthop_idx
%= cbt
->liveness
.num_recent_circs
;
1465 * A circuit was just forcibly closed. If there has been no recent network
1466 * activity at all, but this circuit was launched back when we thought the
1467 * network was live, increment the number of "nonlive" circuit timeouts.
1469 * This is used by circuit_build_times_network_check_live() to decide
1470 * if we should record the circuit build timeout or not.
1473 circuit_build_times_network_close(circuit_build_times_t
*cbt
,
1474 int did_onehop
, time_t start_time
)
1476 time_t now
= time(NULL
);
1478 // Count circuit close
1479 cbt
->num_circ_closed
++;
1481 // If we're going to wrap int32, scale everything
1482 if (cbt
->num_circ_closed
>= INT32_MAX
) {
1483 circuit_build_times_scale_circ_counts(cbt
);
1487 * Check if this is a timeout that was for a circuit that spent its
1488 * entire existence during a time where we have had no network activity.
1490 if (cbt
->liveness
.network_last_live
< start_time
) {
1492 char last_live_buf
[ISO_TIME_LEN
+1];
1493 char start_time_buf
[ISO_TIME_LEN
+1];
1494 char now_buf
[ISO_TIME_LEN
+1];
1495 format_local_iso_time(last_live_buf
, cbt
->liveness
.network_last_live
);
1496 format_local_iso_time(start_time_buf
, start_time
);
1497 format_local_iso_time(now_buf
, now
);
1499 "A circuit somehow completed a hop while the network was "
1500 "not live. The network was last live at %s, but the circuit "
1501 "launched at %s. It's now %s. This could mean your clock "
1502 "changed.", last_live_buf
, start_time_buf
, now_buf
);
1504 cbt
->liveness
.nonlive_timeouts
++;
1505 if (cbt
->liveness
.nonlive_timeouts
== 1) {
1507 "Tor has not observed any network activity for the past %d "
1508 "seconds. Disabling circuit build timeout recording.",
1509 (int)(now
- cbt
->liveness
.network_last_live
));
1511 /* Tell control.c */
1512 control_event_network_liveness_update(0);
1515 "Got non-live timeout. Current count is: %d",
1516 cbt
->liveness
.nonlive_timeouts
);
1522 * When the network is not live, we do not record circuit build times.
1524 * The network is considered not live if there has been at least one
1525 * circuit build that began and ended (had its close_ms measurement
1526 * period expire) since we last received a cell.
1528 * Also has the side effect of rewinding the circuit time history
1529 * in the case of recent liveness changes.
1532 circuit_build_times_network_check_live(const circuit_build_times_t
*cbt
)
1534 if (cbt
->liveness
.nonlive_timeouts
> 0) {
1542 * Returns true if we have seen more than MAX_RECENT_TIMEOUT_COUNT of
1543 * the past RECENT_CIRCUITS time out after the first hop. Used to detect
1544 * if the network connection has changed significantly, and if so,
1545 * resets our circuit build timeout to the default.
1547 * Also resets the entire timeout history in this case and causes us
1548 * to restart the process of building test circuits and estimating a
1552 circuit_build_times_network_check_changed(circuit_build_times_t
*cbt
)
1554 int total_build_times
= cbt
->total_build_times
;
1555 int timeout_count
=0;
1558 if (cbt
->liveness
.timeouts_after_firsthop
&&
1559 cbt
->liveness
.num_recent_circs
> 0) {
1560 /* how many of our recent circuits made it to the first hop but then
1562 for (i
= 0; i
< cbt
->liveness
.num_recent_circs
; i
++) {
1563 timeout_count
+= cbt
->liveness
.timeouts_after_firsthop
[i
];
1567 /* If 80% of our recent circuits are timing out after the first hop,
1568 * we need to re-estimate a new initial alpha and timeout. */
1569 if (timeout_count
< circuit_build_times_max_timeouts()) {
1573 circuit_build_times_reset(cbt
);
1574 if (cbt
->liveness
.timeouts_after_firsthop
&&
1575 cbt
->liveness
.num_recent_circs
> 0) {
1576 memset(cbt
->liveness
.timeouts_after_firsthop
, 0,
1577 sizeof(*cbt
->liveness
.timeouts_after_firsthop
)*
1578 cbt
->liveness
.num_recent_circs
);
1580 cbt
->liveness
.after_firsthop_idx
= 0;
1582 #define MAX_TIMEOUT ((int32_t) (INT32_MAX/2))
1583 /* Check to see if this has happened before. If so, double the timeout
1584 * to give clients on abysmally bad network connections a shot at access */
1585 if (cbt
->timeout_ms
>= circuit_build_times_get_initial_timeout()) {
1586 if (cbt
->timeout_ms
> MAX_TIMEOUT
|| cbt
->close_ms
> MAX_TIMEOUT
) {
1587 log_warn(LD_CIRC
, "Insanely large circuit build timeout value. "
1588 "(timeout = %fmsec, close = %fmsec)",
1589 cbt
->timeout_ms
, cbt
->close_ms
);
1591 cbt
->timeout_ms
*= 2;
1595 cbt
->close_ms
= cbt
->timeout_ms
1596 = circuit_build_times_get_initial_timeout();
1600 cbt_control_event_buildtimeout_set(cbt
, BUILDTIMEOUT_SET_EVENT_RESET
);
1603 "Your network connection speed appears to have changed. Resetting "
1604 "timeout to %ldms after %d timeouts and %d buildtimes.",
1605 tor_lround(cbt
->timeout_ms
), timeout_count
, total_build_times
);
1611 * Count the number of timeouts in a set of cbt data.
1614 circuit_build_times_timeout_rate(const circuit_build_times_t
*cbt
)
1617 for (i
= 0; i
< CBT_NCIRCUITS_TO_OBSERVE
; i
++) {
1618 if (cbt
->circuit_build_times
[i
] >= cbt
->timeout_ms
) {
1623 if (!cbt
->total_build_times
)
1626 return ((double)timeouts
)/cbt
->total_build_times
;
1630 * Count the number of closed circuits in a set of cbt data.
1633 circuit_build_times_close_rate(const circuit_build_times_t
*cbt
)
1636 for (i
= 0; i
< CBT_NCIRCUITS_TO_OBSERVE
; i
++) {
1637 if (cbt
->circuit_build_times
[i
] == CBT_BUILD_ABANDONED
) {
1642 if (!cbt
->total_build_times
)
1645 return ((double)closed
)/cbt
->total_build_times
;
1649 * Store a timeout as a synthetic value.
1651 * Returns true if the store was successful and we should possibly
1652 * update our timeout estimate.
1655 circuit_build_times_count_close(circuit_build_times_t
*cbt
,
1659 if (circuit_build_times_disabled(get_options())) {
1660 cbt
->close_ms
= cbt
->timeout_ms
1661 = circuit_build_times_get_initial_timeout();
1665 /* Record this force-close to help determine if the network is dead */
1666 circuit_build_times_network_close(cbt
, did_onehop
, start_time
);
1668 /* Only count timeouts if network is live.. */
1669 if (!circuit_build_times_network_check_live(cbt
)) {
1673 circuit_build_times_add_time(cbt
, CBT_BUILD_ABANDONED
);
1678 * Update timeout counts to determine if we need to expire
1679 * our build time history due to excessive timeouts.
1681 * We do not record any actual time values at this stage;
1682 * we are only interested in recording the fact that a timeout
1683 * happened. We record the time values via
1684 * circuit_build_times_count_close() and circuit_build_times_add_time().
1687 circuit_build_times_count_timeout(circuit_build_times_t
*cbt
,
1690 if (circuit_build_times_disabled(get_options())) {
1691 cbt
->close_ms
= cbt
->timeout_ms
1692 = circuit_build_times_get_initial_timeout();
1696 /* Register the fact that a timeout just occurred. */
1697 circuit_build_times_network_timeout(cbt
, did_onehop
);
1699 /* If there are a ton of timeouts, we should reset
1700 * the circuit build timeout. */
1701 circuit_build_times_network_check_changed(cbt
);
1705 * Estimate a new timeout based on history and set our timeout
1706 * variable accordingly.
1709 circuit_build_times_set_timeout_worker(circuit_build_times_t
*cbt
)
1711 build_time_t max_time
;
1712 if (!circuit_build_times_enough_to_compute(cbt
))
1715 if (!circuit_build_times_update_alpha(cbt
))
1718 cbt
->timeout_ms
= circuit_build_times_calculate_timeout(cbt
,
1719 circuit_build_times_quantile_cutoff());
1721 cbt
->close_ms
= circuit_build_times_calculate_timeout(cbt
,
1722 circuit_build_times_close_quantile());
1724 max_time
= circuit_build_times_max(cbt
);
1726 if (cbt
->timeout_ms
> max_time
) {
1728 "Circuit build timeout of %dms is beyond the maximum build "
1729 "time we have ever observed. Capping it to %dms.",
1730 (int)cbt
->timeout_ms
, max_time
);
1731 cbt
->timeout_ms
= max_time
;
1734 if (max_time
< INT32_MAX
/2 && cbt
->close_ms
> 2*max_time
) {
1736 "Circuit build measurement period of %dms is more than twice "
1737 "the maximum build time we have ever observed. Capping it to "
1738 "%dms.", (int)cbt
->close_ms
, 2*max_time
);
1739 cbt
->close_ms
= 2*max_time
;
1742 /* Sometimes really fast guard nodes give us such a steep curve
1743 * that this ends up being not that much greater than timeout_ms.
1744 * Make it be at least 1 min to handle this case. */
1745 cbt
->close_ms
= MAX(cbt
->close_ms
, circuit_build_times_initial_timeout());
1747 cbt
->have_computed_timeout
= 1;
1752 * Exposed function to compute a new timeout. Dispatches events and
1753 * also filters out extremely high timeout values.
1756 circuit_build_times_set_timeout(circuit_build_times_t
*cbt
)
1758 long prev_timeout
= tor_lround(cbt
->timeout_ms
/1000);
1759 double timeout_rate
;
1762 * Just return if we aren't using adaptive timeouts
1764 if (circuit_build_times_disabled(get_options()))
1767 if (!circuit_build_times_set_timeout_worker(cbt
))
1770 if (cbt
->timeout_ms
< circuit_build_times_min_timeout()) {
1771 log_notice(LD_CIRC
, "Set buildtimeout to low value %fms. Setting to %dms",
1772 cbt
->timeout_ms
, circuit_build_times_min_timeout());
1773 cbt
->timeout_ms
= circuit_build_times_min_timeout();
1774 if (cbt
->close_ms
< cbt
->timeout_ms
) {
1775 /* This shouldn't happen because of MAX() in timeout_worker above,
1776 * but doing it just in case */
1777 cbt
->close_ms
= circuit_build_times_initial_timeout();
1781 cbt_control_event_buildtimeout_set(cbt
, BUILDTIMEOUT_SET_EVENT_COMPUTED
);
1783 timeout_rate
= circuit_build_times_timeout_rate(cbt
);
1785 if (prev_timeout
> tor_lround(cbt
->timeout_ms
/1000)) {
1787 "Based on %d circuit times, it looks like we don't need to "
1788 "wait so long for circuits to finish. We will now assume a "
1789 "circuit is too slow to use after waiting %ld milliseconds.",
1790 cbt
->total_build_times
,
1791 tor_lround(cbt
->timeout_ms
));
1793 "Circuit timeout data: %fms, %fms, Xm: %d, a: %f, r: %f",
1794 cbt
->timeout_ms
, cbt
->close_ms
, cbt
->Xm
, cbt
->alpha
,
1796 } else if (prev_timeout
< tor_lround(cbt
->timeout_ms
/1000)) {
1798 "Based on %d circuit times, it looks like we need to wait "
1799 "longer for circuits to finish. We will now assume a "
1800 "circuit is too slow to use after waiting %ld milliseconds.",
1801 cbt
->total_build_times
,
1802 tor_lround(cbt
->timeout_ms
));
1804 "Circuit timeout data: %fms, %fms, Xm: %d, a: %f, r: %f",
1805 cbt
->timeout_ms
, cbt
->close_ms
, cbt
->Xm
, cbt
->alpha
,
1809 "Set circuit build timeout to %ldms (%fms, %fms, Xm: %d, a: %f,"
1810 " r: %f) based on %d circuit times",
1811 tor_lround(cbt
->timeout_ms
),
1812 cbt
->timeout_ms
, cbt
->close_ms
, cbt
->Xm
, cbt
->alpha
, timeout_rate
,
1813 cbt
->total_build_times
);
1817 #ifdef TOR_UNIT_TESTS
1818 /** Make a note that we're running unit tests (rather than running Tor
1819 * itself), so we avoid clobbering our state file. */
1821 circuitbuild_running_unit_tests(void)
1825 #endif /* defined(TOR_UNIT_TESTS) */
1828 circuit_build_times_update_last_circ(circuit_build_times_t
*cbt
)
1830 cbt
->last_circ_at
= approx_time();
1834 cbt_control_event_buildtimeout_set(const circuit_build_times_t
*cbt
,
1835 buildtimeout_set_event_t type
)
1839 double timeout_rate
= 0.0;
1840 double close_rate
= 0.0;
1843 case BUILDTIMEOUT_SET_EVENT_RESET
:
1844 case BUILDTIMEOUT_SET_EVENT_SUSPENDED
:
1845 case BUILDTIMEOUT_SET_EVENT_DISCARD
:
1848 case BUILDTIMEOUT_SET_EVENT_COMPUTED
:
1849 case BUILDTIMEOUT_SET_EVENT_RESUME
:
1851 qnt
= circuit_build_times_quantile_cutoff();
1855 /* The timeout rate is the ratio of the timeout count over
1856 * the total number of circuits attempted. The total number of
1857 * circuits is (timeouts+succeeded), since every circuit
1858 * either succeeds, or times out. "Closed" circuits are
1859 * MEASURE_TIMEOUT circuits whose measurement period expired.
1860 * All MEASURE_TIMEOUT circuits are counted in the timeouts stat
1861 * before transitioning to MEASURE_TIMEOUT (in
1862 * circuit_build_times_mark_circ_as_measurement_only()).
1863 * MEASURE_TIMEOUT circuits that succeed are *not* counted as
1864 * "succeeded". See circuit_build_times_handle_completed_hop().
1866 * We cast the denominator
1867 * to promote it to double before the addition, to avoid int32
1869 const double total_circuits
=
1870 ((double)cbt
->num_circ_timeouts
) + cbt
->num_circ_succeeded
;
1871 if (total_circuits
>= 1.0) {
1872 timeout_rate
= cbt
->num_circ_timeouts
/ total_circuits
;
1873 close_rate
= cbt
->num_circ_closed
/ total_circuits
;
1876 tor_asprintf(&args
, "TOTAL_TIMES=%lu "
1877 "TIMEOUT_MS=%lu XM=%lu ALPHA=%f CUTOFF_QUANTILE=%f "
1878 "TIMEOUT_RATE=%f CLOSE_MS=%lu CLOSE_RATE=%f",
1879 (unsigned long)cbt
->total_build_times
,
1880 (unsigned long)cbt
->timeout_ms
,
1881 (unsigned long)cbt
->Xm
, cbt
->alpha
, qnt
,
1883 (unsigned long)cbt
->close_ms
,
1886 control_event_buildtimeout_set(type
, args
);