circuitstats.c 62 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615616617618619620621622623624625626627628629630631632633634635636637638639640641642643644645646647648649650651652653654655656657658659660661662663664665666667668669670671672673674675676677678679680681682683684685686687688689690691692693694695696697698699700701702703704705706707708709710711712713714715716717718719720721722723724725726727728729730731732733734735736737738739740741742743744745746747748749750751752753754755756757758759760761762763764765766767768769770771772773774775776777778779780781782783784785786787788789790791792793794795796797798799800801802803804805806807808809810811812813814815816817818819820821822823824825826827828829830831832833834835836837838839840841842843844845846847848849850851852853854855856857858859860861862863864865866867868869870871872873874875876877878879880881882883884885886887888889890891892893894895896897898899900901902903904905906907908909910911912913914915916917918919920921922923924925926927928929930931932933934935936937938939940941942943944945946947948949950951952953954955956957958959960961962963964965966967968969970971972973974975976977978979980981982983984985986987988989990991992993994995996997998999100010011002100310041005100610071008100910101011101210131014101510161017101810191020102110221023102410251026102710281029103010311032103310341035103610371038103910401041104210431044104510461047104810491050105110521053105410551056105710581059106010611062106310641065106610671068106910701071107210731074107510761077107810791080108110821083108410851086108710881089109010911092109310941095109610971098109911001101110211031104110511061107110811091110111111121113111411151116111711181119112011211122112311241125112611271128112911301131113211331134113511361137113811391140114111421143114411451146114711481149115011511152115311541155115611571158115911601161116211631164116511661167116811691170117111721173117411751176117711781179118011811182118311841185118611871188118911901191119211931194119511961197119811991200120112021203120412051206120712081209121012111212121312141215121612171218121912201221122212231224122512261227122812291230123112321233123412351236123712381239124012411242124312441245124612471248124912501251125212531254125512561257125812591260126112621263126412651266126712681269127012711272127312741275127612771278127912801281128212831284128512861287128812891290129112921293129412951296129712981299130013011302130313041305130613071308130913101311131213131314131513161317131813191320132113221323132413251326132713281329133013311332133313341335133613371338133913401341134213431344134513461347134813491350135113521353135413551356135713581359136013611362136313641365136613671368136913701371137213731374137513761377137813791380138113821383138413851386138713881389139013911392139313941395139613971398139914001401140214031404140514061407140814091410141114121413141414151416141714181419142014211422142314241425142614271428142914301431143214331434143514361437143814391440144114421443144414451446144714481449145014511452145314541455145614571458145914601461146214631464146514661467146814691470147114721473147414751476147714781479148014811482148314841485148614871488148914901491149214931494149514961497149814991500150115021503150415051506150715081509151015111512151315141515151615171518151915201521152215231524152515261527152815291530153115321533153415351536153715381539154015411542154315441545154615471548154915501551155215531554155515561557155815591560156115621563156415651566156715681569157015711572157315741575157615771578157915801581158215831584158515861587158815891590159115921593159415951596159715981599160016011602160316041605160616071608160916101611161216131614161516161617161816191620162116221623162416251626162716281629163016311632163316341635163616371638163916401641164216431644164516461647164816491650165116521653165416551656165716581659166016611662166316641665166616671668166916701671167216731674167516761677167816791680168116821683168416851686168716881689169016911692169316941695169616971698169917001701170217031704170517061707170817091710171117121713171417151716171717181719172017211722172317241725172617271728172917301731173217331734173517361737173817391740174117421743174417451746174717481749175017511752175317541755175617571758175917601761176217631764176517661767176817691770177117721773177417751776177717781779178017811782178317841785178617871788178917901791179217931794179517961797179817991800180118021803180418051806180718081809181018111812181318141815181618171818181918201821182218231824182518261827182818291830183118321833183418351836183718381839184018411842184318441845184618471848184918501851185218531854185518561857185818591860186118621863186418651866186718681869187018711872187318741875187618771878187918801881188218831884188518861887188818891890189118921893189418951896189718981899190019011902190319041905190619071908190919101911191219131914191519161917191819191920192119221923192419251926192719281929193019311932193319341935193619371938193919401941194219431944194519461947194819491950
  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. /**
  7. * \file circuitstats.c
  8. *
  9. * \brief Maintains and analyzes statistics about circuit built times, so we
  10. * can tell how long we may need to wait for a fast circuit to be constructed.
  11. *
  12. * By keeping these statistics, a client learns when it should time out a slow
  13. * circuit for being too slow, and when it should keep a circuit open in order
  14. * to wait for it to complete.
  15. *
  16. * The information here is kept in a circuit_built_times_t structure, which is
  17. * currently a singleton, but doesn't need to be. It's updated by calls to
  18. * circuit_build_times_count_timeout() from circuituse.c,
  19. * circuit_build_times_count_close() from circuituse.c, and
  20. * circuit_build_times_add_time() from circuitbuild.c, and inspected by other
  21. * calls into this module, mostly from circuitlist.c. Observations are
  22. * persisted to disk via the or_state_t-related calls.
  23. */
  24. #define CIRCUITSTATS_PRIVATE
  25. #include "or/or.h"
  26. #include "or/circuitbuild.h"
  27. #include "or/circuitstats.h"
  28. #include "or/config.h"
  29. #include "or/confparse.h"
  30. #include "or/control.h"
  31. #include "lib/crypt_ops/crypto_rand.h"
  32. #include "or/main.h"
  33. #include "or/networkstatus.h"
  34. #include "or/rendclient.h"
  35. #include "or/rendservice.h"
  36. #include "or/router.h"
  37. #include "or/statefile.h"
  38. #include "or/circuitlist.h"
  39. #include "or/circuituse.h"
  40. #include "lib/math/fp.h"
  41. #include "lib/time/tvdiff.h"
  42. #include "or/crypt_path_st.h"
  43. #include "or/origin_circuit_st.h"
  44. #undef log
  45. #include <math.h>
  46. static void cbt_control_event_buildtimeout_set(
  47. const circuit_build_times_t *cbt,
  48. buildtimeout_set_event_t type);
  49. static void circuit_build_times_scale_circ_counts(circuit_build_times_t *cbt);
  50. #define CBT_BIN_TO_MS(bin) ((bin)*CBT_BIN_WIDTH + (CBT_BIN_WIDTH/2))
  51. /** Global list of circuit build times */
  52. // XXXX: Add this as a member for entry_guard_t instead of global?
  53. // Then we could do per-guard statistics, as guards are likely to
  54. // vary in their own latency. The downside of this is that guards
  55. // can change frequently, so we'd be building a lot more circuits
  56. // most likely.
  57. static circuit_build_times_t circ_times;
  58. #ifdef TOR_UNIT_TESTS
  59. /** If set, we're running the unit tests: we should avoid clobbering
  60. * our state file or accessing get_options() or get_or_state() */
  61. static int unit_tests = 0;
  62. #else
  63. #define unit_tests 0
  64. #endif /* defined(TOR_UNIT_TESTS) */
  65. /** Return a pointer to the data structure describing our current circuit
  66. * build time history and computations. */
  67. const circuit_build_times_t *
  68. get_circuit_build_times(void)
  69. {
  70. return &circ_times;
  71. }
  72. /** As get_circuit_build_times, but return a mutable pointer. */
  73. circuit_build_times_t *
  74. get_circuit_build_times_mutable(void)
  75. {
  76. return &circ_times;
  77. }
  78. /** Return the time to wait before actually closing an under-construction, in
  79. * milliseconds. */
  80. double
  81. get_circuit_build_close_time_ms(void)
  82. {
  83. return circ_times.close_ms;
  84. }
  85. /** Return the time to wait before giving up on an under-construction circuit,
  86. * in milliseconds. */
  87. double
  88. get_circuit_build_timeout_ms(void)
  89. {
  90. return circ_times.timeout_ms;
  91. }
  92. /**
  93. * This function decides if CBT learning should be disabled. It returns
  94. * true if one or more of the following conditions are met:
  95. *
  96. * 1. If the cbtdisabled consensus parameter is set.
  97. * 2. If the torrc option LearnCircuitBuildTimeout is false.
  98. * 3. If we are a directory authority
  99. * 4. If we fail to write circuit build time history to our state file.
  100. * 5. If we are compiled or configured in Tor2web mode
  101. * 6. If we are configured in Single Onion mode
  102. */
  103. int
  104. circuit_build_times_disabled(const or_options_t *options)
  105. {
  106. return circuit_build_times_disabled_(options, 0);
  107. }
  108. /** As circuit_build_times_disabled, but take options as an argument. */
  109. int
  110. circuit_build_times_disabled_(const or_options_t *options,
  111. int ignore_consensus)
  112. {
  113. if (unit_tests) {
  114. return 0;
  115. } else {
  116. int consensus_disabled =
  117. ignore_consensus ? 0 : networkstatus_get_param(NULL, "cbtdisabled",
  118. 0, 0, 1);
  119. int config_disabled = !options->LearnCircuitBuildTimeout;
  120. int dirauth_disabled = authdir_mode(options);
  121. int state_disabled = did_last_state_file_write_fail() ? 1 : 0;
  122. /* LearnCircuitBuildTimeout and Tor2web/Single Onion Services are
  123. * incompatible in two ways:
  124. *
  125. * - LearnCircuitBuildTimeout results in a low CBT, which
  126. * Single Onion use of one-hop intro and rendezvous circuits lowers
  127. * much further, producing *far* too many timeouts.
  128. *
  129. * - The adaptive CBT code does not update its timeout estimate
  130. * using build times for single-hop circuits.
  131. *
  132. * If we fix both of these issues someday, we should test
  133. * these modes with LearnCircuitBuildTimeout on again. */
  134. int tor2web_disabled = rend_client_allow_non_anonymous_connection(options);
  135. int single_onion_disabled = rend_service_allow_non_anonymous_connection(
  136. options);
  137. if (consensus_disabled || config_disabled || dirauth_disabled ||
  138. state_disabled || tor2web_disabled || single_onion_disabled) {
  139. #if 0
  140. log_debug(LD_CIRC,
  141. "CircuitBuildTime learning is disabled. "
  142. "Consensus=%d, Config=%d, AuthDir=%d, StateFile=%d",
  143. consensus_disabled, config_disabled, dirauth_disabled,
  144. state_disabled);
  145. #endif /* 0 */
  146. return 1;
  147. } else {
  148. #if 0
  149. log_debug(LD_CIRC,
  150. "CircuitBuildTime learning is not disabled. "
  151. "Consensus=%d, Config=%d, AuthDir=%d, StateFile=%d",
  152. consensus_disabled, config_disabled, dirauth_disabled,
  153. state_disabled);
  154. #endif /* 0 */
  155. return 0;
  156. }
  157. }
  158. }
  159. /**
  160. * Retrieve and bounds-check the cbtmaxtimeouts consensus parameter.
  161. *
  162. * Effect: When this many timeouts happen in the last 'cbtrecentcount'
  163. * circuit attempts, the client should discard all of its history and
  164. * begin learning a fresh timeout value.
  165. */
  166. static int32_t
  167. circuit_build_times_max_timeouts(void)
  168. {
  169. int32_t cbt_maxtimeouts;
  170. cbt_maxtimeouts = networkstatus_get_param(NULL, "cbtmaxtimeouts",
  171. CBT_DEFAULT_MAX_RECENT_TIMEOUT_COUNT,
  172. CBT_MIN_MAX_RECENT_TIMEOUT_COUNT,
  173. CBT_MAX_MAX_RECENT_TIMEOUT_COUNT);
  174. if (!(get_options()->LearnCircuitBuildTimeout)) {
  175. log_debug(LD_BUG,
  176. "circuit_build_times_max_timeouts() called, cbtmaxtimeouts is"
  177. " %d",
  178. cbt_maxtimeouts);
  179. }
  180. return cbt_maxtimeouts;
  181. }
  182. /**
  183. * Retrieve and bounds-check the cbtnummodes consensus parameter.
  184. *
  185. * Effect: This value governs how many modes to use in the weighted
  186. * average calculation of Pareto parameter Xm. A value of 3 introduces
  187. * some bias (2-5% of CDF) under ideal conditions, but allows for better
  188. * performance in the event that a client chooses guard nodes of radically
  189. * different performance characteristics.
  190. */
  191. static int32_t
  192. circuit_build_times_default_num_xm_modes(void)
  193. {
  194. int32_t num = networkstatus_get_param(NULL, "cbtnummodes",
  195. CBT_DEFAULT_NUM_XM_MODES,
  196. CBT_MIN_NUM_XM_MODES,
  197. CBT_MAX_NUM_XM_MODES);
  198. if (!(get_options()->LearnCircuitBuildTimeout)) {
  199. log_debug(LD_BUG,
  200. "circuit_build_times_default_num_xm_modes() called, cbtnummodes"
  201. " is %d",
  202. num);
  203. }
  204. return num;
  205. }
  206. /**
  207. * Retrieve and bounds-check the cbtmincircs consensus parameter.
  208. *
  209. * Effect: This is the minimum number of circuits to build before
  210. * computing a timeout.
  211. */
  212. static int32_t
  213. circuit_build_times_min_circs_to_observe(void)
  214. {
  215. int32_t num = networkstatus_get_param(NULL, "cbtmincircs",
  216. CBT_DEFAULT_MIN_CIRCUITS_TO_OBSERVE,
  217. CBT_MIN_MIN_CIRCUITS_TO_OBSERVE,
  218. CBT_MAX_MIN_CIRCUITS_TO_OBSERVE);
  219. if (!(get_options()->LearnCircuitBuildTimeout)) {
  220. log_debug(LD_BUG,
  221. "circuit_build_times_min_circs_to_observe() called, cbtmincircs"
  222. " is %d",
  223. num);
  224. }
  225. return num;
  226. }
  227. /** Return true iff <b>cbt</b> has recorded enough build times that we
  228. * want to start acting on the timeout it implies. */
  229. int
  230. circuit_build_times_enough_to_compute(const circuit_build_times_t *cbt)
  231. {
  232. return cbt->total_build_times >= circuit_build_times_min_circs_to_observe();
  233. }
  234. /**
  235. * Retrieve and bounds-check the cbtquantile consensus parameter.
  236. *
  237. * Effect: This is the position on the quantile curve to use to set the
  238. * timeout value. It is a percent (10-99).
  239. */
  240. double
  241. circuit_build_times_quantile_cutoff(void)
  242. {
  243. int32_t num = networkstatus_get_param(NULL, "cbtquantile",
  244. CBT_DEFAULT_QUANTILE_CUTOFF,
  245. CBT_MIN_QUANTILE_CUTOFF,
  246. CBT_MAX_QUANTILE_CUTOFF);
  247. if (!(get_options()->LearnCircuitBuildTimeout)) {
  248. log_debug(LD_BUG,
  249. "circuit_build_times_quantile_cutoff() called, cbtquantile"
  250. " is %d",
  251. num);
  252. }
  253. return num/100.0;
  254. }
  255. /**
  256. * Retrieve and bounds-check the cbtclosequantile consensus parameter.
  257. *
  258. * Effect: This is the position on the quantile curve to use to set the
  259. * timeout value to use to actually close circuits. It is a percent
  260. * (0-99).
  261. */
  262. static double
  263. circuit_build_times_close_quantile(void)
  264. {
  265. int32_t param;
  266. /* Cast is safe - circuit_build_times_quantile_cutoff() is capped */
  267. int32_t min = (int)tor_lround(100*circuit_build_times_quantile_cutoff());
  268. param = networkstatus_get_param(NULL, "cbtclosequantile",
  269. CBT_DEFAULT_CLOSE_QUANTILE,
  270. CBT_MIN_CLOSE_QUANTILE,
  271. CBT_MAX_CLOSE_QUANTILE);
  272. if (!(get_options()->LearnCircuitBuildTimeout)) {
  273. log_debug(LD_BUG,
  274. "circuit_build_times_close_quantile() called, cbtclosequantile"
  275. " is %d", param);
  276. }
  277. if (param < min) {
  278. log_warn(LD_DIR, "Consensus parameter cbtclosequantile is "
  279. "too small, raising to %d", min);
  280. param = min;
  281. }
  282. return param / 100.0;
  283. }
  284. /**
  285. * Retrieve and bounds-check the cbttestfreq consensus parameter.
  286. *
  287. * Effect: Describes how often in seconds to build a test circuit to
  288. * gather timeout values. Only applies if less than 'cbtmincircs'
  289. * have been recorded.
  290. */
  291. static int32_t
  292. circuit_build_times_test_frequency(void)
  293. {
  294. int32_t num = networkstatus_get_param(NULL, "cbttestfreq",
  295. CBT_DEFAULT_TEST_FREQUENCY,
  296. CBT_MIN_TEST_FREQUENCY,
  297. CBT_MAX_TEST_FREQUENCY);
  298. if (!(get_options()->LearnCircuitBuildTimeout)) {
  299. log_debug(LD_BUG,
  300. "circuit_build_times_test_frequency() called, cbttestfreq is %d",
  301. num);
  302. }
  303. return num;
  304. }
  305. /**
  306. * Retrieve and bounds-check the cbtmintimeout consensus parameter.
  307. *
  308. * Effect: This is the minimum allowed timeout value in milliseconds.
  309. * The minimum is to prevent rounding to 0 (we only check once
  310. * per second).
  311. */
  312. static int32_t
  313. circuit_build_times_min_timeout(void)
  314. {
  315. int32_t num = networkstatus_get_param(NULL, "cbtmintimeout",
  316. CBT_DEFAULT_TIMEOUT_MIN_VALUE,
  317. CBT_MIN_TIMEOUT_MIN_VALUE,
  318. CBT_MAX_TIMEOUT_MIN_VALUE);
  319. if (!(get_options()->LearnCircuitBuildTimeout)) {
  320. log_debug(LD_BUG,
  321. "circuit_build_times_min_timeout() called, cbtmintimeout is %d",
  322. num);
  323. }
  324. return num;
  325. }
  326. /**
  327. * Retrieve and bounds-check the cbtinitialtimeout consensus parameter.
  328. *
  329. * Effect: This is the timeout value to use before computing a timeout,
  330. * in milliseconds.
  331. */
  332. int32_t
  333. circuit_build_times_initial_timeout(void)
  334. {
  335. int32_t min = circuit_build_times_min_timeout();
  336. int32_t param = networkstatus_get_param(NULL, "cbtinitialtimeout",
  337. CBT_DEFAULT_TIMEOUT_INITIAL_VALUE,
  338. CBT_MIN_TIMEOUT_INITIAL_VALUE,
  339. CBT_MAX_TIMEOUT_INITIAL_VALUE);
  340. if (!(get_options()->LearnCircuitBuildTimeout)) {
  341. log_debug(LD_BUG,
  342. "circuit_build_times_initial_timeout() called, "
  343. "cbtinitialtimeout is %d",
  344. param);
  345. }
  346. if (param < min) {
  347. log_warn(LD_DIR, "Consensus parameter cbtinitialtimeout is too small, "
  348. "raising to %d", min);
  349. param = min;
  350. }
  351. return param;
  352. }
  353. /**
  354. * Retrieve and bounds-check the cbtrecentcount consensus parameter.
  355. *
  356. * Effect: This is the number of circuit build times to keep track of
  357. * for deciding if we hit cbtmaxtimeouts and need to reset our state
  358. * and learn a new timeout.
  359. */
  360. static int32_t
  361. circuit_build_times_recent_circuit_count(networkstatus_t *ns)
  362. {
  363. int32_t num;
  364. num = networkstatus_get_param(ns, "cbtrecentcount",
  365. CBT_DEFAULT_RECENT_CIRCUITS,
  366. CBT_MIN_RECENT_CIRCUITS,
  367. CBT_MAX_RECENT_CIRCUITS);
  368. if (!(get_options()->LearnCircuitBuildTimeout)) {
  369. log_debug(LD_BUG,
  370. "circuit_build_times_recent_circuit_count() called, "
  371. "cbtrecentcount is %d",
  372. num);
  373. }
  374. return num;
  375. }
  376. /**
  377. * This function is called when we get a consensus update.
  378. *
  379. * It checks to see if we have changed any consensus parameters
  380. * that require reallocation or discard of previous stats.
  381. */
  382. void
  383. circuit_build_times_new_consensus_params(circuit_build_times_t *cbt,
  384. networkstatus_t *ns)
  385. {
  386. int32_t num;
  387. /*
  388. * First check if we're doing adaptive timeouts at all; nothing to
  389. * update if we aren't.
  390. */
  391. if (!circuit_build_times_disabled(get_options())) {
  392. num = circuit_build_times_recent_circuit_count(ns);
  393. if (num > 0) {
  394. if (num != cbt->liveness.num_recent_circs) {
  395. int8_t *recent_circs;
  396. if (cbt->liveness.num_recent_circs > 0) {
  397. log_notice(LD_CIRC, "The Tor Directory Consensus has changed how "
  398. "many circuits we must track to detect network failures "
  399. "from %d to %d.", cbt->liveness.num_recent_circs, num);
  400. } else {
  401. log_notice(LD_CIRC, "Upon receiving a consensus directory, "
  402. "re-enabling circuit-based network failure detection.");
  403. }
  404. tor_assert(cbt->liveness.timeouts_after_firsthop ||
  405. cbt->liveness.num_recent_circs == 0);
  406. /*
  407. * Technically this is a circular array that we are reallocating
  408. * and memcopying. However, since it only consists of either 1s
  409. * or 0s, and is only used in a statistical test to determine when
  410. * we should discard our history after a sufficient number of 1's
  411. * have been reached, it is fine if order is not preserved or
  412. * elements are lost.
  413. *
  414. * cbtrecentcount should only be changing in cases of severe network
  415. * distress anyway, so memory correctness here is paramount over
  416. * doing acrobatics to preserve the array.
  417. */
  418. recent_circs = tor_calloc(num, sizeof(int8_t));
  419. if (cbt->liveness.timeouts_after_firsthop &&
  420. cbt->liveness.num_recent_circs > 0) {
  421. memcpy(recent_circs, cbt->liveness.timeouts_after_firsthop,
  422. sizeof(int8_t)*MIN(num, cbt->liveness.num_recent_circs));
  423. }
  424. // Adjust the index if it needs it.
  425. if (num < cbt->liveness.num_recent_circs) {
  426. cbt->liveness.after_firsthop_idx = MIN(num-1,
  427. cbt->liveness.after_firsthop_idx);
  428. }
  429. tor_free(cbt->liveness.timeouts_after_firsthop);
  430. cbt->liveness.timeouts_after_firsthop = recent_circs;
  431. cbt->liveness.num_recent_circs = num;
  432. }
  433. /* else no change, nothing to do */
  434. } else { /* num == 0 */
  435. /*
  436. * Weird. This probably shouldn't happen, so log a warning, but try
  437. * to do something sensible anyway.
  438. */
  439. log_warn(LD_CIRC,
  440. "The cbtrecentcircs consensus parameter came back zero! "
  441. "This disables adaptive timeouts since we can't keep track of "
  442. "any recent circuits.");
  443. circuit_build_times_free_timeouts(cbt);
  444. }
  445. } else {
  446. /*
  447. * Adaptive timeouts are disabled; this might be because of the
  448. * LearnCircuitBuildTimes config parameter, and hence permanent, or
  449. * the cbtdisabled consensus parameter, so it may be a new condition.
  450. * Treat it like getting num == 0 above and free the circuit history
  451. * if we have any.
  452. */
  453. circuit_build_times_free_timeouts(cbt);
  454. }
  455. }
  456. /**
  457. * Return the initial default or configured timeout in milliseconds
  458. */
  459. static double
  460. circuit_build_times_get_initial_timeout(void)
  461. {
  462. double timeout;
  463. const or_options_t *options = get_options();
  464. /*
  465. * Check if we have LearnCircuitBuildTimeout, and if we don't,
  466. * always use CircuitBuildTimeout, no questions asked.
  467. */
  468. if (!unit_tests && options->CircuitBuildTimeout) {
  469. timeout = options->CircuitBuildTimeout*1000;
  470. if (!circuit_build_times_disabled(options) &&
  471. timeout < circuit_build_times_min_timeout()) {
  472. log_warn(LD_CIRC, "Config CircuitBuildTimeout too low. Setting to %ds",
  473. circuit_build_times_min_timeout()/1000);
  474. timeout = circuit_build_times_min_timeout();
  475. }
  476. } else {
  477. timeout = circuit_build_times_initial_timeout();
  478. }
  479. return timeout;
  480. }
  481. /**
  482. * Reset the build time state.
  483. *
  484. * Leave estimated parameters, timeout and network liveness intact
  485. * for future use.
  486. */
  487. STATIC void
  488. circuit_build_times_reset(circuit_build_times_t *cbt)
  489. {
  490. memset(cbt->circuit_build_times, 0, sizeof(cbt->circuit_build_times));
  491. cbt->total_build_times = 0;
  492. cbt->build_times_idx = 0;
  493. cbt->have_computed_timeout = 0;
  494. // Reset timeout and close counts
  495. cbt->num_circ_succeeded = 0;
  496. cbt->num_circ_closed = 0;
  497. cbt->num_circ_timeouts = 0;
  498. }
  499. /**
  500. * Initialize the buildtimes structure for first use.
  501. *
  502. * Sets the initial timeout values based on either the config setting,
  503. * the consensus param, or the default (CBT_DEFAULT_TIMEOUT_INITIAL_VALUE).
  504. */
  505. void
  506. circuit_build_times_init(circuit_build_times_t *cbt)
  507. {
  508. memset(cbt, 0, sizeof(*cbt));
  509. /*
  510. * Check if we really are using adaptive timeouts, and don't keep
  511. * track of this stuff if not.
  512. */
  513. if (!circuit_build_times_disabled(get_options())) {
  514. cbt->liveness.num_recent_circs =
  515. circuit_build_times_recent_circuit_count(NULL);
  516. cbt->liveness.timeouts_after_firsthop =
  517. tor_calloc(cbt->liveness.num_recent_circs, sizeof(int8_t));
  518. } else {
  519. cbt->liveness.num_recent_circs = 0;
  520. cbt->liveness.timeouts_after_firsthop = NULL;
  521. }
  522. cbt->close_ms = cbt->timeout_ms = circuit_build_times_get_initial_timeout();
  523. cbt_control_event_buildtimeout_set(cbt, BUILDTIMEOUT_SET_EVENT_RESET);
  524. }
  525. /**
  526. * Free the saved timeouts, if the cbtdisabled consensus parameter got turned
  527. * on or something.
  528. */
  529. void
  530. circuit_build_times_free_timeouts(circuit_build_times_t *cbt)
  531. {
  532. if (!cbt) return;
  533. if (cbt->liveness.timeouts_after_firsthop) {
  534. tor_free(cbt->liveness.timeouts_after_firsthop);
  535. }
  536. cbt->liveness.num_recent_circs = 0;
  537. }
  538. #if 0
  539. /**
  540. * Rewind our build time history by n positions.
  541. */
  542. static void
  543. circuit_build_times_rewind_history(circuit_build_times_t *cbt, int n)
  544. {
  545. int i = 0;
  546. cbt->build_times_idx -= n;
  547. cbt->build_times_idx %= CBT_NCIRCUITS_TO_OBSERVE;
  548. for (i = 0; i < n; i++) {
  549. cbt->circuit_build_times[(i+cbt->build_times_idx)
  550. %CBT_NCIRCUITS_TO_OBSERVE]=0;
  551. }
  552. if (cbt->total_build_times > n) {
  553. cbt->total_build_times -= n;
  554. } else {
  555. cbt->total_build_times = 0;
  556. }
  557. log_info(LD_CIRC,
  558. "Rewound history by %d places. Current index: %d. "
  559. "Total: %d", n, cbt->build_times_idx, cbt->total_build_times);
  560. }
  561. #endif /* 0 */
  562. /**
  563. * Mark this circuit as timed out, but change its purpose
  564. * so that it continues to build, allowing us to measure
  565. * its full build time.
  566. */
  567. void
  568. circuit_build_times_mark_circ_as_measurement_only(origin_circuit_t *circ)
  569. {
  570. control_event_circuit_status(circ,
  571. CIRC_EVENT_FAILED,
  572. END_CIRC_REASON_TIMEOUT);
  573. circuit_change_purpose(TO_CIRCUIT(circ),
  574. CIRCUIT_PURPOSE_C_MEASURE_TIMEOUT);
  575. /* Record this event to check for too many timeouts
  576. * in a row. This function does not record a time value yet
  577. * (we do that later); it only counts the fact that we did
  578. * have a timeout. We also want to avoid double-counting
  579. * already "relaxed" circuits, which are counted in
  580. * circuit_expire_building(). */
  581. if (!circ->relaxed_timeout) {
  582. int first_hop_succeeded = circ->cpath &&
  583. circ->cpath->state == CPATH_STATE_OPEN;
  584. circuit_build_times_count_timeout(
  585. get_circuit_build_times_mutable(),
  586. first_hop_succeeded);
  587. }
  588. }
  589. /**
  590. * Perform the build time work that needs to be done when a circuit
  591. * completes a hop.
  592. *
  593. * This function decides if we should record a circuit's build time
  594. * in our histogram data and other statistics, and if so, records it.
  595. * It also will mark circuits that have already timed out as
  596. * measurement-only circuits, so they can continue to build but
  597. * not get used.
  598. *
  599. * For this, we want to consider circuits that will eventually make
  600. * it to the third hop. For circuits longer than 3 hops, we want to
  601. * record their build time when they reach the third hop, but let
  602. * them continue (and not count them later). For circuits that are
  603. * exactly 3 hops, this will count them when they are completed. We
  604. * do this so that CBT is always gathering statistics on circuits
  605. * of the same length, regardless of their type.
  606. */
  607. void
  608. circuit_build_times_handle_completed_hop(origin_circuit_t *circ)
  609. {
  610. struct timeval end;
  611. long timediff;
  612. /* If circuit build times are disabled, let circuit_expire_building()
  613. * handle it.. */
  614. if (circuit_build_times_disabled(get_options())) {
  615. return;
  616. }
  617. /* Is this a circuit for which the timeout applies in a straight-forward
  618. * way? If so, handle it below. If not, just return (and let
  619. * circuit_expire_building() eventually take care of it).
  620. */
  621. if (!circuit_timeout_want_to_count_circ(circ)) {
  622. return;
  623. }
  624. tor_gettimeofday(&end);
  625. timediff = tv_mdiff(&circ->base_.timestamp_began, &end);
  626. /* Check if we would have timed out already. If so, change the
  627. * purpose here. But don't do any timeout handling here if there
  628. * are no circuits opened yet. Save it for circuit_expire_building()
  629. * (to allow it to handle timeout "relaxing" over there). */
  630. if (timediff > get_circuit_build_timeout_ms() &&
  631. circuit_any_opened_circuits_cached()) {
  632. /* Circuits are allowed to last longer for measurement.
  633. * Switch their purpose and wait. */
  634. if (circ->base_.purpose != CIRCUIT_PURPOSE_C_MEASURE_TIMEOUT) {
  635. log_info(LD_CIRC,
  636. "Deciding to timeout circuit "U64_FORMAT"\n",
  637. U64_PRINTF_ARG(circ->global_identifier));
  638. circuit_build_times_mark_circ_as_measurement_only(circ);
  639. }
  640. }
  641. /* If the circuit is built to exactly the DEFAULT_ROUTE_LEN,
  642. * add it to our buildtimes. */
  643. if (circuit_get_cpath_opened_len(circ) == DEFAULT_ROUTE_LEN) {
  644. /* If the circuit build time is much greater than we would have cut
  645. * it off at, we probably had a suspend event along this codepath,
  646. * and we should discard the value.
  647. */
  648. if (timediff < 0 ||
  649. timediff > 2*get_circuit_build_close_time_ms()+1000) {
  650. log_notice(LD_CIRC, "Strange value for circuit build time: %ldmsec. "
  651. "Assuming clock jump. Purpose %d (%s)", timediff,
  652. circ->base_.purpose,
  653. circuit_purpose_to_string(circ->base_.purpose));
  654. } else {
  655. /* Only count circuit times if the network is live */
  656. if (circuit_build_times_network_check_live(
  657. get_circuit_build_times())) {
  658. circuit_build_times_add_time(get_circuit_build_times_mutable(),
  659. (build_time_t)timediff);
  660. circuit_build_times_set_timeout(get_circuit_build_times_mutable());
  661. }
  662. if (circ->base_.purpose != CIRCUIT_PURPOSE_C_MEASURE_TIMEOUT) {
  663. circuit_build_times_network_circ_success(
  664. get_circuit_build_times_mutable());
  665. }
  666. }
  667. }
  668. }
  669. /**
  670. * Add a new build time value <b>time</b> to the set of build times. Time
  671. * units are milliseconds.
  672. *
  673. * circuit_build_times <b>cbt</b> is a circular array, so loop around when
  674. * array is full.
  675. */
  676. int
  677. circuit_build_times_add_time(circuit_build_times_t *cbt, build_time_t btime)
  678. {
  679. if (btime <= 0 || btime > CBT_BUILD_TIME_MAX) {
  680. log_warn(LD_BUG, "Circuit build time is too large (%u)."
  681. "This is probably a bug.", btime);
  682. tor_fragile_assert();
  683. return -1;
  684. }
  685. log_debug(LD_CIRC, "Adding circuit build time %u", btime);
  686. cbt->circuit_build_times[cbt->build_times_idx] = btime;
  687. cbt->build_times_idx = (cbt->build_times_idx + 1) % CBT_NCIRCUITS_TO_OBSERVE;
  688. if (cbt->total_build_times < CBT_NCIRCUITS_TO_OBSERVE)
  689. cbt->total_build_times++;
  690. if ((cbt->total_build_times % CBT_SAVE_STATE_EVERY) == 0) {
  691. /* Save state every n circuit builds */
  692. if (!unit_tests && !get_options()->AvoidDiskWrites)
  693. or_state_mark_dirty(get_or_state(), 0);
  694. }
  695. return 0;
  696. }
  697. /**
  698. * Return maximum circuit build time
  699. */
  700. static build_time_t
  701. circuit_build_times_max(const circuit_build_times_t *cbt)
  702. {
  703. int i = 0;
  704. build_time_t max_build_time = 0;
  705. for (i = 0; i < CBT_NCIRCUITS_TO_OBSERVE; i++) {
  706. if (cbt->circuit_build_times[i] > max_build_time
  707. && cbt->circuit_build_times[i] != CBT_BUILD_ABANDONED)
  708. max_build_time = cbt->circuit_build_times[i];
  709. }
  710. return max_build_time;
  711. }
  712. #if 0
  713. /** Return minimum circuit build time */
  714. build_time_t
  715. circuit_build_times_min(circuit_build_times_t *cbt)
  716. {
  717. int i = 0;
  718. build_time_t min_build_time = CBT_BUILD_TIME_MAX;
  719. for (i = 0; i < CBT_NCIRCUITS_TO_OBSERVE; i++) {
  720. if (cbt->circuit_build_times[i] && /* 0 <-> uninitialized */
  721. cbt->circuit_build_times[i] < min_build_time)
  722. min_build_time = cbt->circuit_build_times[i];
  723. }
  724. if (min_build_time == CBT_BUILD_TIME_MAX) {
  725. log_warn(LD_CIRC, "No build times less than CBT_BUILD_TIME_MAX!");
  726. }
  727. return min_build_time;
  728. }
  729. #endif /* 0 */
  730. /**
  731. * Calculate and return a histogram for the set of build times.
  732. *
  733. * Returns an allocated array of histrogram bins representing
  734. * the frequency of index*CBT_BIN_WIDTH millisecond
  735. * build times. Also outputs the number of bins in nbins.
  736. *
  737. * The return value must be freed by the caller.
  738. */
  739. static uint32_t *
  740. circuit_build_times_create_histogram(const circuit_build_times_t *cbt,
  741. build_time_t *nbins)
  742. {
  743. uint32_t *histogram;
  744. build_time_t max_build_time = circuit_build_times_max(cbt);
  745. int i, c;
  746. *nbins = 1 + (max_build_time / CBT_BIN_WIDTH);
  747. histogram = tor_calloc(*nbins, sizeof(build_time_t));
  748. // calculate histogram
  749. for (i = 0; i < CBT_NCIRCUITS_TO_OBSERVE; i++) {
  750. if (cbt->circuit_build_times[i] == 0
  751. || cbt->circuit_build_times[i] == CBT_BUILD_ABANDONED)
  752. continue; /* 0 <-> uninitialized */
  753. c = (cbt->circuit_build_times[i] / CBT_BIN_WIDTH);
  754. histogram[c]++;
  755. }
  756. return histogram;
  757. }
  758. /**
  759. * Return the Pareto start-of-curve parameter Xm.
  760. *
  761. * Because we are not a true Pareto curve, we compute this as the
  762. * weighted average of the N most frequent build time bins. N is either
  763. * 1 if we don't have enough circuit build time data collected, or
  764. * determined by the consensus parameter cbtnummodes (default 3).
  765. */
  766. static build_time_t
  767. circuit_build_times_get_xm(circuit_build_times_t *cbt)
  768. {
  769. build_time_t i, nbins;
  770. build_time_t *nth_max_bin;
  771. int32_t bin_counts=0;
  772. build_time_t ret = 0;
  773. uint32_t *histogram = circuit_build_times_create_histogram(cbt, &nbins);
  774. int n=0;
  775. int num_modes = circuit_build_times_default_num_xm_modes();
  776. tor_assert(nbins > 0);
  777. tor_assert(num_modes > 0);
  778. // Only use one mode if < 1000 buildtimes. Not enough data
  779. // for multiple.
  780. if (cbt->total_build_times < CBT_NCIRCUITS_TO_OBSERVE)
  781. num_modes = 1;
  782. nth_max_bin = tor_calloc(num_modes, sizeof(build_time_t));
  783. /* Determine the N most common build times */
  784. for (i = 0; i < nbins; i++) {
  785. if (histogram[i] >= histogram[nth_max_bin[0]]) {
  786. nth_max_bin[0] = i;
  787. }
  788. for (n = 1; n < num_modes; n++) {
  789. if (histogram[i] >= histogram[nth_max_bin[n]] &&
  790. (!histogram[nth_max_bin[n-1]]
  791. || histogram[i] < histogram[nth_max_bin[n-1]])) {
  792. nth_max_bin[n] = i;
  793. }
  794. }
  795. }
  796. for (n = 0; n < num_modes; n++) {
  797. bin_counts += histogram[nth_max_bin[n]];
  798. ret += CBT_BIN_TO_MS(nth_max_bin[n])*histogram[nth_max_bin[n]];
  799. log_info(LD_CIRC, "Xm mode #%d: %u %u", n, CBT_BIN_TO_MS(nth_max_bin[n]),
  800. histogram[nth_max_bin[n]]);
  801. }
  802. /* bin_counts can become zero if all of our last CBT_NCIRCUITS_TO_OBSERVE
  803. * circuits were abandoned before they completed. This shouldn't happen,
  804. * though. We should have reset/re-learned a lower timeout first. */
  805. if (bin_counts == 0) {
  806. ret = 0;
  807. log_warn(LD_CIRC,
  808. "No valid circuit build time data out of %d times, %u modes, "
  809. "have_timeout=%d, %lfms", cbt->total_build_times, num_modes,
  810. cbt->have_computed_timeout, cbt->timeout_ms);
  811. goto done;
  812. }
  813. tor_assert(bin_counts > 0);
  814. ret /= bin_counts;
  815. done:
  816. tor_free(histogram);
  817. tor_free(nth_max_bin);
  818. return ret;
  819. }
  820. /**
  821. * Output a histogram of current circuit build times to
  822. * the or_state_t state structure.
  823. */
  824. void
  825. circuit_build_times_update_state(const circuit_build_times_t *cbt,
  826. or_state_t *state)
  827. {
  828. uint32_t *histogram;
  829. build_time_t i = 0;
  830. build_time_t nbins = 0;
  831. config_line_t **next, *line;
  832. histogram = circuit_build_times_create_histogram(cbt, &nbins);
  833. // write to state
  834. config_free_lines(state->BuildtimeHistogram);
  835. next = &state->BuildtimeHistogram;
  836. *next = NULL;
  837. state->TotalBuildTimes = cbt->total_build_times;
  838. state->CircuitBuildAbandonedCount = 0;
  839. for (i = 0; i < CBT_NCIRCUITS_TO_OBSERVE; i++) {
  840. if (cbt->circuit_build_times[i] == CBT_BUILD_ABANDONED)
  841. state->CircuitBuildAbandonedCount++;
  842. }
  843. for (i = 0; i < nbins; i++) {
  844. // compress the histogram by skipping the blanks
  845. if (histogram[i] == 0) continue;
  846. *next = line = tor_malloc_zero(sizeof(config_line_t));
  847. line->key = tor_strdup("CircuitBuildTimeBin");
  848. tor_asprintf(&line->value, "%d %d",
  849. CBT_BIN_TO_MS(i), histogram[i]);
  850. next = &(line->next);
  851. }
  852. if (!unit_tests) {
  853. if (!get_options()->AvoidDiskWrites)
  854. or_state_mark_dirty(get_or_state(), 0);
  855. }
  856. tor_free(histogram);
  857. }
  858. /**
  859. * Shuffle the build times array.
  860. *
  861. * Adapted from http://en.wikipedia.org/wiki/Fisher-Yates_shuffle
  862. */
  863. static void
  864. circuit_build_times_shuffle_and_store_array(circuit_build_times_t *cbt,
  865. build_time_t *raw_times,
  866. uint32_t num_times)
  867. {
  868. uint32_t n = num_times;
  869. if (num_times > CBT_NCIRCUITS_TO_OBSERVE) {
  870. log_notice(LD_CIRC, "The number of circuit times that this Tor version "
  871. "uses to calculate build times is less than the number stored "
  872. "in your state file. Decreasing the circuit time history from "
  873. "%lu to %d.", (unsigned long)num_times,
  874. CBT_NCIRCUITS_TO_OBSERVE);
  875. }
  876. if (n > INT_MAX-1) {
  877. log_warn(LD_CIRC, "For some insane reasons, you had %lu circuit build "
  878. "observations in your state file. That's far too many; probably "
  879. "there's a bug here.", (unsigned long)n);
  880. n = INT_MAX-1;
  881. }
  882. /* This code can only be run on a compact array */
  883. while (n-- > 1) {
  884. int k = crypto_rand_int(n + 1); /* 0 <= k <= n. */
  885. build_time_t tmp = raw_times[k];
  886. raw_times[k] = raw_times[n];
  887. raw_times[n] = tmp;
  888. }
  889. /* Since the times are now shuffled, take a random CBT_NCIRCUITS_TO_OBSERVE
  890. * subset (ie the first CBT_NCIRCUITS_TO_OBSERVE values) */
  891. for (n = 0; n < MIN(num_times, CBT_NCIRCUITS_TO_OBSERVE); n++) {
  892. circuit_build_times_add_time(cbt, raw_times[n]);
  893. }
  894. }
  895. /**
  896. * Filter old synthetic timeouts that were created before the
  897. * new right-censored Pareto calculation was deployed.
  898. *
  899. * Once all clients before 0.2.1.13-alpha are gone, this code
  900. * will be unused.
  901. */
  902. static int
  903. circuit_build_times_filter_timeouts(circuit_build_times_t *cbt)
  904. {
  905. int num_filtered=0, i=0;
  906. double timeout_rate = 0;
  907. build_time_t max_timeout = 0;
  908. timeout_rate = circuit_build_times_timeout_rate(cbt);
  909. max_timeout = (build_time_t)cbt->close_ms;
  910. for (i = 0; i < CBT_NCIRCUITS_TO_OBSERVE; i++) {
  911. if (cbt->circuit_build_times[i] > max_timeout) {
  912. build_time_t replaced = cbt->circuit_build_times[i];
  913. num_filtered++;
  914. cbt->circuit_build_times[i] = CBT_BUILD_ABANDONED;
  915. log_debug(LD_CIRC, "Replaced timeout %d with %d", replaced,
  916. cbt->circuit_build_times[i]);
  917. }
  918. }
  919. log_info(LD_CIRC,
  920. "We had %d timeouts out of %d build times, "
  921. "and filtered %d above the max of %u",
  922. (int)(cbt->total_build_times*timeout_rate),
  923. cbt->total_build_times, num_filtered, max_timeout);
  924. return num_filtered;
  925. }
  926. /**
  927. * Load histogram from <b>state</b>, shuffling the resulting array
  928. * after we do so. Use this result to estimate parameters and
  929. * calculate the timeout.
  930. *
  931. * Return -1 on error.
  932. */
  933. int
  934. circuit_build_times_parse_state(circuit_build_times_t *cbt,
  935. or_state_t *state)
  936. {
  937. int tot_values = 0;
  938. uint32_t loaded_cnt = 0, N = 0;
  939. config_line_t *line;
  940. int i;
  941. build_time_t *loaded_times;
  942. int err = 0;
  943. circuit_build_times_init(cbt);
  944. if (circuit_build_times_disabled(get_options())) {
  945. return 0;
  946. }
  947. /* build_time_t 0 means uninitialized */
  948. loaded_times = tor_calloc(state->TotalBuildTimes, sizeof(build_time_t));
  949. for (line = state->BuildtimeHistogram; line; line = line->next) {
  950. smartlist_t *args = smartlist_new();
  951. smartlist_split_string(args, line->value, " ",
  952. SPLIT_SKIP_SPACE|SPLIT_IGNORE_BLANK, 0);
  953. if (smartlist_len(args) < 2) {
  954. log_warn(LD_GENERAL, "Unable to parse circuit build times: "
  955. "Too few arguments to CircuitBuildTime");
  956. err = 1;
  957. SMARTLIST_FOREACH(args, char*, cp, tor_free(cp));
  958. smartlist_free(args);
  959. break;
  960. } else {
  961. const char *ms_str = smartlist_get(args,0);
  962. const char *count_str = smartlist_get(args,1);
  963. uint32_t count, k;
  964. build_time_t ms;
  965. int ok;
  966. ms = (build_time_t)tor_parse_ulong(ms_str, 10, 0,
  967. CBT_BUILD_TIME_MAX, &ok, NULL);
  968. if (!ok) {
  969. log_warn(LD_GENERAL, "Unable to parse circuit build times: "
  970. "Unparsable bin number");
  971. err = 1;
  972. SMARTLIST_FOREACH(args, char*, cp, tor_free(cp));
  973. smartlist_free(args);
  974. break;
  975. }
  976. count = (uint32_t)tor_parse_ulong(count_str, 10, 0,
  977. UINT32_MAX, &ok, NULL);
  978. if (!ok) {
  979. log_warn(LD_GENERAL, "Unable to parse circuit build times: "
  980. "Unparsable bin count");
  981. err = 1;
  982. SMARTLIST_FOREACH(args, char*, cp, tor_free(cp));
  983. smartlist_free(args);
  984. break;
  985. }
  986. if (loaded_cnt+count+ (unsigned)state->CircuitBuildAbandonedCount
  987. > (unsigned) state->TotalBuildTimes) {
  988. log_warn(LD_CIRC,
  989. "Too many build times in state file. "
  990. "Stopping short before %d",
  991. loaded_cnt+count);
  992. SMARTLIST_FOREACH(args, char*, cp, tor_free(cp));
  993. smartlist_free(args);
  994. break;
  995. }
  996. for (k = 0; k < count; k++) {
  997. loaded_times[loaded_cnt++] = ms;
  998. }
  999. N++;
  1000. SMARTLIST_FOREACH(args, char*, cp, tor_free(cp));
  1001. smartlist_free(args);
  1002. }
  1003. }
  1004. log_info(LD_CIRC,
  1005. "Adding %d timeouts.", state->CircuitBuildAbandonedCount);
  1006. for (i=0; i < state->CircuitBuildAbandonedCount; i++) {
  1007. loaded_times[loaded_cnt++] = CBT_BUILD_ABANDONED;
  1008. }
  1009. if (loaded_cnt != (unsigned)state->TotalBuildTimes) {
  1010. log_warn(LD_CIRC,
  1011. "Corrupt state file? Build times count mismatch. "
  1012. "Read %d times, but file says %d", loaded_cnt,
  1013. state->TotalBuildTimes);
  1014. err = 1;
  1015. circuit_build_times_reset(cbt);
  1016. goto done;
  1017. }
  1018. circuit_build_times_shuffle_and_store_array(cbt, loaded_times, loaded_cnt);
  1019. /* Verify that we didn't overwrite any indexes */
  1020. for (i=0; i < CBT_NCIRCUITS_TO_OBSERVE; i++) {
  1021. if (!cbt->circuit_build_times[i])
  1022. break;
  1023. tot_values++;
  1024. }
  1025. log_info(LD_CIRC,
  1026. "Loaded %d/%d values from %d lines in circuit time histogram",
  1027. tot_values, cbt->total_build_times, N);
  1028. if (cbt->total_build_times != tot_values
  1029. || cbt->total_build_times > CBT_NCIRCUITS_TO_OBSERVE) {
  1030. log_warn(LD_CIRC,
  1031. "Corrupt state file? Shuffled build times mismatch. "
  1032. "Read %d times, but file says %d", tot_values,
  1033. state->TotalBuildTimes);
  1034. err = 1;
  1035. circuit_build_times_reset(cbt);
  1036. goto done;
  1037. }
  1038. circuit_build_times_set_timeout(cbt);
  1039. if (!state->CircuitBuildAbandonedCount && cbt->total_build_times) {
  1040. circuit_build_times_filter_timeouts(cbt);
  1041. }
  1042. done:
  1043. tor_free(loaded_times);
  1044. return err ? -1 : 0;
  1045. }
  1046. /**
  1047. * Estimates the Xm and Alpha parameters using
  1048. * http://en.wikipedia.org/wiki/Pareto_distribution#Parameter_estimation
  1049. *
  1050. * The notable difference is that we use mode instead of min to estimate Xm.
  1051. * This is because our distribution is frechet-like. We claim this is
  1052. * an acceptable approximation because we are only concerned with the
  1053. * accuracy of the CDF of the tail.
  1054. */
  1055. STATIC int
  1056. circuit_build_times_update_alpha(circuit_build_times_t *cbt)
  1057. {
  1058. build_time_t *x=cbt->circuit_build_times;
  1059. double a = 0;
  1060. int n=0,i=0,abandoned_count=0;
  1061. build_time_t max_time=0;
  1062. /* http://en.wikipedia.org/wiki/Pareto_distribution#Parameter_estimation */
  1063. /* We sort of cheat here and make our samples slightly more pareto-like
  1064. * and less frechet-like. */
  1065. cbt->Xm = circuit_build_times_get_xm(cbt);
  1066. /* If Xm came back 0, then too many circuits were abandoned. */
  1067. if (cbt->Xm == 0)
  1068. return 0;
  1069. tor_assert(cbt->Xm > 0);
  1070. for (i=0; i< CBT_NCIRCUITS_TO_OBSERVE; i++) {
  1071. if (!x[i]) {
  1072. continue;
  1073. }
  1074. if (x[i] < cbt->Xm) {
  1075. a += tor_mathlog(cbt->Xm);
  1076. } else if (x[i] == CBT_BUILD_ABANDONED) {
  1077. abandoned_count++;
  1078. } else {
  1079. a += tor_mathlog(x[i]);
  1080. if (x[i] > max_time)
  1081. max_time = x[i];
  1082. }
  1083. n++;
  1084. }
  1085. /*
  1086. * We are erring and asserting here because this can only happen
  1087. * in codepaths other than startup. The startup state parsing code
  1088. * performs this same check, and resets state if it hits it. If we
  1089. * hit it at runtime, something serious has gone wrong.
  1090. */
  1091. if (n!=cbt->total_build_times) {
  1092. log_err(LD_CIRC, "Discrepancy in build times count: %d vs %d", n,
  1093. cbt->total_build_times);
  1094. }
  1095. tor_assert(n==cbt->total_build_times);
  1096. if (max_time <= 0) {
  1097. /* This can happen if Xm is actually the *maximum* value in the set.
  1098. * It can also happen if we've abandoned every single circuit somehow.
  1099. * In either case, tell the caller not to compute a new build timeout. */
  1100. log_warn(LD_BUG,
  1101. "Could not determine largest build time (%d). "
  1102. "Xm is %dms and we've abandoned %d out of %d circuits.", max_time,
  1103. cbt->Xm, abandoned_count, n);
  1104. return 0;
  1105. }
  1106. a += abandoned_count*tor_mathlog(max_time);
  1107. a -= n*tor_mathlog(cbt->Xm);
  1108. // Estimator comes from Eq #4 in:
  1109. // "Bayesian estimation based on trimmed samples from Pareto populations"
  1110. // by Arturo J. Fernández. We are right-censored only.
  1111. a = (n-abandoned_count)/a;
  1112. cbt->alpha = a;
  1113. return 1;
  1114. }
  1115. /**
  1116. * This is the Pareto Quantile Function. It calculates the point x
  1117. * in the distribution such that F(x) = quantile (ie quantile*100%
  1118. * of the mass of the density function is below x on the curve).
  1119. *
  1120. * We use it to calculate the timeout and also to generate synthetic
  1121. * values of time for circuits that timeout before completion.
  1122. *
  1123. * See http://en.wikipedia.org/wiki/Quantile_function,
  1124. * http://en.wikipedia.org/wiki/Inverse_transform_sampling and
  1125. * http://en.wikipedia.org/wiki/Pareto_distribution#Generating_a_
  1126. * random_sample_from_Pareto_distribution
  1127. * That's right. I'll cite wikipedia all day long.
  1128. *
  1129. * Return value is in milliseconds, clamped to INT32_MAX.
  1130. */
  1131. STATIC double
  1132. circuit_build_times_calculate_timeout(circuit_build_times_t *cbt,
  1133. double quantile)
  1134. {
  1135. double ret;
  1136. tor_assert(quantile >= 0);
  1137. tor_assert(1.0-quantile > 0);
  1138. tor_assert(cbt->Xm > 0);
  1139. /* If either alpha or p are 0, we would divide by zero, yielding an
  1140. * infinite (double) result; which would be clamped to INT32_MAX.
  1141. * Instead, initialise ret to INT32_MAX, and skip over these
  1142. * potentially illegal/trapping divides by zero.
  1143. */
  1144. ret = INT32_MAX;
  1145. if (cbt->alpha > 0) {
  1146. double p;
  1147. p = pow(1.0-quantile,1.0/cbt->alpha);
  1148. if (p > 0) {
  1149. ret = cbt->Xm/p;
  1150. }
  1151. }
  1152. if (ret > INT32_MAX) {
  1153. ret = INT32_MAX;
  1154. }
  1155. tor_assert(ret > 0);
  1156. return ret;
  1157. }
  1158. #ifdef TOR_UNIT_TESTS
  1159. /** Pareto CDF */
  1160. double
  1161. circuit_build_times_cdf(circuit_build_times_t *cbt, double x)
  1162. {
  1163. double ret;
  1164. tor_assert(cbt->Xm > 0);
  1165. ret = 1.0-pow(cbt->Xm/x,cbt->alpha);
  1166. tor_assert(0 <= ret && ret <= 1.0);
  1167. return ret;
  1168. }
  1169. #endif /* defined(TOR_UNIT_TESTS) */
  1170. #ifdef TOR_UNIT_TESTS
  1171. /**
  1172. * Generate a synthetic time using our distribution parameters.
  1173. *
  1174. * The return value will be within the [q_lo, q_hi) quantile points
  1175. * on the CDF.
  1176. */
  1177. build_time_t
  1178. circuit_build_times_generate_sample(circuit_build_times_t *cbt,
  1179. double q_lo, double q_hi)
  1180. {
  1181. double randval = crypto_rand_double();
  1182. build_time_t ret;
  1183. double u;
  1184. /* Generate between [q_lo, q_hi) */
  1185. /*XXXX This is what nextafter is supposed to be for; we should use it on the
  1186. * platforms that support it. */
  1187. q_hi -= 1.0/(INT32_MAX);
  1188. tor_assert(q_lo >= 0);
  1189. tor_assert(q_hi < 1);
  1190. tor_assert(q_lo < q_hi);
  1191. u = q_lo + (q_hi-q_lo)*randval;
  1192. tor_assert(0 <= u && u < 1.0);
  1193. /* circuit_build_times_calculate_timeout returns <= INT32_MAX */
  1194. ret = (build_time_t)
  1195. tor_lround(circuit_build_times_calculate_timeout(cbt, u));
  1196. tor_assert(ret > 0);
  1197. return ret;
  1198. }
  1199. #endif /* defined(TOR_UNIT_TESTS) */
  1200. #ifdef TOR_UNIT_TESTS
  1201. /**
  1202. * Estimate an initial alpha parameter by solving the quantile
  1203. * function with a quantile point and a specific timeout value.
  1204. */
  1205. void
  1206. circuit_build_times_initial_alpha(circuit_build_times_t *cbt,
  1207. double quantile, double timeout_ms)
  1208. {
  1209. // Q(u) = Xm/((1-u)^(1/a))
  1210. // Q(0.8) = Xm/((1-0.8))^(1/a)) = CircBuildTimeout
  1211. // CircBuildTimeout = Xm/((1-0.8))^(1/a))
  1212. // CircBuildTimeout = Xm*((1-0.8))^(-1/a))
  1213. // ln(CircBuildTimeout) = ln(Xm)+ln(((1-0.8)))*(-1/a)
  1214. // -ln(1-0.8)/(ln(CircBuildTimeout)-ln(Xm))=a
  1215. tor_assert(quantile >= 0);
  1216. tor_assert(cbt->Xm > 0);
  1217. cbt->alpha = tor_mathlog(1.0-quantile)/
  1218. (tor_mathlog(cbt->Xm)-tor_mathlog(timeout_ms));
  1219. tor_assert(cbt->alpha > 0);
  1220. }
  1221. #endif /* defined(TOR_UNIT_TESTS) */
  1222. /**
  1223. * Returns true if we need circuits to be built
  1224. */
  1225. int
  1226. circuit_build_times_needs_circuits(const circuit_build_times_t *cbt)
  1227. {
  1228. /* Return true if < MIN_CIRCUITS_TO_OBSERVE */
  1229. return !circuit_build_times_enough_to_compute(cbt);
  1230. }
  1231. /**
  1232. * Returns true if we should build a timeout test circuit
  1233. * right now.
  1234. */
  1235. int
  1236. circuit_build_times_needs_circuits_now(const circuit_build_times_t *cbt)
  1237. {
  1238. return circuit_build_times_needs_circuits(cbt) &&
  1239. approx_time()-cbt->last_circ_at > circuit_build_times_test_frequency();
  1240. }
  1241. /**
  1242. * How long should we be unreachable before we think we need to check if
  1243. * our published IP address has changed.
  1244. */
  1245. #define CIRCUIT_TIMEOUT_BEFORE_RECHECK_IP (60*3)
  1246. /**
  1247. * Called to indicate that the network showed some signs of liveness,
  1248. * i.e. we received a cell.
  1249. *
  1250. * This is used by circuit_build_times_network_check_live() to decide
  1251. * if we should record the circuit build timeout or not.
  1252. *
  1253. * This function is called every time we receive a cell. Avoid
  1254. * syscalls, events, and other high-intensity work.
  1255. */
  1256. void
  1257. circuit_build_times_network_is_live(circuit_build_times_t *cbt)
  1258. {
  1259. time_t now = approx_time();
  1260. if (cbt->liveness.nonlive_timeouts > 0) {
  1261. time_t time_since_live = now - cbt->liveness.network_last_live;
  1262. log_notice(LD_CIRC,
  1263. "Tor now sees network activity. Restoring circuit build "
  1264. "timeout recording. Network was down for %d seconds "
  1265. "during %d circuit attempts.",
  1266. (int)time_since_live,
  1267. cbt->liveness.nonlive_timeouts);
  1268. if (time_since_live > CIRCUIT_TIMEOUT_BEFORE_RECHECK_IP)
  1269. reschedule_descriptor_update_check();
  1270. }
  1271. cbt->liveness.network_last_live = now;
  1272. cbt->liveness.nonlive_timeouts = 0;
  1273. /* Tell control.c */
  1274. control_event_network_liveness_update(1);
  1275. }
  1276. /**
  1277. * Non-destructively scale all of our circuit success, timeout, and close
  1278. * counts down by a factor of two. Scaling in this way preserves the
  1279. * ratios between succeeded vs timed out vs closed circuits, so that
  1280. * our statistics don't change when we scale.
  1281. *
  1282. * This is used only in the rare event that we build more than
  1283. * INT32_MAX circuits. Since the num_circ_* variables are
  1284. * uint32_t, we won't even be close to overflowing them.
  1285. */
  1286. void
  1287. circuit_build_times_scale_circ_counts(circuit_build_times_t *cbt)
  1288. {
  1289. cbt->num_circ_succeeded /= 2;
  1290. cbt->num_circ_timeouts /= 2;
  1291. cbt->num_circ_closed /= 2;
  1292. }
  1293. /**
  1294. * Called to indicate that we "completed" a circuit. Because this circuit
  1295. * succeeded, it doesn't count as a timeout-after-the-first-hop.
  1296. *
  1297. * (For the purposes of the cbt code, we consider a circuit "completed" if
  1298. * it has 3 hops, regardless of its final hop count. We do this because
  1299. * we're trying to answer the question, "how long should a circuit take to
  1300. * reach the 3-hop count".)
  1301. *
  1302. * This is used by circuit_build_times_network_check_changed() to determine
  1303. * if we had too many recent timeouts and need to reset our learned timeout
  1304. * to something higher.
  1305. */
  1306. void
  1307. circuit_build_times_network_circ_success(circuit_build_times_t *cbt)
  1308. {
  1309. // Count circuit success
  1310. cbt->num_circ_succeeded++;
  1311. // If we're going to wrap int32, scale everything
  1312. if (cbt->num_circ_succeeded >= INT32_MAX) {
  1313. circuit_build_times_scale_circ_counts(cbt);
  1314. }
  1315. /* Check for NULLness because we might not be using adaptive timeouts */
  1316. if (cbt->liveness.timeouts_after_firsthop &&
  1317. cbt->liveness.num_recent_circs > 0) {
  1318. cbt->liveness.timeouts_after_firsthop[cbt->liveness.after_firsthop_idx]
  1319. = 0;
  1320. cbt->liveness.after_firsthop_idx++;
  1321. cbt->liveness.after_firsthop_idx %= cbt->liveness.num_recent_circs;
  1322. }
  1323. }
  1324. /**
  1325. * A circuit just timed out. If it failed after the first hop, record it
  1326. * in our history for later deciding if the network speed has changed.
  1327. *
  1328. * This is used by circuit_build_times_network_check_changed() to determine
  1329. * if we had too many recent timeouts and need to reset our learned timeout
  1330. * to something higher.
  1331. */
  1332. static void
  1333. circuit_build_times_network_timeout(circuit_build_times_t *cbt,
  1334. int did_onehop)
  1335. {
  1336. // Count circuit timeout
  1337. cbt->num_circ_timeouts++;
  1338. // If we're going to wrap int32, scale everything
  1339. if (cbt->num_circ_timeouts >= INT32_MAX) {
  1340. circuit_build_times_scale_circ_counts(cbt);
  1341. }
  1342. /* Check for NULLness because we might not be using adaptive timeouts */
  1343. if (cbt->liveness.timeouts_after_firsthop &&
  1344. cbt->liveness.num_recent_circs > 0) {
  1345. if (did_onehop) {
  1346. cbt->liveness.timeouts_after_firsthop[cbt->liveness.after_firsthop_idx]
  1347. = 1;
  1348. cbt->liveness.after_firsthop_idx++;
  1349. cbt->liveness.after_firsthop_idx %= cbt->liveness.num_recent_circs;
  1350. }
  1351. }
  1352. }
  1353. /**
  1354. * A circuit was just forcibly closed. If there has been no recent network
  1355. * activity at all, but this circuit was launched back when we thought the
  1356. * network was live, increment the number of "nonlive" circuit timeouts.
  1357. *
  1358. * This is used by circuit_build_times_network_check_live() to decide
  1359. * if we should record the circuit build timeout or not.
  1360. */
  1361. static void
  1362. circuit_build_times_network_close(circuit_build_times_t *cbt,
  1363. int did_onehop, time_t start_time)
  1364. {
  1365. time_t now = time(NULL);
  1366. // Count circuit close
  1367. cbt->num_circ_closed++;
  1368. // If we're going to wrap int32, scale everything
  1369. if (cbt->num_circ_closed >= INT32_MAX) {
  1370. circuit_build_times_scale_circ_counts(cbt);
  1371. }
  1372. /*
  1373. * Check if this is a timeout that was for a circuit that spent its
  1374. * entire existence during a time where we have had no network activity.
  1375. */
  1376. if (cbt->liveness.network_last_live < start_time) {
  1377. if (did_onehop) {
  1378. char last_live_buf[ISO_TIME_LEN+1];
  1379. char start_time_buf[ISO_TIME_LEN+1];
  1380. char now_buf[ISO_TIME_LEN+1];
  1381. format_local_iso_time(last_live_buf, cbt->liveness.network_last_live);
  1382. format_local_iso_time(start_time_buf, start_time);
  1383. format_local_iso_time(now_buf, now);
  1384. log_notice(LD_CIRC,
  1385. "A circuit somehow completed a hop while the network was "
  1386. "not live. The network was last live at %s, but the circuit "
  1387. "launched at %s. It's now %s. This could mean your clock "
  1388. "changed.", last_live_buf, start_time_buf, now_buf);
  1389. }
  1390. cbt->liveness.nonlive_timeouts++;
  1391. if (cbt->liveness.nonlive_timeouts == 1) {
  1392. log_notice(LD_CIRC,
  1393. "Tor has not observed any network activity for the past %d "
  1394. "seconds. Disabling circuit build timeout recording.",
  1395. (int)(now - cbt->liveness.network_last_live));
  1396. /* Tell control.c */
  1397. control_event_network_liveness_update(0);
  1398. } else {
  1399. log_info(LD_CIRC,
  1400. "Got non-live timeout. Current count is: %d",
  1401. cbt->liveness.nonlive_timeouts);
  1402. }
  1403. }
  1404. }
  1405. /**
  1406. * When the network is not live, we do not record circuit build times.
  1407. *
  1408. * The network is considered not live if there has been at least one
  1409. * circuit build that began and ended (had its close_ms measurement
  1410. * period expire) since we last received a cell.
  1411. *
  1412. * Also has the side effect of rewinding the circuit time history
  1413. * in the case of recent liveness changes.
  1414. */
  1415. int
  1416. circuit_build_times_network_check_live(const circuit_build_times_t *cbt)
  1417. {
  1418. if (cbt->liveness.nonlive_timeouts > 0) {
  1419. return 0;
  1420. }
  1421. return 1;
  1422. }
  1423. /**
  1424. * Returns true if we have seen more than MAX_RECENT_TIMEOUT_COUNT of
  1425. * the past RECENT_CIRCUITS time out after the first hop. Used to detect
  1426. * if the network connection has changed significantly, and if so,
  1427. * resets our circuit build timeout to the default.
  1428. *
  1429. * Also resets the entire timeout history in this case and causes us
  1430. * to restart the process of building test circuits and estimating a
  1431. * new timeout.
  1432. */
  1433. STATIC int
  1434. circuit_build_times_network_check_changed(circuit_build_times_t *cbt)
  1435. {
  1436. int total_build_times = cbt->total_build_times;
  1437. int timeout_count=0;
  1438. int i;
  1439. if (cbt->liveness.timeouts_after_firsthop &&
  1440. cbt->liveness.num_recent_circs > 0) {
  1441. /* how many of our recent circuits made it to the first hop but then
  1442. * timed out? */
  1443. for (i = 0; i < cbt->liveness.num_recent_circs; i++) {
  1444. timeout_count += cbt->liveness.timeouts_after_firsthop[i];
  1445. }
  1446. }
  1447. /* If 80% of our recent circuits are timing out after the first hop,
  1448. * we need to re-estimate a new initial alpha and timeout. */
  1449. if (timeout_count < circuit_build_times_max_timeouts()) {
  1450. return 0;
  1451. }
  1452. circuit_build_times_reset(cbt);
  1453. if (cbt->liveness.timeouts_after_firsthop &&
  1454. cbt->liveness.num_recent_circs > 0) {
  1455. memset(cbt->liveness.timeouts_after_firsthop, 0,
  1456. sizeof(*cbt->liveness.timeouts_after_firsthop)*
  1457. cbt->liveness.num_recent_circs);
  1458. }
  1459. cbt->liveness.after_firsthop_idx = 0;
  1460. #define MAX_TIMEOUT ((int32_t) (INT32_MAX/2))
  1461. /* Check to see if this has happened before. If so, double the timeout
  1462. * to give clients on abysmally bad network connections a shot at access */
  1463. if (cbt->timeout_ms >= circuit_build_times_get_initial_timeout()) {
  1464. if (cbt->timeout_ms > MAX_TIMEOUT || cbt->close_ms > MAX_TIMEOUT) {
  1465. log_warn(LD_CIRC, "Insanely large circuit build timeout value. "
  1466. "(timeout = %fmsec, close = %fmsec)",
  1467. cbt->timeout_ms, cbt->close_ms);
  1468. } else {
  1469. cbt->timeout_ms *= 2;
  1470. cbt->close_ms *= 2;
  1471. }
  1472. } else {
  1473. cbt->close_ms = cbt->timeout_ms
  1474. = circuit_build_times_get_initial_timeout();
  1475. }
  1476. #undef MAX_TIMEOUT
  1477. cbt_control_event_buildtimeout_set(cbt, BUILDTIMEOUT_SET_EVENT_RESET);
  1478. log_notice(LD_CIRC,
  1479. "Your network connection speed appears to have changed. Resetting "
  1480. "timeout to %lds after %d timeouts and %d buildtimes.",
  1481. tor_lround(cbt->timeout_ms/1000), timeout_count,
  1482. total_build_times);
  1483. return 1;
  1484. }
  1485. /**
  1486. * Count the number of timeouts in a set of cbt data.
  1487. */
  1488. double
  1489. circuit_build_times_timeout_rate(const circuit_build_times_t *cbt)
  1490. {
  1491. int i=0,timeouts=0;
  1492. for (i = 0; i < CBT_NCIRCUITS_TO_OBSERVE; i++) {
  1493. if (cbt->circuit_build_times[i] >= cbt->timeout_ms) {
  1494. timeouts++;
  1495. }
  1496. }
  1497. if (!cbt->total_build_times)
  1498. return 0;
  1499. return ((double)timeouts)/cbt->total_build_times;
  1500. }
  1501. /**
  1502. * Count the number of closed circuits in a set of cbt data.
  1503. */
  1504. double
  1505. circuit_build_times_close_rate(const circuit_build_times_t *cbt)
  1506. {
  1507. int i=0,closed=0;
  1508. for (i = 0; i < CBT_NCIRCUITS_TO_OBSERVE; i++) {
  1509. if (cbt->circuit_build_times[i] == CBT_BUILD_ABANDONED) {
  1510. closed++;
  1511. }
  1512. }
  1513. if (!cbt->total_build_times)
  1514. return 0;
  1515. return ((double)closed)/cbt->total_build_times;
  1516. }
  1517. /**
  1518. * Store a timeout as a synthetic value.
  1519. *
  1520. * Returns true if the store was successful and we should possibly
  1521. * update our timeout estimate.
  1522. */
  1523. int
  1524. circuit_build_times_count_close(circuit_build_times_t *cbt,
  1525. int did_onehop,
  1526. time_t start_time)
  1527. {
  1528. if (circuit_build_times_disabled(get_options())) {
  1529. cbt->close_ms = cbt->timeout_ms
  1530. = circuit_build_times_get_initial_timeout();
  1531. return 0;
  1532. }
  1533. /* Record this force-close to help determine if the network is dead */
  1534. circuit_build_times_network_close(cbt, did_onehop, start_time);
  1535. /* Only count timeouts if network is live.. */
  1536. if (!circuit_build_times_network_check_live(cbt)) {
  1537. return 0;
  1538. }
  1539. circuit_build_times_add_time(cbt, CBT_BUILD_ABANDONED);
  1540. return 1;
  1541. }
  1542. /**
  1543. * Update timeout counts to determine if we need to expire
  1544. * our build time history due to excessive timeouts.
  1545. *
  1546. * We do not record any actual time values at this stage;
  1547. * we are only interested in recording the fact that a timeout
  1548. * happened. We record the time values via
  1549. * circuit_build_times_count_close() and circuit_build_times_add_time().
  1550. */
  1551. void
  1552. circuit_build_times_count_timeout(circuit_build_times_t *cbt,
  1553. int did_onehop)
  1554. {
  1555. if (circuit_build_times_disabled(get_options())) {
  1556. cbt->close_ms = cbt->timeout_ms
  1557. = circuit_build_times_get_initial_timeout();
  1558. return;
  1559. }
  1560. /* Register the fact that a timeout just occurred. */
  1561. circuit_build_times_network_timeout(cbt, did_onehop);
  1562. /* If there are a ton of timeouts, we should reset
  1563. * the circuit build timeout. */
  1564. circuit_build_times_network_check_changed(cbt);
  1565. }
  1566. /**
  1567. * Estimate a new timeout based on history and set our timeout
  1568. * variable accordingly.
  1569. */
  1570. static int
  1571. circuit_build_times_set_timeout_worker(circuit_build_times_t *cbt)
  1572. {
  1573. build_time_t max_time;
  1574. if (!circuit_build_times_enough_to_compute(cbt))
  1575. return 0;
  1576. if (!circuit_build_times_update_alpha(cbt))
  1577. return 0;
  1578. cbt->timeout_ms = circuit_build_times_calculate_timeout(cbt,
  1579. circuit_build_times_quantile_cutoff());
  1580. cbt->close_ms = circuit_build_times_calculate_timeout(cbt,
  1581. circuit_build_times_close_quantile());
  1582. max_time = circuit_build_times_max(cbt);
  1583. if (cbt->timeout_ms > max_time) {
  1584. log_info(LD_CIRC,
  1585. "Circuit build timeout of %dms is beyond the maximum build "
  1586. "time we have ever observed. Capping it to %dms.",
  1587. (int)cbt->timeout_ms, max_time);
  1588. cbt->timeout_ms = max_time;
  1589. }
  1590. if (max_time < INT32_MAX/2 && cbt->close_ms > 2*max_time) {
  1591. log_info(LD_CIRC,
  1592. "Circuit build measurement period of %dms is more than twice "
  1593. "the maximum build time we have ever observed. Capping it to "
  1594. "%dms.", (int)cbt->close_ms, 2*max_time);
  1595. cbt->close_ms = 2*max_time;
  1596. }
  1597. /* Sometimes really fast guard nodes give us such a steep curve
  1598. * that this ends up being not that much greater than timeout_ms.
  1599. * Make it be at least 1 min to handle this case. */
  1600. cbt->close_ms = MAX(cbt->close_ms, circuit_build_times_initial_timeout());
  1601. cbt->have_computed_timeout = 1;
  1602. return 1;
  1603. }
  1604. /**
  1605. * Exposed function to compute a new timeout. Dispatches events and
  1606. * also filters out extremely high timeout values.
  1607. */
  1608. void
  1609. circuit_build_times_set_timeout(circuit_build_times_t *cbt)
  1610. {
  1611. long prev_timeout = tor_lround(cbt->timeout_ms/1000);
  1612. double timeout_rate;
  1613. /*
  1614. * Just return if we aren't using adaptive timeouts
  1615. */
  1616. if (circuit_build_times_disabled(get_options()))
  1617. return;
  1618. if (!circuit_build_times_set_timeout_worker(cbt))
  1619. return;
  1620. if (cbt->timeout_ms < circuit_build_times_min_timeout()) {
  1621. log_info(LD_CIRC, "Set buildtimeout to low value %fms. Setting to %dms",
  1622. cbt->timeout_ms, circuit_build_times_min_timeout());
  1623. cbt->timeout_ms = circuit_build_times_min_timeout();
  1624. if (cbt->close_ms < cbt->timeout_ms) {
  1625. /* This shouldn't happen because of MAX() in timeout_worker above,
  1626. * but doing it just in case */
  1627. cbt->close_ms = circuit_build_times_initial_timeout();
  1628. }
  1629. }
  1630. cbt_control_event_buildtimeout_set(cbt, BUILDTIMEOUT_SET_EVENT_COMPUTED);
  1631. timeout_rate = circuit_build_times_timeout_rate(cbt);
  1632. if (prev_timeout > tor_lround(cbt->timeout_ms/1000)) {
  1633. log_info(LD_CIRC,
  1634. "Based on %d circuit times, it looks like we don't need to "
  1635. "wait so long for circuits to finish. We will now assume a "
  1636. "circuit is too slow to use after waiting %ld seconds.",
  1637. cbt->total_build_times,
  1638. tor_lround(cbt->timeout_ms/1000));
  1639. log_info(LD_CIRC,
  1640. "Circuit timeout data: %fms, %fms, Xm: %d, a: %f, r: %f",
  1641. cbt->timeout_ms, cbt->close_ms, cbt->Xm, cbt->alpha,
  1642. timeout_rate);
  1643. } else if (prev_timeout < tor_lround(cbt->timeout_ms/1000)) {
  1644. log_info(LD_CIRC,
  1645. "Based on %d circuit times, it looks like we need to wait "
  1646. "longer for circuits to finish. We will now assume a "
  1647. "circuit is too slow to use after waiting %ld seconds.",
  1648. cbt->total_build_times,
  1649. tor_lround(cbt->timeout_ms/1000));
  1650. log_info(LD_CIRC,
  1651. "Circuit timeout data: %fms, %fms, Xm: %d, a: %f, r: %f",
  1652. cbt->timeout_ms, cbt->close_ms, cbt->Xm, cbt->alpha,
  1653. timeout_rate);
  1654. } else {
  1655. log_info(LD_CIRC,
  1656. "Set circuit build timeout to %lds (%fms, %fms, Xm: %d, a: %f,"
  1657. " r: %f) based on %d circuit times",
  1658. tor_lround(cbt->timeout_ms/1000),
  1659. cbt->timeout_ms, cbt->close_ms, cbt->Xm, cbt->alpha, timeout_rate,
  1660. cbt->total_build_times);
  1661. }
  1662. }
  1663. #ifdef TOR_UNIT_TESTS
  1664. /** Make a note that we're running unit tests (rather than running Tor
  1665. * itself), so we avoid clobbering our state file. */
  1666. void
  1667. circuitbuild_running_unit_tests(void)
  1668. {
  1669. unit_tests = 1;
  1670. }
  1671. #endif /* defined(TOR_UNIT_TESTS) */
  1672. void
  1673. circuit_build_times_update_last_circ(circuit_build_times_t *cbt)
  1674. {
  1675. cbt->last_circ_at = approx_time();
  1676. }
  1677. static void
  1678. cbt_control_event_buildtimeout_set(const circuit_build_times_t *cbt,
  1679. buildtimeout_set_event_t type)
  1680. {
  1681. char *args = NULL;
  1682. double qnt;
  1683. double timeout_rate = 0.0;
  1684. double close_rate = 0.0;
  1685. switch (type) {
  1686. case BUILDTIMEOUT_SET_EVENT_RESET:
  1687. case BUILDTIMEOUT_SET_EVENT_SUSPENDED:
  1688. case BUILDTIMEOUT_SET_EVENT_DISCARD:
  1689. qnt = 1.0;
  1690. break;
  1691. case BUILDTIMEOUT_SET_EVENT_COMPUTED:
  1692. case BUILDTIMEOUT_SET_EVENT_RESUME:
  1693. default:
  1694. qnt = circuit_build_times_quantile_cutoff();
  1695. break;
  1696. }
  1697. /* The timeout rate is the ratio of the timeout count over
  1698. * the total number of circuits attempted. The total number of
  1699. * circuits is (timeouts+succeeded), since every circuit
  1700. * either succeeds, or times out. "Closed" circuits are
  1701. * MEASURE_TIMEOUT circuits whose measurement period expired.
  1702. * All MEASURE_TIMEOUT circuits are counted in the timeouts stat
  1703. * before transitioning to MEASURE_TIMEOUT (in
  1704. * circuit_build_times_mark_circ_as_measurement_only()).
  1705. * MEASURE_TIMEOUT circuits that succeed are *not* counted as
  1706. * "succeeded". See circuit_build_times_handle_completed_hop().
  1707. *
  1708. * We cast the denominator
  1709. * to promote it to double before the addition, to avoid int32
  1710. * overflow. */
  1711. const double total_circuits =
  1712. ((double)cbt->num_circ_timeouts) + cbt->num_circ_succeeded;
  1713. if (total_circuits >= 1.0) {
  1714. timeout_rate = cbt->num_circ_timeouts / total_circuits;
  1715. close_rate = cbt->num_circ_closed / total_circuits;
  1716. }
  1717. tor_asprintf(&args, "TOTAL_TIMES=%lu "
  1718. "TIMEOUT_MS=%lu XM=%lu ALPHA=%f CUTOFF_QUANTILE=%f "
  1719. "TIMEOUT_RATE=%f CLOSE_MS=%lu CLOSE_RATE=%f",
  1720. (unsigned long)cbt->total_build_times,
  1721. (unsigned long)cbt->timeout_ms,
  1722. (unsigned long)cbt->Xm, cbt->alpha, qnt,
  1723. timeout_rate,
  1724. (unsigned long)cbt->close_ms,
  1725. close_rate);
  1726. control_event_buildtimeout_set(type, args);
  1727. tor_free(args);
  1728. }