tor  0.4.0.0-alpha-dev
circuitstats.c
Go to the documentation of this file.
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-2018, The Tor Project, Inc. */
5 /* See LICENSE for licensing information */
6 
26 #define CIRCUITSTATS_PRIVATE
27 
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"
35 #include "core/mainloop/mainloop.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"
47 
48 #include "core/or/crypt_path_st.h"
49 #include "core/or/origin_circuit_st.h"
50 #include "app/config/or_state_st.h"
51 
52 #undef log
53 #include <math.h>
54 
55 static void cbt_control_event_buildtimeout_set(
56  const circuit_build_times_t *cbt,
58 static void circuit_build_times_scale_circ_counts(circuit_build_times_t *cbt);
59 
60 #define CBT_BIN_TO_MS(bin) ((bin)*CBT_BIN_WIDTH + (CBT_BIN_WIDTH/2))
61 
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
67 // most likely.
68 static circuit_build_times_t circ_times;
69 
70 #ifdef TOR_UNIT_TESTS
71 
73 static int unit_tests = 0;
74 #else
75 #define unit_tests 0
76 #endif /* defined(TOR_UNIT_TESTS) */
77 
80 const circuit_build_times_t *
82 {
83  return &circ_times;
84 }
85 
87 circuit_build_times_t *
89 {
90  return &circ_times;
91 }
92 
95 double
97 {
98  return circ_times.close_ms;
99 }
100 
103 double
105 {
106  return circ_times.timeout_ms;
107 }
108 
119 int
121 {
122  return circuit_build_times_disabled_(options, 0);
123 }
124 
126 int
128  int ignore_consensus)
129 {
130  if (unit_tests) {
131  return 0;
132  } else {
133  int consensus_disabled =
134  ignore_consensus ? 0 : networkstatus_get_param(NULL, "cbtdisabled",
135  0, 0, 1);
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:
141  *
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.
145  *
146  * - The adaptive CBT code does not update its timeout estimate
147  * using build times for single-hop circuits.
148  *
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(
152  options);
153 
154  if (consensus_disabled || config_disabled || dirauth_disabled ||
155  state_disabled || single_onion_disabled) {
156 #if 0
157  log_debug(LD_CIRC,
158  "CircuitBuildTime learning is disabled. "
159  "Consensus=%d, Config=%d, AuthDir=%d, StateFile=%d",
160  consensus_disabled, config_disabled, dirauth_disabled,
161  state_disabled);
162 #endif /* 0 */
163  return 1;
164  } else {
165 #if 0
166  log_debug(LD_CIRC,
167  "CircuitBuildTime learning is not disabled. "
168  "Consensus=%d, Config=%d, AuthDir=%d, StateFile=%d",
169  consensus_disabled, config_disabled, dirauth_disabled,
170  state_disabled);
171 #endif /* 0 */
172  return 0;
173  }
174  }
175 }
176 
184 static int32_t
186 {
187  int32_t cbt_maxtimeouts;
188 
189  cbt_maxtimeouts = networkstatus_get_param(NULL, "cbtmaxtimeouts",
191  CBT_MIN_MAX_RECENT_TIMEOUT_COUNT,
192  CBT_MAX_MAX_RECENT_TIMEOUT_COUNT);
193 
194  if (!(get_options()->LearnCircuitBuildTimeout)) {
195  log_debug(LD_BUG,
196  "circuit_build_times_max_timeouts() called, cbtmaxtimeouts is"
197  " %d",
198  cbt_maxtimeouts);
199  }
200 
201  return cbt_maxtimeouts;
202 }
203 
213 static int32_t
215 {
216  int32_t num = networkstatus_get_param(NULL, "cbtnummodes",
218  CBT_MIN_NUM_XM_MODES,
219  CBT_MAX_NUM_XM_MODES);
220 
221  if (!(get_options()->LearnCircuitBuildTimeout)) {
222  log_debug(LD_BUG,
223  "circuit_build_times_default_num_xm_modes() called, cbtnummodes"
224  " is %d",
225  num);
226  }
227 
228  return num;
229 }
230 
237 static int32_t
239 {
240  int32_t num = networkstatus_get_param(NULL, "cbtmincircs",
242  CBT_MIN_MIN_CIRCUITS_TO_OBSERVE,
243  CBT_MAX_MIN_CIRCUITS_TO_OBSERVE);
244 
245  if (!(get_options()->LearnCircuitBuildTimeout)) {
246  log_debug(LD_BUG,
247  "circuit_build_times_min_circs_to_observe() called, cbtmincircs"
248  " is %d",
249  num);
250  }
251 
252  return num;
253 }
254 
257 int
258 circuit_build_times_enough_to_compute(const circuit_build_times_t *cbt)
259 {
260  return cbt->total_build_times >= circuit_build_times_min_circs_to_observe();
261 }
262 
269 double
271 {
272  int32_t num = networkstatus_get_param(NULL, "cbtquantile",
274  CBT_MIN_QUANTILE_CUTOFF,
275  CBT_MAX_QUANTILE_CUTOFF);
276 
277  if (!(get_options()->LearnCircuitBuildTimeout)) {
278  log_debug(LD_BUG,
279  "circuit_build_times_quantile_cutoff() called, cbtquantile"
280  " is %d",
281  num);
282  }
283 
284  return num/100.0;
285 }
286 
294 static double
296 {
297  int32_t param;
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",
302  CBT_MIN_CLOSE_QUANTILE,
303  CBT_MAX_CLOSE_QUANTILE);
304 
305  if (!(get_options()->LearnCircuitBuildTimeout)) {
306  log_debug(LD_BUG,
307  "circuit_build_times_close_quantile() called, cbtclosequantile"
308  " is %d", param);
309  }
310 
311  if (param < min) {
312  log_warn(LD_DIR, "Consensus parameter cbtclosequantile is "
313  "too small, raising to %d", min);
314  param = min;
315  }
316  return param / 100.0;
317 }
318 
326 static int32_t
328 {
329  int32_t num = networkstatus_get_param(NULL, "cbttestfreq",
331  CBT_MIN_TEST_FREQUENCY,
332  CBT_MAX_TEST_FREQUENCY);
333 
334  if (!(get_options()->LearnCircuitBuildTimeout)) {
335  log_debug(LD_BUG,
336  "circuit_build_times_test_frequency() called, cbttestfreq is %d",
337  num);
338  }
339 
340  return num;
341 }
342 
350 static int32_t
352 {
353  int32_t num = networkstatus_get_param(NULL, "cbtmintimeout",
355  CBT_MIN_TIMEOUT_MIN_VALUE,
356  CBT_MAX_TIMEOUT_MIN_VALUE);
357 
358  if (!(get_options()->LearnCircuitBuildTimeout)) {
359  log_debug(LD_BUG,
360  "circuit_build_times_min_timeout() called, cbtmintimeout is %d",
361  num);
362  }
363  return num;
364 }
365 
372 int32_t
374 {
375  int32_t min = circuit_build_times_min_timeout();
376  int32_t param = networkstatus_get_param(NULL, "cbtinitialtimeout",
378  CBT_MIN_TIMEOUT_INITIAL_VALUE,
379  CBT_MAX_TIMEOUT_INITIAL_VALUE);
380 
381  if (!(get_options()->LearnCircuitBuildTimeout)) {
382  log_debug(LD_BUG,
383  "circuit_build_times_initial_timeout() called, "
384  "cbtinitialtimeout is %d",
385  param);
386  }
387 
388  if (param < min) {
389  log_warn(LD_DIR, "Consensus parameter cbtinitialtimeout is too small, "
390  "raising to %d", min);
391  param = min;
392  }
393  return param;
394 }
395 
403 static int32_t
405 {
406  int32_t num;
407  num = networkstatus_get_param(ns, "cbtrecentcount",
409  CBT_MIN_RECENT_CIRCUITS,
410  CBT_MAX_RECENT_CIRCUITS);
411 
412  if (!(get_options()->LearnCircuitBuildTimeout)) {
413  log_debug(LD_BUG,
414  "circuit_build_times_recent_circuit_count() called, "
415  "cbtrecentcount is %d",
416  num);
417  }
418 
419  return num;
420 }
421 
428 void
429 circuit_build_times_new_consensus_params(circuit_build_times_t *cbt,
430  networkstatus_t *ns)
431 {
432  int32_t num;
433 
434  /*
435  * First check if we're doing adaptive timeouts at all; nothing to
436  * update if we aren't.
437  */
438 
439  if (!circuit_build_times_disabled(get_options())) {
441 
442  if (num > 0) {
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);
449  } else {
450  log_notice(LD_CIRC, "Upon receiving a consensus directory, "
451  "re-enabling circuit-based network failure detection.");
452  }
453 
454  tor_assert(cbt->liveness.timeouts_after_firsthop ||
455  cbt->liveness.num_recent_circs == 0);
456 
457  /*
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
463  * elements are lost.
464  *
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.
468  */
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));
474  }
475 
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);
480  }
481 
482  tor_free(cbt->liveness.timeouts_after_firsthop);
483  cbt->liveness.timeouts_after_firsthop = recent_circs;
484  cbt->liveness.num_recent_circs = num;
485  }
486  /* else no change, nothing to do */
487  } else { /* num == 0 */
488  /*
489  * Weird. This probably shouldn't happen, so log a warning, but try
490  * to do something sensible anyway.
491  */
492 
493  log_warn(LD_CIRC,
494  "The cbtrecentcircs consensus parameter came back zero! "
495  "This disables adaptive timeouts since we can't keep track of "
496  "any recent circuits.");
497 
499  }
500  } else {
501  /*
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
506  * if we have any.
507  */
508 
510  }
511 }
512 
516 static double
518 {
519  double timeout;
520  const or_options_t *options = get_options();
521 
522  /*
523  * Check if we have LearnCircuitBuildTimeout, and if we don't,
524  * always use CircuitBuildTimeout, no questions asked.
525  */
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",
533  }
534  } else {
536  }
537 
538  return timeout;
539 }
540 
547 STATIC void
548 circuit_build_times_reset(circuit_build_times_t *cbt)
549 {
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;
554 
555  // Reset timeout and close counts
556  cbt->num_circ_succeeded = 0;
557  cbt->num_circ_closed = 0;
558  cbt->num_circ_timeouts = 0;
559 }
560 
567 void
568 circuit_build_times_init(circuit_build_times_t *cbt)
569 {
570  memset(cbt, 0, sizeof(*cbt));
571  /*
572  * Check if we really are using adaptive timeouts, and don't keep
573  * track of this stuff if not.
574  */
575  if (!circuit_build_times_disabled(get_options())) {
576  cbt->liveness.num_recent_circs =
578  cbt->liveness.timeouts_after_firsthop =
579  tor_calloc(cbt->liveness.num_recent_circs, sizeof(int8_t));
580  } else {
581  cbt->liveness.num_recent_circs = 0;
582  cbt->liveness.timeouts_after_firsthop = NULL;
583  }
584  cbt->close_ms = cbt->timeout_ms = circuit_build_times_get_initial_timeout();
585  cbt_control_event_buildtimeout_set(cbt, BUILDTIMEOUT_SET_EVENT_RESET);
586 }
587 
593 void
594 circuit_build_times_free_timeouts(circuit_build_times_t *cbt)
595 {
596  if (!cbt) return;
597 
598  if (cbt->liveness.timeouts_after_firsthop) {
599  tor_free(cbt->liveness.timeouts_after_firsthop);
600  }
601 
602  cbt->liveness.num_recent_circs = 0;
603 }
604 
605 #if 0
606 
609 static void
610 circuit_build_times_rewind_history(circuit_build_times_t *cbt, int n)
611 {
612  int i = 0;
613 
614  cbt->build_times_idx -= n;
615  cbt->build_times_idx %= CBT_NCIRCUITS_TO_OBSERVE;
616 
617  for (i = 0; i < n; i++) {
618  cbt->circuit_build_times[(i+cbt->build_times_idx)
620  }
621 
622  if (cbt->total_build_times > n) {
623  cbt->total_build_times -= n;
624  } else {
625  cbt->total_build_times = 0;
626  }
627 
628  log_info(LD_CIRC,
629  "Rewound history by %d places. Current index: %d. "
630  "Total: %d", n, cbt->build_times_idx, cbt->total_build_times);
631 }
632 #endif /* 0 */
633 
639 void
641 {
643  CIRC_EVENT_FAILED,
644  END_CIRC_REASON_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;
656 
659  first_hop_succeeded);
660  }
661 }
662 
681 void
683 {
684  struct timeval end;
685  long timediff;
686 
687  /* If circuit build times are disabled, let circuit_expire_building()
688  * handle it.. */
689  if (circuit_build_times_disabled(get_options())) {
690  return;
691  }
692 
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).
696  */
698  return;
699  }
700 
701  tor_gettimeofday(&end);
702  timediff = tv_mdiff(&circ->base_.timestamp_began, &end);
703 
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() &&
710 
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) {
714  log_info(LD_CIRC,
715  "Deciding to timeout circuit %"PRIu32"\n",
716  (circ->global_identifier));
718  }
719  }
720 
721  /* If the circuit is built to exactly the DEFAULT_ROUTE_LEN,
722  * add it to our buildtimes. */
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.
727  */
728  if (timediff < 0 ||
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,
732  circ->base_.purpose,
733  circuit_purpose_to_string(circ->base_.purpose));
734  } else {
735  /* Only count circuit times if the network is live */
739  (build_time_t)timediff);
741  }
742 
743  if (circ->base_.purpose != CIRCUIT_PURPOSE_C_MEASURE_TIMEOUT) {
746  }
747  }
748  }
749 }
750 
758 int
759 circuit_build_times_add_time(circuit_build_times_t *cbt, build_time_t btime)
760 {
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);
765  return -1;
766  }
767 
768  log_debug(LD_CIRC, "Adding circuit build time %u", btime);
769 
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++;
774 
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);
779  }
780 
781  return 0;
782 }
783 
787 static build_time_t
788 circuit_build_times_max(const circuit_build_times_t *cbt)
789 {
790  int i = 0;
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];
796  }
797  return max_build_time;
798 }
799 
800 #if 0
801 
803 circuit_build_times_min(circuit_build_times_t *cbt)
804 {
805  int i = 0;
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];
811  }
812  if (min_build_time == CBT_BUILD_TIME_MAX) {
813  log_warn(LD_CIRC, "No build times less than CBT_BUILD_TIME_MAX!");
814  }
815  return min_build_time;
816 }
817 #endif /* 0 */
818 
828 static uint32_t *
829 circuit_build_times_create_histogram(const circuit_build_times_t *cbt,
830  build_time_t *nbins)
831 {
832  uint32_t *histogram;
833  build_time_t max_build_time = circuit_build_times_max(cbt);
834  int i, c;
835 
836  *nbins = 1 + (max_build_time / CBT_BIN_WIDTH);
837  histogram = tor_calloc(*nbins, sizeof(build_time_t));
838 
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 */
844 
845  c = (cbt->circuit_build_times[i] / CBT_BIN_WIDTH);
846  histogram[c]++;
847  }
848 
849  return histogram;
850 }
851 
860 static build_time_t
861 circuit_build_times_get_xm(circuit_build_times_t *cbt)
862 {
863  build_time_t i, nbins;
864  build_time_t *nth_max_bin;
865  int32_t bin_counts=0;
866  build_time_t ret = 0;
867  uint32_t *histogram = circuit_build_times_create_histogram(cbt, &nbins);
868  int n=0;
870 
871  tor_assert(nbins > 0);
872  tor_assert(num_modes > 0);
873 
874  // Only use one mode if < 1000 buildtimes. Not enough data
875  // for multiple.
876  if (cbt->total_build_times < CBT_NCIRCUITS_TO_OBSERVE)
877  num_modes = 1;
878 
879  nth_max_bin = tor_calloc(num_modes, sizeof(build_time_t));
880 
881  /* Determine the N most common build times */
882  for (i = 0; i < nbins; i++) {
883  if (histogram[i] >= histogram[nth_max_bin[0]]) {
884  nth_max_bin[0] = i;
885  }
886 
887  for (n = 1; n < num_modes; n++) {
888  if (histogram[i] >= histogram[nth_max_bin[n]] &&
889  (!histogram[nth_max_bin[n-1]]
890  || histogram[i] < histogram[nth_max_bin[n-1]])) {
891  nth_max_bin[n] = i;
892  }
893  }
894  }
895 
896  for (n = 0; n < num_modes; n++) {
897  bin_counts += histogram[nth_max_bin[n]];
898  ret += CBT_BIN_TO_MS(nth_max_bin[n])*histogram[nth_max_bin[n]];
899  log_info(LD_CIRC, "Xm mode #%d: %u %u", n, CBT_BIN_TO_MS(nth_max_bin[n]),
900  histogram[nth_max_bin[n]]);
901  }
902 
903  /* bin_counts can become zero if all of our last CBT_NCIRCUITS_TO_OBSERVE
904  * circuits were abandoned before they completed. This shouldn't happen,
905  * though. We should have reset/re-learned a lower timeout first. */
906  if (bin_counts == 0) {
907  ret = 0;
908  log_warn(LD_CIRC,
909  "No valid circuit build time data out of %d times, %u modes, "
910  "have_timeout=%d, %lfms", cbt->total_build_times, num_modes,
911  cbt->have_computed_timeout, cbt->timeout_ms);
912  goto done;
913  }
914 
915  tor_assert(bin_counts > 0);
916 
917  ret /= bin_counts;
918 
919  done:
920  tor_free(histogram);
921  tor_free(nth_max_bin);
922 
923  return ret;
924 }
925 
930 void
931 circuit_build_times_update_state(const circuit_build_times_t *cbt,
932  or_state_t *state)
933 {
934  uint32_t *histogram;
935  build_time_t i = 0;
936  build_time_t nbins = 0;
937  config_line_t **next, *line;
938 
939  histogram = circuit_build_times_create_histogram(cbt, &nbins);
940  // write to state
941  config_free_lines(state->BuildtimeHistogram);
942  next = &state->BuildtimeHistogram;
943  *next = NULL;
944 
945  state->TotalBuildTimes = cbt->total_build_times;
946  state->CircuitBuildAbandonedCount = 0;
947 
948  for (i = 0; i < CBT_NCIRCUITS_TO_OBSERVE; i++) {
949  if (cbt->circuit_build_times[i] == CBT_BUILD_ABANDONED)
950  state->CircuitBuildAbandonedCount++;
951  }
952 
953  for (i = 0; i < nbins; i++) {
954  // compress the histogram by skipping the blanks
955  if (histogram[i] == 0) continue;
956  *next = line = tor_malloc_zero(sizeof(config_line_t));
957  line->key = tor_strdup("CircuitBuildTimeBin");
958  tor_asprintf(&line->value, "%d %d",
959  CBT_BIN_TO_MS(i), histogram[i]);
960  next = &(line->next);
961  }
962 
963  if (!unit_tests) {
964  if (!get_options()->AvoidDiskWrites)
965  or_state_mark_dirty(get_or_state(), 0);
966  }
967 
968  tor_free(histogram);
969 }
970 
976 static void
978  build_time_t *raw_times,
979  uint32_t num_times)
980 {
981  uint32_t n = num_times;
982  if (num_times > CBT_NCIRCUITS_TO_OBSERVE) {
983  log_notice(LD_CIRC, "The number of circuit times that this Tor version "
984  "uses to calculate build times is less than the number stored "
985  "in your state file. Decreasing the circuit time history from "
986  "%lu to %d.", (unsigned long)num_times,
988  }
989 
990  if (n > INT_MAX-1) {
991  log_warn(LD_CIRC, "For some insane reasons, you had %lu circuit build "
992  "observations in your state file. That's far too many; probably "
993  "there's a bug here.", (unsigned long)n);
994  n = INT_MAX-1;
995  }
996 
997  /* This code can only be run on a compact array */
998  while (n-- > 1) {
999  int k = crypto_rand_int(n + 1); /* 0 <= k <= n. */
1000  build_time_t tmp = raw_times[k];
1001  raw_times[k] = raw_times[n];
1002  raw_times[n] = tmp;
1003  }
1004 
1005  /* Since the times are now shuffled, take a random CBT_NCIRCUITS_TO_OBSERVE
1006  * subset (ie the first CBT_NCIRCUITS_TO_OBSERVE values) */
1007  for (n = 0; n < MIN(num_times, CBT_NCIRCUITS_TO_OBSERVE); n++) {
1008  circuit_build_times_add_time(cbt, raw_times[n]);
1009  }
1010 }
1011 
1019 static int
1020 circuit_build_times_filter_timeouts(circuit_build_times_t *cbt)
1021 {
1022  int num_filtered=0, i=0;
1023  double timeout_rate = 0;
1024  build_time_t max_timeout = 0;
1025 
1026  timeout_rate = circuit_build_times_timeout_rate(cbt);
1027  max_timeout = (build_time_t)cbt->close_ms;
1028 
1029  for (i = 0; i < CBT_NCIRCUITS_TO_OBSERVE; i++) {
1030  if (cbt->circuit_build_times[i] > max_timeout) {
1031  build_time_t replaced = cbt->circuit_build_times[i];
1032  num_filtered++;
1033  cbt->circuit_build_times[i] = CBT_BUILD_ABANDONED;
1034 
1035  log_debug(LD_CIRC, "Replaced timeout %d with %d", replaced,
1036  cbt->circuit_build_times[i]);
1037  }
1038  }
1039 
1040  log_info(LD_CIRC,
1041  "We had %d timeouts out of %d build times, "
1042  "and filtered %d above the max of %u",
1043  (int)(cbt->total_build_times*timeout_rate),
1044  cbt->total_build_times, num_filtered, max_timeout);
1045 
1046  return num_filtered;
1047 }
1048 
1056 int
1057 circuit_build_times_parse_state(circuit_build_times_t *cbt,
1058  or_state_t *state)
1059 {
1060  int tot_values = 0;
1061  uint32_t loaded_cnt = 0, N = 0;
1062  config_line_t *line;
1063  int i;
1064  build_time_t *loaded_times;
1065  int err = 0;
1067 
1068  if (circuit_build_times_disabled(get_options())) {
1069  return 0;
1070  }
1071 
1072  /* build_time_t 0 means uninitialized */
1073  loaded_times = tor_calloc(state->TotalBuildTimes, sizeof(build_time_t));
1074 
1075  for (line = state->BuildtimeHistogram; line; line = line->next) {
1076  smartlist_t *args = smartlist_new();
1077  smartlist_split_string(args, line->value, " ",
1078  SPLIT_SKIP_SPACE|SPLIT_IGNORE_BLANK, 0);
1079  if (smartlist_len(args) < 2) {
1080  log_warn(LD_GENERAL, "Unable to parse circuit build times: "
1081  "Too few arguments to CircuitBuildTime");
1082  err = 1;
1083  SMARTLIST_FOREACH(args, char*, cp, tor_free(cp));
1084  smartlist_free(args);
1085  break;
1086  } else {
1087  const char *ms_str = smartlist_get(args,0);
1088  const char *count_str = smartlist_get(args,1);
1089  uint32_t count, k;
1090  build_time_t ms;
1091  int ok;
1092  ms = (build_time_t)tor_parse_ulong(ms_str, 10, 0,
1093  CBT_BUILD_TIME_MAX, &ok, NULL);
1094  if (!ok) {
1095  log_warn(LD_GENERAL, "Unable to parse circuit build times: "
1096  "Unparsable bin number");
1097  err = 1;
1098  SMARTLIST_FOREACH(args, char*, cp, tor_free(cp));
1099  smartlist_free(args);
1100  break;
1101  }
1102  count = (uint32_t)tor_parse_ulong(count_str, 10, 0,
1103  UINT32_MAX, &ok, NULL);
1104  if (!ok) {
1105  log_warn(LD_GENERAL, "Unable to parse circuit build times: "
1106  "Unparsable bin count");
1107  err = 1;
1108  SMARTLIST_FOREACH(args, char*, cp, tor_free(cp));
1109  smartlist_free(args);
1110  break;
1111  }
1112 
1113  if (loaded_cnt+count+ (unsigned)state->CircuitBuildAbandonedCount
1114  > (unsigned) state->TotalBuildTimes) {
1115  log_warn(LD_CIRC,
1116  "Too many build times in state file. "
1117  "Stopping short before %d",
1118  loaded_cnt+count);
1119  SMARTLIST_FOREACH(args, char*, cp, tor_free(cp));
1120  smartlist_free(args);
1121  break;
1122  }
1123 
1124  for (k = 0; k < count; k++) {
1125  loaded_times[loaded_cnt++] = ms;
1126  }
1127  N++;
1128  SMARTLIST_FOREACH(args, char*, cp, tor_free(cp));
1129  smartlist_free(args);
1130  }
1131  }
1132 
1133  log_info(LD_CIRC,
1134  "Adding %d timeouts.", state->CircuitBuildAbandonedCount);
1135  for (i=0; i < state->CircuitBuildAbandonedCount; i++) {
1136  loaded_times[loaded_cnt++] = CBT_BUILD_ABANDONED;
1137  }
1138 
1139  if (loaded_cnt != (unsigned)state->TotalBuildTimes) {
1140  log_warn(LD_CIRC,
1141  "Corrupt state file? Build times count mismatch. "
1142  "Read %d times, but file says %d", loaded_cnt,
1143  state->TotalBuildTimes);
1144  err = 1;
1146  goto done;
1147  }
1148 
1149  circuit_build_times_shuffle_and_store_array(cbt, loaded_times, loaded_cnt);
1150 
1151  /* Verify that we didn't overwrite any indexes */
1152  for (i=0; i < CBT_NCIRCUITS_TO_OBSERVE; i++) {
1153  if (!cbt->circuit_build_times[i])
1154  break;
1155  tot_values++;
1156  }
1157  log_info(LD_CIRC,
1158  "Loaded %d/%d values from %d lines in circuit time histogram",
1159  tot_values, cbt->total_build_times, N);
1160 
1161  if (cbt->total_build_times != tot_values
1162  || cbt->total_build_times > CBT_NCIRCUITS_TO_OBSERVE) {
1163  log_warn(LD_CIRC,
1164  "Corrupt state file? Shuffled build times mismatch. "
1165  "Read %d times, but file says %d", tot_values,
1166  state->TotalBuildTimes);
1167  err = 1;
1169  goto done;
1170  }
1171 
1173 
1174  if (!state->CircuitBuildAbandonedCount && cbt->total_build_times) {
1176  }
1177 
1178  done:
1179  tor_free(loaded_times);
1180  return err ? -1 : 0;
1181 }
1182 
1192 STATIC int
1193 circuit_build_times_update_alpha(circuit_build_times_t *cbt)
1194 {
1195  build_time_t *x=cbt->circuit_build_times;
1196  double a = 0;
1197  int n=0,i=0,abandoned_count=0;
1198  build_time_t max_time=0;
1199 
1200  /* http://en.wikipedia.org/wiki/Pareto_distribution#Parameter_estimation */
1201  /* We sort of cheat here and make our samples slightly more pareto-like
1202  * and less frechet-like. */
1203  cbt->Xm = circuit_build_times_get_xm(cbt);
1204 
1205  /* If Xm came back 0, then too many circuits were abandoned. */
1206  if (cbt->Xm == 0)
1207  return 0;
1208 
1209  tor_assert(cbt->Xm > 0);
1210 
1211  for (i=0; i< CBT_NCIRCUITS_TO_OBSERVE; i++) {
1212  if (!x[i]) {
1213  continue;
1214  }
1215 
1216  if (x[i] < cbt->Xm) {
1217  a += tor_mathlog(cbt->Xm);
1218  } else if (x[i] == CBT_BUILD_ABANDONED) {
1219  abandoned_count++;
1220  } else {
1221  a += tor_mathlog(x[i]);
1222  if (x[i] > max_time)
1223  max_time = x[i];
1224  }
1225  n++;
1226  }
1227 
1228  /*
1229  * We are erring and asserting here because this can only happen
1230  * in codepaths other than startup. The startup state parsing code
1231  * performs this same check, and resets state if it hits it. If we
1232  * hit it at runtime, something serious has gone wrong.
1233  */
1234  if (n!=cbt->total_build_times) {
1235  log_err(LD_CIRC, "Discrepancy in build times count: %d vs %d", n,
1236  cbt->total_build_times);
1237  }
1238  tor_assert(n==cbt->total_build_times);
1239 
1240  if (max_time <= 0) {
1241  /* This can happen if Xm is actually the *maximum* value in the set.
1242  * It can also happen if we've abandoned every single circuit somehow.
1243  * In either case, tell the caller not to compute a new build timeout. */
1244  log_warn(LD_BUG,
1245  "Could not determine largest build time (%d). "
1246  "Xm is %dms and we've abandoned %d out of %d circuits.", max_time,
1247  cbt->Xm, abandoned_count, n);
1248  return 0;
1249  }
1250 
1251  a += abandoned_count*tor_mathlog(max_time);
1252 
1253  a -= n*tor_mathlog(cbt->Xm);
1254  // Estimator comes from Eq #4 in:
1255  // "Bayesian estimation based on trimmed samples from Pareto populations"
1256  // by Arturo J. Fern├índez. We are right-censored only.
1257  a = (n-abandoned_count)/a;
1258 
1259  cbt->alpha = a;
1260 
1261  return 1;
1262 }
1263 
1280 STATIC double
1281 circuit_build_times_calculate_timeout(circuit_build_times_t *cbt,
1282  double quantile)
1283 {
1284  double ret;
1285  tor_assert(quantile >= 0);
1286  tor_assert(1.0-quantile > 0);
1287  tor_assert(cbt->Xm > 0);
1288 
1289  /* If either alpha or p are 0, we would divide by zero, yielding an
1290  * infinite (double) result; which would be clamped to INT32_MAX.
1291  * Instead, initialise ret to INT32_MAX, and skip over these
1292  * potentially illegal/trapping divides by zero.
1293  */
1294  ret = INT32_MAX;
1295 
1296  if (cbt->alpha > 0) {
1297  double p;
1298  p = pow(1.0-quantile,1.0/cbt->alpha);
1299  if (p > 0) {
1300  ret = cbt->Xm/p;
1301  }
1302  }
1303 
1304  if (ret > INT32_MAX) {
1305  ret = INT32_MAX;
1306  }
1307  tor_assert(ret > 0);
1308  return ret;
1309 }
1310 
1311 #ifdef TOR_UNIT_TESTS
1312 
1313 double
1314 circuit_build_times_cdf(circuit_build_times_t *cbt, double x)
1315 {
1316  double ret;
1317  tor_assert(cbt->Xm > 0);
1318  ret = 1.0-pow(cbt->Xm/x,cbt->alpha);
1319  tor_assert(0 <= ret && ret <= 1.0);
1320  return ret;
1321 }
1322 #endif /* defined(TOR_UNIT_TESTS) */
1323 
1324 #ifdef TOR_UNIT_TESTS
1325 
1332 circuit_build_times_generate_sample(circuit_build_times_t *cbt,
1333  double q_lo, double q_hi)
1334 {
1335  double randval = crypto_rand_double();
1336  build_time_t ret;
1337  double u;
1338 
1339  /* Generate between [q_lo, q_hi) */
1340  /*XXXX This is what nextafter is supposed to be for; we should use it on the
1341  * platforms that support it. */
1342  q_hi -= 1.0/(INT32_MAX);
1343 
1344  tor_assert(q_lo >= 0);
1345  tor_assert(q_hi < 1);
1346  tor_assert(q_lo < q_hi);
1347 
1348  u = q_lo + (q_hi-q_lo)*randval;
1349 
1350  tor_assert(0 <= u && u < 1.0);
1351  /* circuit_build_times_calculate_timeout returns <= INT32_MAX */
1352  ret = (build_time_t)
1354  tor_assert(ret > 0);
1355  return ret;
1356 }
1357 #endif /* defined(TOR_UNIT_TESTS) */
1358 
1359 #ifdef TOR_UNIT_TESTS
1360 
1364 void
1365 circuit_build_times_initial_alpha(circuit_build_times_t *cbt,
1366  double quantile, double timeout_ms)
1367 {
1368  // Q(u) = Xm/((1-u)^(1/a))
1369  // Q(0.8) = Xm/((1-0.8))^(1/a)) = CircBuildTimeout
1370  // CircBuildTimeout = Xm/((1-0.8))^(1/a))
1371  // CircBuildTimeout = Xm*((1-0.8))^(-1/a))
1372  // ln(CircBuildTimeout) = ln(Xm)+ln(((1-0.8)))*(-1/a)
1373  // -ln(1-0.8)/(ln(CircBuildTimeout)-ln(Xm))=a
1374  tor_assert(quantile >= 0);
1375  tor_assert(cbt->Xm > 0);
1376  cbt->alpha = tor_mathlog(1.0-quantile)/
1377  (tor_mathlog(cbt->Xm)-tor_mathlog(timeout_ms));
1378  tor_assert(cbt->alpha > 0);
1379 }
1380 #endif /* defined(TOR_UNIT_TESTS) */
1381 
1385 int
1386 circuit_build_times_needs_circuits(const circuit_build_times_t *cbt)
1387 {
1388  /* Return true if < MIN_CIRCUITS_TO_OBSERVE */
1390 }
1391 
1396 int
1397 circuit_build_times_needs_circuits_now(const circuit_build_times_t *cbt)
1398 {
1399  return circuit_build_times_needs_circuits(cbt) &&
1400  approx_time()-cbt->last_circ_at > circuit_build_times_test_frequency();
1401 }
1402 
1407 #define CIRCUIT_TIMEOUT_BEFORE_RECHECK_IP (60*3)
1408 
1419 void
1420 circuit_build_times_network_is_live(circuit_build_times_t *cbt)
1421 {
1422  time_t now = approx_time();
1423  if (cbt->liveness.nonlive_timeouts > 0) {
1424  time_t time_since_live = now - cbt->liveness.network_last_live;
1425  log_notice(LD_CIRC,
1426  "Tor now sees network activity. Restoring circuit build "
1427  "timeout recording. Network was down for %d seconds "
1428  "during %d circuit attempts.",
1429  (int)time_since_live,
1430  cbt->liveness.nonlive_timeouts);
1431  if (time_since_live > CIRCUIT_TIMEOUT_BEFORE_RECHECK_IP)
1433  }
1434  cbt->liveness.network_last_live = now;
1435  cbt->liveness.nonlive_timeouts = 0;
1436 
1437  /* Tell control.c */
1439 }
1440 
1451 void
1452 circuit_build_times_scale_circ_counts(circuit_build_times_t *cbt)
1453 {
1454  cbt->num_circ_succeeded /= 2;
1455  cbt->num_circ_timeouts /= 2;
1456  cbt->num_circ_closed /= 2;
1457 }
1458 
1472 void
1473 circuit_build_times_network_circ_success(circuit_build_times_t *cbt)
1474 {
1475  // Count circuit success
1476  cbt->num_circ_succeeded++;
1477 
1478  // If we're going to wrap int32, scale everything
1479  if (cbt->num_circ_succeeded >= INT32_MAX) {
1481  }
1482 
1483  /* Check for NULLness because we might not be using adaptive timeouts */
1484  if (cbt->liveness.timeouts_after_firsthop &&
1485  cbt->liveness.num_recent_circs > 0) {
1486  cbt->liveness.timeouts_after_firsthop[cbt->liveness.after_firsthop_idx]
1487  = 0;
1488  cbt->liveness.after_firsthop_idx++;
1489  cbt->liveness.after_firsthop_idx %= cbt->liveness.num_recent_circs;
1490  }
1491 }
1492 
1501 static void
1502 circuit_build_times_network_timeout(circuit_build_times_t *cbt,
1503  int did_onehop)
1504 {
1505  // Count circuit timeout
1506  cbt->num_circ_timeouts++;
1507 
1508  // If we're going to wrap int32, scale everything
1509  if (cbt->num_circ_timeouts >= INT32_MAX) {
1511  }
1512 
1513  /* Check for NULLness because we might not be using adaptive timeouts */
1514  if (cbt->liveness.timeouts_after_firsthop &&
1515  cbt->liveness.num_recent_circs > 0) {
1516  if (did_onehop) {
1517  cbt->liveness.timeouts_after_firsthop[cbt->liveness.after_firsthop_idx]
1518  = 1;
1519  cbt->liveness.after_firsthop_idx++;
1520  cbt->liveness.after_firsthop_idx %= cbt->liveness.num_recent_circs;
1521  }
1522  }
1523 }
1524 
1533 static void
1534 circuit_build_times_network_close(circuit_build_times_t *cbt,
1535  int did_onehop, time_t start_time)
1536 {
1537  time_t now = time(NULL);
1538 
1539  // Count circuit close
1540  cbt->num_circ_closed++;
1541 
1542  // If we're going to wrap int32, scale everything
1543  if (cbt->num_circ_closed >= INT32_MAX) {
1545  }
1546 
1547  /*
1548  * Check if this is a timeout that was for a circuit that spent its
1549  * entire existence during a time where we have had no network activity.
1550  */
1551  if (cbt->liveness.network_last_live < start_time) {
1552  if (did_onehop) {
1553  char last_live_buf[ISO_TIME_LEN+1];
1554  char start_time_buf[ISO_TIME_LEN+1];
1555  char now_buf[ISO_TIME_LEN+1];
1556  format_local_iso_time(last_live_buf, cbt->liveness.network_last_live);
1557  format_local_iso_time(start_time_buf, start_time);
1558  format_local_iso_time(now_buf, now);
1559  log_notice(LD_CIRC,
1560  "A circuit somehow completed a hop while the network was "
1561  "not live. The network was last live at %s, but the circuit "
1562  "launched at %s. It's now %s. This could mean your clock "
1563  "changed.", last_live_buf, start_time_buf, now_buf);
1564  }
1565  cbt->liveness.nonlive_timeouts++;
1566  if (cbt->liveness.nonlive_timeouts == 1) {
1567  log_notice(LD_CIRC,
1568  "Tor has not observed any network activity for the past %d "
1569  "seconds. Disabling circuit build timeout recording.",
1570  (int)(now - cbt->liveness.network_last_live));
1571 
1572  /* Tell control.c */
1574  } else {
1575  log_info(LD_CIRC,
1576  "Got non-live timeout. Current count is: %d",
1577  cbt->liveness.nonlive_timeouts);
1578  }
1579  }
1580 }
1581 
1592 int
1593 circuit_build_times_network_check_live(const circuit_build_times_t *cbt)
1594 {
1595  if (cbt->liveness.nonlive_timeouts > 0) {
1596  return 0;
1597  }
1598 
1599  return 1;
1600 }
1601 
1612 STATIC int
1614 {
1615  int total_build_times = cbt->total_build_times;
1616  int timeout_count=0;
1617  int i;
1618 
1619  if (cbt->liveness.timeouts_after_firsthop &&
1620  cbt->liveness.num_recent_circs > 0) {
1621  /* how many of our recent circuits made it to the first hop but then
1622  * timed out? */
1623  for (i = 0; i < cbt->liveness.num_recent_circs; i++) {
1624  timeout_count += cbt->liveness.timeouts_after_firsthop[i];
1625  }
1626  }
1627 
1628  /* If 80% of our recent circuits are timing out after the first hop,
1629  * we need to re-estimate a new initial alpha and timeout. */
1630  if (timeout_count < circuit_build_times_max_timeouts()) {
1631  return 0;
1632  }
1633 
1635  if (cbt->liveness.timeouts_after_firsthop &&
1636  cbt->liveness.num_recent_circs > 0) {
1637  memset(cbt->liveness.timeouts_after_firsthop, 0,
1638  sizeof(*cbt->liveness.timeouts_after_firsthop)*
1639  cbt->liveness.num_recent_circs);
1640  }
1641  cbt->liveness.after_firsthop_idx = 0;
1642 
1643 #define MAX_TIMEOUT ((int32_t) (INT32_MAX/2))
1644  /* Check to see if this has happened before. If so, double the timeout
1645  * to give clients on abysmally bad network connections a shot at access */
1646  if (cbt->timeout_ms >= circuit_build_times_get_initial_timeout()) {
1647  if (cbt->timeout_ms > MAX_TIMEOUT || cbt->close_ms > MAX_TIMEOUT) {
1648  log_warn(LD_CIRC, "Insanely large circuit build timeout value. "
1649  "(timeout = %fmsec, close = %fmsec)",
1650  cbt->timeout_ms, cbt->close_ms);
1651  } else {
1652  cbt->timeout_ms *= 2;
1653  cbt->close_ms *= 2;
1654  }
1655  } else {
1656  cbt->close_ms = cbt->timeout_ms
1658  }
1659 #undef MAX_TIMEOUT
1660 
1661  cbt_control_event_buildtimeout_set(cbt, BUILDTIMEOUT_SET_EVENT_RESET);
1662 
1663  log_notice(LD_CIRC,
1664  "Your network connection speed appears to have changed. Resetting "
1665  "timeout to %lds after %d timeouts and %d buildtimes.",
1666  tor_lround(cbt->timeout_ms/1000), timeout_count,
1667  total_build_times);
1668 
1669  return 1;
1670 }
1671 
1675 double
1676 circuit_build_times_timeout_rate(const circuit_build_times_t *cbt)
1677 {
1678  int i=0,timeouts=0;
1679  for (i = 0; i < CBT_NCIRCUITS_TO_OBSERVE; i++) {
1680  if (cbt->circuit_build_times[i] >= cbt->timeout_ms) {
1681  timeouts++;
1682  }
1683  }
1684 
1685  if (!cbt->total_build_times)
1686  return 0;
1687 
1688  return ((double)timeouts)/cbt->total_build_times;
1689 }
1690 
1694 double
1695 circuit_build_times_close_rate(const circuit_build_times_t *cbt)
1696 {
1697  int i=0,closed=0;
1698  for (i = 0; i < CBT_NCIRCUITS_TO_OBSERVE; i++) {
1699  if (cbt->circuit_build_times[i] == CBT_BUILD_ABANDONED) {
1700  closed++;
1701  }
1702  }
1703 
1704  if (!cbt->total_build_times)
1705  return 0;
1706 
1707  return ((double)closed)/cbt->total_build_times;
1708 }
1709 
1716 int
1717 circuit_build_times_count_close(circuit_build_times_t *cbt,
1718  int did_onehop,
1719  time_t start_time)
1720 {
1721  if (circuit_build_times_disabled(get_options())) {
1722  cbt->close_ms = cbt->timeout_ms
1724  return 0;
1725  }
1726 
1727  /* Record this force-close to help determine if the network is dead */
1728  circuit_build_times_network_close(cbt, did_onehop, start_time);
1729 
1730  /* Only count timeouts if network is live.. */
1732  return 0;
1733  }
1734 
1736  return 1;
1737 }
1738 
1748 void
1749 circuit_build_times_count_timeout(circuit_build_times_t *cbt,
1750  int did_onehop)
1751 {
1752  if (circuit_build_times_disabled(get_options())) {
1753  cbt->close_ms = cbt->timeout_ms
1755  return;
1756  }
1757 
1758  /* Register the fact that a timeout just occurred. */
1759  circuit_build_times_network_timeout(cbt, did_onehop);
1760 
1761  /* If there are a ton of timeouts, we should reset
1762  * the circuit build timeout. */
1764 }
1765 
1770 static int
1771 circuit_build_times_set_timeout_worker(circuit_build_times_t *cbt)
1772 {
1773  build_time_t max_time;
1775  return 0;
1776 
1778  return 0;
1779 
1780  cbt->timeout_ms = circuit_build_times_calculate_timeout(cbt,
1782 
1783  cbt->close_ms = circuit_build_times_calculate_timeout(cbt,
1785 
1786  max_time = circuit_build_times_max(cbt);
1787 
1788  if (cbt->timeout_ms > max_time) {
1789  log_info(LD_CIRC,
1790  "Circuit build timeout of %dms is beyond the maximum build "
1791  "time we have ever observed. Capping it to %dms.",
1792  (int)cbt->timeout_ms, max_time);
1793  cbt->timeout_ms = max_time;
1794  }
1795 
1796  if (max_time < INT32_MAX/2 && cbt->close_ms > 2*max_time) {
1797  log_info(LD_CIRC,
1798  "Circuit build measurement period of %dms is more than twice "
1799  "the maximum build time we have ever observed. Capping it to "
1800  "%dms.", (int)cbt->close_ms, 2*max_time);
1801  cbt->close_ms = 2*max_time;
1802  }
1803 
1804  /* Sometimes really fast guard nodes give us such a steep curve
1805  * that this ends up being not that much greater than timeout_ms.
1806  * Make it be at least 1 min to handle this case. */
1807  cbt->close_ms = MAX(cbt->close_ms, circuit_build_times_initial_timeout());
1808 
1809  cbt->have_computed_timeout = 1;
1810  return 1;
1811 }
1812 
1817 void
1818 circuit_build_times_set_timeout(circuit_build_times_t *cbt)
1819 {
1820  long prev_timeout = tor_lround(cbt->timeout_ms/1000);
1821  double timeout_rate;
1822 
1823  /*
1824  * Just return if we aren't using adaptive timeouts
1825  */
1826  if (circuit_build_times_disabled(get_options()))
1827  return;
1828 
1830  return;
1831 
1832  if (cbt->timeout_ms < circuit_build_times_min_timeout()) {
1833  log_info(LD_CIRC, "Set buildtimeout to low value %fms. Setting to %dms",
1834  cbt->timeout_ms, circuit_build_times_min_timeout());
1835  cbt->timeout_ms = circuit_build_times_min_timeout();
1836  if (cbt->close_ms < cbt->timeout_ms) {
1837  /* This shouldn't happen because of MAX() in timeout_worker above,
1838  * but doing it just in case */
1839  cbt->close_ms = circuit_build_times_initial_timeout();
1840  }
1841  }
1842 
1843  cbt_control_event_buildtimeout_set(cbt, BUILDTIMEOUT_SET_EVENT_COMPUTED);
1844 
1845  timeout_rate = circuit_build_times_timeout_rate(cbt);
1846 
1847  if (prev_timeout > tor_lround(cbt->timeout_ms/1000)) {
1848  log_info(LD_CIRC,
1849  "Based on %d circuit times, it looks like we don't need to "
1850  "wait so long for circuits to finish. We will now assume a "
1851  "circuit is too slow to use after waiting %ld seconds.",
1852  cbt->total_build_times,
1853  tor_lround(cbt->timeout_ms/1000));
1854  log_info(LD_CIRC,
1855  "Circuit timeout data: %fms, %fms, Xm: %d, a: %f, r: %f",
1856  cbt->timeout_ms, cbt->close_ms, cbt->Xm, cbt->alpha,
1857  timeout_rate);
1858  } else if (prev_timeout < tor_lround(cbt->timeout_ms/1000)) {
1859  log_info(LD_CIRC,
1860  "Based on %d circuit times, it looks like we need to wait "
1861  "longer for circuits to finish. We will now assume a "
1862  "circuit is too slow to use after waiting %ld seconds.",
1863  cbt->total_build_times,
1864  tor_lround(cbt->timeout_ms/1000));
1865  log_info(LD_CIRC,
1866  "Circuit timeout data: %fms, %fms, Xm: %d, a: %f, r: %f",
1867  cbt->timeout_ms, cbt->close_ms, cbt->Xm, cbt->alpha,
1868  timeout_rate);
1869  } else {
1870  log_info(LD_CIRC,
1871  "Set circuit build timeout to %lds (%fms, %fms, Xm: %d, a: %f,"
1872  " r: %f) based on %d circuit times",
1873  tor_lround(cbt->timeout_ms/1000),
1874  cbt->timeout_ms, cbt->close_ms, cbt->Xm, cbt->alpha, timeout_rate,
1875  cbt->total_build_times);
1876  }
1877 }
1878 
1879 #ifdef TOR_UNIT_TESTS
1880 
1882 void
1883 circuitbuild_running_unit_tests(void)
1884 {
1885  unit_tests = 1;
1886 }
1887 #endif /* defined(TOR_UNIT_TESTS) */
1888 
1889 void
1890 circuit_build_times_update_last_circ(circuit_build_times_t *cbt)
1891 {
1892  cbt->last_circ_at = approx_time();
1893 }
1894 
1895 static void
1896 cbt_control_event_buildtimeout_set(const circuit_build_times_t *cbt,
1898 {
1899  char *args = NULL;
1900  double qnt;
1901  double timeout_rate = 0.0;
1902  double close_rate = 0.0;
1903 
1904  switch (type) {
1905  case BUILDTIMEOUT_SET_EVENT_RESET:
1906  case BUILDTIMEOUT_SET_EVENT_SUSPENDED:
1907  case BUILDTIMEOUT_SET_EVENT_DISCARD:
1908  qnt = 1.0;
1909  break;
1910  case BUILDTIMEOUT_SET_EVENT_COMPUTED:
1911  case BUILDTIMEOUT_SET_EVENT_RESUME:
1912  default:
1914  break;
1915  }
1916 
1917  /* The timeout rate is the ratio of the timeout count over
1918  * the total number of circuits attempted. The total number of
1919  * circuits is (timeouts+succeeded), since every circuit
1920  * either succeeds, or times out. "Closed" circuits are
1921  * MEASURE_TIMEOUT circuits whose measurement period expired.
1922  * All MEASURE_TIMEOUT circuits are counted in the timeouts stat
1923  * before transitioning to MEASURE_TIMEOUT (in
1924  * circuit_build_times_mark_circ_as_measurement_only()).
1925  * MEASURE_TIMEOUT circuits that succeed are *not* counted as
1926  * "succeeded". See circuit_build_times_handle_completed_hop().
1927  *
1928  * We cast the denominator
1929  * to promote it to double before the addition, to avoid int32
1930  * overflow. */
1931  const double total_circuits =
1932  ((double)cbt->num_circ_timeouts) + cbt->num_circ_succeeded;
1933  if (total_circuits >= 1.0) {
1934  timeout_rate = cbt->num_circ_timeouts / total_circuits;
1935  close_rate = cbt->num_circ_closed / total_circuits;
1936  }
1937 
1938  tor_asprintf(&args, "TOTAL_TIMES=%lu "
1939  "TIMEOUT_MS=%lu XM=%lu ALPHA=%f CUTOFF_QUANTILE=%f "
1940  "TIMEOUT_RATE=%f CLOSE_MS=%lu CLOSE_RATE=%f",
1941  (unsigned long)cbt->total_build_times,
1942  (unsigned long)cbt->timeout_ms,
1943  (unsigned long)cbt->Xm, cbt->alpha, qnt,
1944  timeout_rate,
1945  (unsigned long)cbt->close_ms,
1946  close_rate);
1947 
1948  control_event_buildtimeout_set(type, args);
1949 
1950  tor_free(args);
1951 }
#define CBT_DEFAULT_RECENT_CIRCUITS
Definition: circuitstats.h:89
Header file for circuitstats.c.
Header for statefile.c.
Header for confline.c.
#define CIRCUIT_PURPOSE_C_MEASURE_TIMEOUT
Definition: circuitlist.h:94
#define CBT_DEFAULT_NUM_XM_MODES
Definition: circuitstats.h:61
#define CBT_SAVE_STATE_EVERY
Definition: circuitstats.h:73
static circuit_build_times_t circ_times
Definition: circuitstats.c:68
Common functions for using (pseudo-)random number generators.
int circuit_build_times_disabled_(const or_options_t *options, int ignore_consensus)
Definition: circuitstats.c:127
void circuit_build_times_new_consensus_params(circuit_build_times_t *cbt, networkstatus_t *ns)
Definition: circuitstats.c:429
#define CBT_DEFAULT_TEST_FREQUENCY
Definition: circuitstats.h:117
void format_local_iso_time(char *buf, time_t t)
Definition: time_fmt.c:281
#define LD_GENERAL
Definition: log.h:58
unsigned long tor_parse_ulong(const char *s, int base, unsigned long min, unsigned long max, int *ok, char **next)
Definition: parse_int.c:75
int control_event_buildtimeout_set(buildtimeout_set_event_t type, const char *args)
Definition: control.c:6639
int authdir_mode(const or_options_t *options)
Definition: authmode.c:25
double tor_mathlog(double d)
Definition: fp.c:22
const char * circuit_purpose_to_string(uint8_t purpose)
Definition: circuitlist.c:896
#define DEFAULT_ROUTE_LEN
Definition: or.h:1003
uint32_t build_time_t
Definition: circuitstats.h:25
static int32_t circuit_build_times_max_timeouts(void)
Definition: circuitstats.c:185
crypt_path_t * cpath
#define CBT_DEFAULT_TIMEOUT_INITIAL_VALUE
Definition: circuitstats.h:127
#define TO_CIRCUIT(x)
Definition: or.h:947
Header file for config.c.
unsigned int relaxed_timeout
int circuit_build_times_needs_circuits_now(const circuit_build_times_t *cbt)
long tv_mdiff(const struct timeval *start, const struct timeval *end)
Definition: tvdiff.c:102
static int circuit_build_times_filter_timeouts(circuit_build_times_t *cbt)
int circuit_event_status(origin_circuit_t *circ, circuit_status_event_t tp, int reason_code)
Definition: circuitlist.c:496
int circuit_timeout_want_to_count_circ(const origin_circuit_t *circ)
Definition: circuitbuild.c:843
void circuit_build_times_count_timeout(circuit_build_times_t *cbt, int did_onehop)
#define tor_free(p)
Definition: malloc.h:52
#define tor_fragile_assert()
Definition: util_bug.h:221
static void circuit_build_times_network_timeout(circuit_build_times_t *cbt, int did_onehop)
STATIC double circuit_build_times_calculate_timeout(circuit_build_times_t *cbt, double quantile)
int crypto_rand_int(unsigned int max)
Definition: crypto_rand.c:548
Header file for mainloop.c.
Header for tvdiff.c.
uint8_t purpose
Definition: circuit_st.h:102
int control_event_network_liveness_update(int liveness)
Definition: control.c:6555
void circuit_build_times_network_is_live(circuit_build_times_t *cbt)
double crypto_rand_double(void)
Definition: crypto_rand.c:634
int CircuitBuildTimeout
static int32_t circuit_build_times_default_num_xm_modes(void)
Definition: circuitstats.c:214
double circuit_build_times_quantile_cutoff(void)
Definition: circuitstats.c:270
STATIC int circuit_build_times_network_check_changed(circuit_build_times_t *cbt)
Header file for directory authority mode.
void circuit_build_times_free_timeouts(circuit_build_times_t *cbt)
Definition: circuitstats.c:594
static void circuit_build_times_shuffle_and_store_array(circuit_build_times_t *cbt, build_time_t *raw_times, uint32_t num_times)
Definition: circuitstats.c:977
buildtimeout_set_event_t
Definition: control.h:41
int circuit_build_times_needs_circuits(const circuit_build_times_t *cbt)
#define CBT_DEFAULT_MIN_CIRCUITS_TO_OBSERVE
Definition: circuitstats.h:106
static void circuit_build_times_scale_circ_counts(circuit_build_times_t *cbt)
static void circuit_build_times_network_close(circuit_build_times_t *cbt, int did_onehop, time_t start_time)
tor_assert(buffer)
void circuit_build_times_set_timeout(circuit_build_times_t *cbt)
void reschedule_descriptor_update_check(void)
Definition: mainloop.c:1698
Header for fp.c.
#define LD_CIRC
Definition: log.h:78
static int32_t circuit_build_times_min_circs_to_observe(void)
Definition: circuitstats.c:238
long tor_lround(double d)
Definition: fp.c:31
int tor_asprintf(char **strp, const char *fmt,...)
Definition: printf.c:75
double get_circuit_build_timeout_ms(void)
Definition: circuitstats.c:104
#define CBT_BIN_WIDTH
Definition: circuitstats.h:58
double circuit_build_times_close_rate(const circuit_build_times_t *cbt)
static int32_t circuit_build_times_test_frequency(void)
Definition: circuitstats.c:327
Master header file for Tor-specific functionality.
Header file for circuitbuild.c.
#define CBT_NCIRCUITS_TO_OBSERVE
Definition: circuitstats.h:55
void circuit_build_times_mark_circ_as_measurement_only(origin_circuit_t *circ)
Definition: circuitstats.c:640
static build_time_t circuit_build_times_get_xm(circuit_build_times_t *cbt)
Definition: circuitstats.c:861
struct config_line_t * BuildtimeHistogram
Definition: or_state_st.h:77
Header file for circuituse.c.
Header file for circuitlist.c.
int circuit_any_opened_circuits_cached(void)
Definition: circuitlist.c:751
Header file for rendservice.c.
#define CBT_DEFAULT_TIMEOUT_MIN_VALUE
Definition: circuitstats.h:122
static double circuit_build_times_close_quantile(void)
Definition: circuitstats.c:295
#define LD_DIR
Definition: log.h:84
int circuit_build_times_enough_to_compute(const circuit_build_times_t *cbt)
Definition: circuitstats.c:258
static double circuit_build_times_get_initial_timeout(void)
Definition: circuitstats.c:517
#define CBT_BUILD_ABANDONED
Definition: circuitstats.h:69
double circuit_build_times_timeout_rate(const circuit_build_times_t *cbt)
static build_time_t circuit_build_times_max(const circuit_build_times_t *cbt)
Definition: circuitstats.c:788
void circuit_build_times_network_circ_success(circuit_build_times_t *cbt)
#define SMARTLIST_FOREACH(sl, type, var, cmd)
Header file for router.c.
int circuit_build_times_add_time(circuit_build_times_t *cbt, build_time_t btime)
Definition: circuitstats.c:759
int circuit_get_cpath_opened_len(const origin_circuit_t *circ)
Definition: circuitlist.c:2055
static int32_t circuit_build_times_min_timeout(void)
Definition: circuitstats.c:351
uint8_t state
Definition: crypt_path_st.h:54
int did_last_state_file_write_fail(void)
Definition: statefile.c:478
circuit_build_times_t * get_circuit_build_times_mutable(void)
Definition: circuitstats.c:88
struct timeval timestamp_began
Definition: circuit_st.h:130
int LearnCircuitBuildTimeout
int circuit_build_times_count_close(circuit_build_times_t *cbt, int did_onehop, time_t start_time)
static int circuit_build_times_set_timeout_worker(circuit_build_times_t *cbt)
Header file for control.c.
double get_circuit_build_close_time_ms(void)
Definition: circuitstats.c:96
const circuit_build_times_t * get_circuit_build_times(void)
Definition: circuitstats.c:81
time_t approx_time(void)
Definition: approx_time.c:32
void or_state_mark_dirty(or_state_t *state, time_t when)
Definition: statefile.c:715
int circuit_build_times_network_check_live(const circuit_build_times_t *cbt)
void circuit_change_purpose(circuit_t *circ, uint8_t new_purpose)
Definition: circuituse.c:3048
#define CBT_DEFAULT_CLOSE_QUANTILE
Definition: circuitstats.h:81
STATIC void circuit_build_times_reset(circuit_build_times_t *cbt)
Definition: circuitstats.c:548
#define MAX(a, b)
Definition: cmp.h:22
void circuit_build_times_handle_completed_hop(origin_circuit_t *circ)
Definition: circuitstats.c:682
#define CBT_DEFAULT_QUANTILE_CUTOFF
Definition: circuitstats.h:111
#define CIRCUIT_TIMEOUT_BEFORE_RECHECK_IP
int circuit_build_times_parse_state(circuit_build_times_t *cbt, or_state_t *state)
void circuit_build_times_init(circuit_build_times_t *cbt)
Definition: circuitstats.c:568
void circuit_build_times_update_state(const circuit_build_times_t *cbt, or_state_t *state)
Definition: circuitstats.c:931
STATIC int circuit_build_times_update_alpha(circuit_build_times_t *cbt)
static uint32_t * circuit_build_times_create_histogram(const circuit_build_times_t *cbt, build_time_t *nbins)
Definition: circuitstats.c:829
#define CBT_DEFAULT_MAX_RECENT_TIMEOUT_COUNT
Definition: circuitstats.h:101
Header file for rendclient.c.
static int32_t circuit_build_times_recent_circuit_count(networkstatus_t *ns)
Definition: circuitstats.c:404
Header file for networkstatus.c.
#define LD_BUG
Definition: log.h:82
int32_t circuit_build_times_initial_timeout(void)
Definition: circuitstats.c:373
int circuit_build_times_disabled(const or_options_t *options)
Definition: circuitstats.c:120
Header for confparse.c.
int smartlist_split_string(smartlist_t *sl, const char *str, const char *sep, int flags, int max)