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