circuitstats.c 49 KB

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