circuitstats.c 62 KB

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