test_stats.c (30623B)
1 /* Copyright (c) 2001-2004, Roger Dingledine. 2 * Copyright (c) 2004-2006, Roger Dingledine, Nick Mathewson. 3 * Copyright (c) 2007-2021, The Tor Project, Inc. */ 4 /* See LICENSE for licensing information */ 5 6 /** 7 * \file test_stats.c 8 * \brief Unit tests for the statistics (reputation history) module. 9 **/ 10 11 #include "orconfig.h" 12 #include "lib/crypt_ops/crypto_rand.h" 13 #include "app/config/or_state_st.h" 14 #include "test/rng_test_helpers.h" 15 #include "feature/hs/hs_cache.h" 16 #include "test/hs_test_helpers.h" 17 18 #include <stdio.h> 19 20 #ifdef _WIN32 21 /* For mkdir() */ 22 #include <direct.h> 23 #else 24 #include <dirent.h> 25 #endif /* defined(_WIN32) */ 26 27 #include <math.h> 28 29 /* These macros pull in declarations for some functions and structures that 30 * are typically file-private. */ 31 #define CIRCUITSTATS_PRIVATE 32 #define CIRCUITLIST_PRIVATE 33 #define MAINLOOP_PRIVATE 34 #define STATEFILE_PRIVATE 35 #define BWHIST_PRIVATE 36 #define REPHIST_PRIVATE 37 #define ROUTER_PRIVATE 38 39 #include "core/or/or.h" 40 #include "lib/err/backtrace.h" 41 #include "lib/buf/buffers.h" 42 #include "core/or/circuitstats.h" 43 #include "app/config/config.h" 44 #include "test/test.h" 45 #include "core/mainloop/mainloop.h" 46 #include "lib/memarea/memarea.h" 47 #include "feature/stats/connstats.h" 48 #include "feature/stats/rephist.h" 49 #include "app/config/statefile.h" 50 #include "feature/stats/bwhist.h" 51 #include "feature/stats/bw_array_st.h" 52 #include "feature/relay/router.h" 53 54 #include <event2/dns.h> 55 56 /** Run unit tests for some stats code. */ 57 static void 58 test_stats(void *arg) 59 { 60 time_t now = 1281533250; /* 2010-08-11 13:27:30 UTC */ 61 char *s = NULL; 62 int i; 63 64 /* Start with testing exit port statistics; we shouldn't collect exit 65 * stats without initializing them. */ 66 (void)arg; 67 rep_hist_note_exit_stream_opened(80); 68 rep_hist_note_exit_bytes(80, 100, 10000); 69 s = rep_hist_format_exit_stats(now + 86400); 70 tt_ptr_op(s, OP_EQ, NULL); 71 72 /* Initialize stats, note some streams and bytes, and generate history 73 * string. */ 74 rep_hist_exit_stats_init(now); 75 rep_hist_note_exit_stream_opened(80); 76 rep_hist_note_exit_bytes(80, 100, 10000); 77 rep_hist_note_exit_stream_opened(443); 78 rep_hist_note_exit_bytes(443, 100, 10000); 79 rep_hist_note_exit_bytes(443, 100, 10000); 80 s = rep_hist_format_exit_stats(now + 86400); 81 tt_str_op("exit-stats-end 2010-08-12 13:27:30 (86400 s)\n" 82 "exit-kibibytes-written 80=1,443=1,other=0\n" 83 "exit-kibibytes-read 80=10,443=20,other=0\n" 84 "exit-streams-opened 80=4,443=4,other=0\n",OP_EQ, s); 85 tor_free(s); 86 87 /* Add a few bytes on 10 more ports and ensure that only the top 10 88 * ports are contained in the history string. */ 89 for (i = 50; i < 60; i++) { 90 rep_hist_note_exit_bytes(i, i, i); 91 rep_hist_note_exit_stream_opened(i); 92 } 93 s = rep_hist_format_exit_stats(now + 86400); 94 tt_str_op("exit-stats-end 2010-08-12 13:27:30 (86400 s)\n" 95 "exit-kibibytes-written 52=1,53=1,54=1,55=1,56=1,57=1,58=1," 96 "59=1,80=1,443=1,other=1\n" 97 "exit-kibibytes-read 52=1,53=1,54=1,55=1,56=1,57=1,58=1," 98 "59=1,80=10,443=20,other=1\n" 99 "exit-streams-opened 52=4,53=4,54=4,55=4,56=4,57=4,58=4," 100 "59=4,80=4,443=4,other=4\n",OP_EQ, s); 101 tor_free(s); 102 103 /* Stop collecting stats, add some bytes, and ensure we don't generate 104 * a history string. */ 105 rep_hist_exit_stats_term(); 106 rep_hist_note_exit_bytes(80, 100, 10000); 107 s = rep_hist_format_exit_stats(now + 86400); 108 tt_ptr_op(s, OP_EQ, NULL); 109 110 /* Re-start stats, add some bytes, reset stats, and see what history we 111 * get when observing no streams or bytes at all. */ 112 rep_hist_exit_stats_init(now); 113 rep_hist_note_exit_stream_opened(80); 114 rep_hist_note_exit_bytes(80, 100, 10000); 115 rep_hist_reset_exit_stats(now); 116 s = rep_hist_format_exit_stats(now + 86400); 117 tt_str_op("exit-stats-end 2010-08-12 13:27:30 (86400 s)\n" 118 "exit-kibibytes-written other=0\n" 119 "exit-kibibytes-read other=0\n" 120 "exit-streams-opened other=0\n",OP_EQ, s); 121 tor_free(s); 122 123 /* Continue with testing connection statistics; we shouldn't collect 124 * conn stats without initializing them. */ 125 conn_stats_note_or_conn_bytes(1, 20, 400, now, false); 126 s = conn_stats_format(now + 86400); 127 tt_ptr_op(s, OP_EQ, NULL); 128 129 /* Initialize stats, note bytes, and generate history string. */ 130 conn_stats_init(now); 131 conn_stats_note_or_conn_bytes(1, 30000, 400000, now, false); 132 conn_stats_note_or_conn_bytes(1, 30000, 400000, now + 5, false); 133 conn_stats_note_or_conn_bytes(2, 400000, 30000, now + 10, true); 134 conn_stats_note_or_conn_bytes(2, 400000, 30000, now + 15, true); 135 s = conn_stats_format(now + 86400); 136 tt_str_op("conn-bi-direct 2010-08-12 13:27:30 (86400 s) 0,0,1,0\n" 137 "ipv6-conn-bi-direct 2010-08-12 13:27:30 (86400 s) 0,0,0,0\n", 138 OP_EQ, s); 139 tor_free(s); 140 141 /* Stop collecting stats, add some bytes, and ensure we don't generate 142 * a history string. */ 143 conn_stats_terminate(); 144 conn_stats_note_or_conn_bytes(2, 400000, 30000, now + 15, true); 145 s = conn_stats_format(now + 86400); 146 tt_ptr_op(s, OP_EQ, NULL); 147 148 /* Re-start stats, add some bytes, reset stats, and see what history we 149 * get when observing no bytes at all. */ 150 conn_stats_init(now); 151 conn_stats_note_or_conn_bytes(1, 30000, 400000, now, false); 152 conn_stats_note_or_conn_bytes(1, 30000, 400000, now + 5, false); 153 conn_stats_note_or_conn_bytes(2, 400000, 30000, now + 10, true); 154 conn_stats_note_or_conn_bytes(2, 400000, 30000, now + 15, true); 155 conn_stats_reset(now); 156 s = conn_stats_format(now + 86400); 157 tt_str_op("conn-bi-direct 2010-08-12 13:27:30 (86400 s) 0,0,0,0\n" 158 "ipv6-conn-bi-direct 2010-08-12 13:27:30 (86400 s) 0,0,0,0\n", 159 OP_EQ, s); 160 tor_free(s); 161 162 /* Continue with testing buffer statistics; we shouldn't collect buffer 163 * stats without initializing them. */ 164 rep_hist_add_buffer_stats(2.0, 2.0, 20); 165 s = rep_hist_format_buffer_stats(now + 86400); 166 tt_ptr_op(s, OP_EQ, NULL); 167 168 /* Initialize stats, add statistics for a single circuit, and generate 169 * the history string. */ 170 rep_hist_buffer_stats_init(now); 171 rep_hist_add_buffer_stats(2.0, 2.0, 20); 172 s = rep_hist_format_buffer_stats(now + 86400); 173 tt_str_op("cell-stats-end 2010-08-12 13:27:30 (86400 s)\n" 174 "cell-processed-cells 20,0,0,0,0,0,0,0,0,0\n" 175 "cell-queued-cells 2.00,0.00,0.00,0.00,0.00,0.00,0.00,0.00," 176 "0.00,0.00\n" 177 "cell-time-in-queue 2,0,0,0,0,0,0,0,0,0\n" 178 "cell-circuits-per-decile 1\n",OP_EQ, s); 179 tor_free(s); 180 181 /* Add nineteen more circuit statistics to the one that's already in the 182 * history to see that the math works correctly. */ 183 for (i = 21; i < 30; i++) 184 rep_hist_add_buffer_stats(2.0, 2.0, i); 185 for (i = 20; i < 30; i++) 186 rep_hist_add_buffer_stats(3.5, 3.5, i); 187 s = rep_hist_format_buffer_stats(now + 86400); 188 tt_str_op("cell-stats-end 2010-08-12 13:27:30 (86400 s)\n" 189 "cell-processed-cells 29,28,27,26,25,24,23,22,21,20\n" 190 "cell-queued-cells 2.75,2.75,2.75,2.75,2.75,2.75,2.75,2.75," 191 "2.75,2.75\n" 192 "cell-time-in-queue 3,3,3,3,3,3,3,3,3,3\n" 193 "cell-circuits-per-decile 2\n",OP_EQ, s); 194 tor_free(s); 195 196 /* Stop collecting stats, add statistics for one circuit, and ensure we 197 * don't generate a history string. */ 198 rep_hist_buffer_stats_term(); 199 rep_hist_add_buffer_stats(2.0, 2.0, 20); 200 s = rep_hist_format_buffer_stats(now + 86400); 201 tt_ptr_op(s, OP_EQ, NULL); 202 203 /* Re-start stats, add statistics for one circuit, reset stats, and make 204 * sure that the history has all zeros. */ 205 rep_hist_buffer_stats_init(now); 206 rep_hist_add_buffer_stats(2.0, 2.0, 20); 207 rep_hist_reset_buffer_stats(now); 208 s = rep_hist_format_buffer_stats(now + 86400); 209 tt_str_op("cell-stats-end 2010-08-12 13:27:30 (86400 s)\n" 210 "cell-processed-cells 0,0,0,0,0,0,0,0,0,0\n" 211 "cell-queued-cells 0.00,0.00,0.00,0.00,0.00,0.00,0.00,0.00," 212 "0.00,0.00\n" 213 "cell-time-in-queue 0,0,0,0,0,0,0,0,0,0\n" 214 "cell-circuits-per-decile 0\n",OP_EQ, s); 215 216 done: 217 tor_free(s); 218 } 219 220 /** Run unit tests the mtbf stats code. */ 221 static void 222 test_rephist_mtbf(void *arg) 223 { 224 (void)arg; 225 226 time_t now = 1572500000; /* 2010-10-31 05:33:20 UTC */ 227 time_t far_future = MAX(now, time(NULL)) + 365*24*60*60; 228 int r; 229 230 /* Make a temporary datadir for these tests */ 231 char *ddir_fname = tor_strdup(get_fname_rnd("datadir_mtbf")); 232 tor_free(get_options_mutable()->DataDirectory); 233 get_options_mutable()->DataDirectory = tor_strdup(ddir_fname); 234 check_private_dir(ddir_fname, CPD_CREATE, NULL); 235 236 rep_history_clean(far_future); 237 238 /* No data */ 239 240 r = rep_hist_load_mtbf_data(now); 241 tt_int_op(r, OP_EQ, -1); 242 rep_history_clean(far_future); 243 244 /* Blank data */ 245 246 r = rep_hist_record_mtbf_data(now, 0); 247 tt_int_op(r, OP_EQ, 0); 248 r = rep_hist_load_mtbf_data(now); 249 tt_int_op(r, OP_EQ, 0); 250 rep_history_clean(far_future); 251 252 r = rep_hist_record_mtbf_data(now, 1); 253 tt_int_op(r, OP_EQ, 0); 254 r = rep_hist_load_mtbf_data(now); 255 tt_int_op(r, OP_EQ, 0); 256 rep_history_clean(far_future); 257 258 done: 259 rep_history_clean(far_future); 260 tor_free(ddir_fname); 261 } 262 263 static void 264 test_commit_max(void *arg) 265 { 266 (void) arg; 267 bw_array_t *b = bw_array_new(); 268 time_t now = b->cur_obs_time; 269 270 commit_max(b); 271 tt_int_op(b->next_period, OP_EQ, now + 2*86400); 272 273 b->total_in_period = 100; 274 b->max_total = 10; 275 commit_max(b); 276 tor_assert(b->total_in_period == 0); 277 tor_assert(b->max_total == 0); 278 tt_int_op(b->totals[1], OP_EQ, 100); 279 tt_int_op(b->maxima[1], OP_EQ, 10); 280 tt_int_op(b->next_period, OP_EQ, now + 3*86400); 281 282 commit_max(b); 283 tt_int_op(b->next_period, OP_EQ, now + 4*86400); 284 285 commit_max(b); 286 tt_int_op(b->next_period, OP_EQ, now + 5*86400); 287 288 b->total_in_period = 100; 289 b->max_total = 10; 290 commit_max(b); 291 tor_assert(!b->next_max_idx); 292 tt_int_op(b->cur_obs_idx, OP_EQ, 0); 293 tt_int_op(b->totals[4], OP_EQ, 100); 294 tt_int_op(b->maxima[4], OP_EQ, 10); 295 tt_int_op(b->next_period, OP_EQ, now + 6*86400); 296 done: 297 bw_array_free(b); 298 } 299 300 #define test_obs(b, idx, time, tot, max) STMT_BEGIN \ 301 tt_int_op(b->cur_obs_idx, OP_EQ, idx); \ 302 tt_int_op(b->cur_obs_time, OP_EQ, time); \ 303 tt_int_op(b->total_obs, OP_EQ, tot); \ 304 tt_int_op(b->max_total, OP_EQ, max); \ 305 STMT_END; 306 307 static void 308 test_advance_obs(void *arg) 309 { 310 (void) arg; 311 int iter, tot = 0; 312 bw_array_t *b = bw_array_new(); 313 time_t now = b->cur_obs_time; 314 315 for (iter = 0; iter < 10; ++iter) { 316 b->obs[b->cur_obs_idx] += 10; 317 tot += 10; 318 advance_obs(b); 319 if (iter == 9) { 320 /* The current value under cur_obs_idx was zeroed in last iterN. */ 321 test_obs(b, 0, now+iter+1, tot - 10, tot); 322 break; 323 } 324 test_obs(b, iter+1, now+iter+1, tot, tot); 325 } 326 327 b->total_in_period = 100; 328 b->cur_obs_time = now + NUM_SECS_BW_SUM_INTERVAL - 1; 329 advance_obs(b); 330 test_obs(b, 1, now+NUM_SECS_BW_SUM_INTERVAL, 80, 0); 331 tt_int_op(b->maxima[0], OP_EQ, 100); 332 tt_int_op(b->totals[0], OP_EQ, 100); 333 tt_int_op(b->num_maxes_set, OP_EQ, 1); 334 done: 335 bw_array_free(b); 336 } 337 338 #define test_add_obs_(b, now, checknow, bw, tot) STMT_BEGIN \ 339 tot += bw; \ 340 add_obs(b, now, bw); \ 341 tt_int_op(b->cur_obs_time, OP_EQ, checknow); \ 342 tt_int_op(b->obs[b->cur_obs_idx], OP_EQ, bw); \ 343 tt_int_op(b->total_in_period, OP_EQ, tot); \ 344 STMT_END; 345 346 static void 347 test_add_obs(void *arg) 348 { 349 (void) arg; 350 bw_array_t *b = bw_array_new(); 351 time_t now = b->cur_obs_time; 352 uint64_t bw = 0, tot = 0; 353 /* Requests for the past should not be entertained. */ 354 test_add_obs_(b, now-1, now, bw, tot); 355 /* Test the expected functionalities for random values. */ 356 now += 53; 357 bw = 97; 358 test_add_obs_(b, now, now, bw, tot); 359 360 now += 60*60; 361 bw = 90; 362 test_add_obs_(b, now, now, bw, tot); 363 364 now += 24*60*60; 365 bw = 100; 366 tot = 0; 367 test_add_obs_(b, now, now, bw, tot); 368 done: 369 bw_array_free(b); 370 } 371 372 static or_options_t mock_options; 373 374 static const or_options_t * 375 mock_get_options(void) 376 { 377 return &mock_options; 378 } 379 380 #define MAX_HIST_VALUE_LEN 21*NUM_TOTALS 381 382 #define set_test_case(b, max, idx, a1, a2, a3, a4, a5) STMT_BEGIN \ 383 b->num_maxes_set = max; \ 384 b->next_max_idx = idx; \ 385 b->totals[0] = a1; \ 386 b->totals[1] = a2; \ 387 b->totals[2] = a3; \ 388 b->totals[3] = a4; \ 389 b->totals[4] = a5; \ 390 STMT_END; 391 392 #define test_fill_bw(b, buf, rv, str, checkrv) STMT_BEGIN \ 393 buf = tor_malloc_zero(MAX_HIST_VALUE_LEN); \ 394 rv = bwhist_fill_bandwidth_history(buf, MAX_HIST_VALUE_LEN, b); \ 395 tt_str_op(buf, OP_EQ, str); \ 396 tt_int_op(rv, OP_EQ, checkrv); \ 397 tor_free(buf); \ 398 STMT_END; 399 400 static void 401 test_fill_bandwidth_history(void *arg) 402 { 403 (void) arg; 404 bw_array_t *b = bw_array_new(); 405 char *buf; 406 size_t rv; 407 /* Remember bandwidth is rounded down to the nearest 1K. */ 408 /* Day 1. */ 409 set_test_case(b, 0, 0, 0, 0, 0, 0, 0); 410 buf = tor_malloc_zero(MAX_HIST_VALUE_LEN); 411 rv = bwhist_fill_bandwidth_history(buf, MAX_HIST_VALUE_LEN, b); 412 tt_int_op(rv, OP_EQ, 0); 413 tor_free(buf); 414 /* Day 2. */ 415 set_test_case(b, 1, 1, 1000, 0, 0, 0, 0); 416 test_fill_bw(b, buf, rv, "0", 1); 417 /* Day 3. */ 418 set_test_case(b, 2, 2, 1000, 1500, 0, 0, 0); 419 test_fill_bw(b, buf, rv, "0,1024", 6); 420 /* Day 4. */ 421 set_test_case(b, 3, 3, 1000, 1500, 3500, 0, 0); 422 test_fill_bw(b, buf, rv, "0,1024,3072", 11); 423 /* Day 5. */ 424 set_test_case(b, 4, 4, 1000, 1500, 3500, 8000, 0); 425 test_fill_bw(b, buf, rv, "0,1024,3072,7168", 16); 426 /* Day 6. */ 427 set_test_case(b, 5, 0, 1000, 1500, 3500, 8000, 6000); 428 test_fill_bw(b, buf, rv, "0,1024,3072,7168,5120", 21); 429 /* Day 7. */ 430 /* Remember oldest entry first. */ 431 set_test_case(b, 5, 1, 10000, 1500, 3500, 8000, 6000); 432 test_fill_bw(b, buf, rv, "1024,3072,7168,5120,9216", 24); 433 /* Mocking get_options to manipulate RelayBandwidthRate. */ 434 MOCK(get_options, mock_get_options); 435 /* Limits bandwidth to 1 KBps. */ 436 /* Cutoff is set to 88473600. */ 437 mock_options.RelayBandwidthRate = 1024; 438 set_test_case(b, 5, 2, 88573600, 88473600, 10000, 8000, 6000); 439 test_fill_bw(b, buf, rv, "9216,7168,5120,88473600,88473600", 32); 440 done: 441 UNMOCK(get_options); 442 bw_array_free(b); 443 } 444 445 #define set_test_bw_lines(r, w, dr, dw, when) STMT_BEGIN \ 446 bwhist_note_bytes_read(r, when, false); \ 447 bwhist_note_bytes_written(w, when, false); \ 448 bwhist_note_dir_bytes_read(dr, when); \ 449 bwhist_note_dir_bytes_written(dw, when); \ 450 STMT_END; 451 452 #define test_get_bw_lines(str, checkstr) STMT_BEGIN \ 453 str = bwhist_get_bandwidth_lines(); \ 454 tt_str_op(str, OP_EQ, checkstr); \ 455 tor_free(str); \ 456 STMT_END; 457 458 static void 459 test_get_bandwidth_lines(void *arg) 460 { 461 (void) arg; 462 char *str = NULL, *checkstr = NULL; 463 char t[ISO_TIME_LEN+1]; 464 int len = (67+MAX_HIST_VALUE_LEN)*4; 465 checkstr = tor_malloc_zero(len); 466 time_t now = time(NULL); 467 bwhist_init(); 468 469 /* Day 1. */ 470 now += 86400; 471 set_test_bw_lines(5000, 5500, 3000, 3500, now - 6*60*60); 472 /* Day 2. */ 473 now += 86400; 474 set_test_bw_lines(50000, 55000, 30000, 35000, now - 6*60*60); 475 /* Day 3. */ 476 now += 86400; 477 set_test_bw_lines(25000, 27500, 15000, 17500, now - 6*60*60); 478 /* Day 4. */ 479 now += 86400; 480 set_test_bw_lines(90000, 76000, 60000, 45000, now - 6*60*60); 481 /* Day 5. */ 482 now += 86400; 483 set_test_bw_lines(500, 55000, 30000, 35000, now - 6*60*60); 484 set_test_bw_lines(0, 0, 0, 0, now); 485 format_iso_time(t, now); 486 tor_snprintf(checkstr, len, "write-history %s (86400 s) " 487 "5120,54272,26624,75776,54272\n" 488 "read-history %s (86400 s) " 489 "4096,49152,24576,89088,0\n" 490 "dirreq-write-history %s (86400 s) " 491 "3072,34816,17408,44032,34816\n" 492 "dirreq-read-history %s (86400 s) " 493 "2048,29696,14336,59392,29696\n", 494 t, t, t, t); 495 test_get_bw_lines(str, checkstr); 496 497 done: 498 tor_free(str); 499 tor_free(checkstr); 500 bwhist_free_all(); 501 } 502 503 static bool 504 mock_should_collect_v3_stats(void) 505 { 506 return true; 507 } 508 509 /* Test v3 metrics */ 510 static void 511 test_rephist_v3_onions(void *arg) 512 { 513 int ret; 514 515 char *stats_string = NULL; 516 char *desc1_str = NULL; 517 ed25519_keypair_t signing_kp1; 518 hs_descriptor_t *desc1 = NULL; 519 520 const hs_v3_stats_t *hs_v3_stats = NULL; 521 522 (void) arg; 523 524 MOCK(should_collect_v3_stats, mock_should_collect_v3_stats); 525 526 get_options_mutable()->HiddenServiceStatistics = 1; 527 528 /* Initialize the subsystems */ 529 hs_cache_init(); 530 rep_hist_hs_stats_init(0); 531 532 /* Change time to 03-01-2002 23:36 UTC */ 533 update_approx_time(1010101010); 534 535 /* HS stats should be zero here */ 536 hs_v3_stats = rep_hist_get_hs_v3_stats(); 537 tt_int_op(digest256map_size(hs_v3_stats->v3_onions_seen_this_period), 538 OP_EQ, 0); 539 540 /* Generate a valid descriptor */ 541 ret = ed25519_keypair_generate(&signing_kp1, 0); 542 tt_int_op(ret, OP_EQ, 0); 543 desc1 = hs_helper_build_hs_desc_with_rev_counter(&signing_kp1, 42); 544 tt_assert(desc1); 545 ret = hs_desc_encode_descriptor(desc1, &signing_kp1, NULL, &desc1_str); 546 tt_int_op(ret, OP_EQ, 0); 547 548 /* Store descriptor and check that stats got updated */ 549 ret = hs_cache_store_as_dir(desc1_str); 550 tt_int_op(ret, OP_EQ, 0); 551 hs_v3_stats = rep_hist_get_hs_v3_stats(); 552 tt_int_op(digest256map_size(hs_v3_stats->v3_onions_seen_this_period), 553 OP_EQ, 1); 554 555 /* cleanup */ 556 hs_descriptor_free(desc1); 557 tor_free(desc1_str); 558 559 /* Generate another valid descriptor */ 560 ret = ed25519_keypair_generate(&signing_kp1, 0); 561 tt_int_op(ret, OP_EQ, 0); 562 desc1 = hs_helper_build_hs_desc_with_rev_counter(&signing_kp1, 42); 563 tt_assert(desc1); 564 ret = hs_desc_encode_descriptor(desc1, &signing_kp1, NULL, &desc1_str); 565 tt_int_op(ret, OP_EQ, 0); 566 567 /* Store descriptor and check that stats are updated */ 568 ret = hs_cache_store_as_dir(desc1_str); 569 tt_int_op(ret, OP_EQ, 0); 570 hs_v3_stats = rep_hist_get_hs_v3_stats(); 571 tt_int_op(digest256map_size(hs_v3_stats->v3_onions_seen_this_period), 572 OP_EQ, 2); 573 574 /* Check that storing the same descriptor twice does not work */ 575 ret = hs_cache_store_as_dir(desc1_str); 576 tt_int_op(ret, OP_EQ, -1); 577 578 /* cleanup */ 579 hs_descriptor_free(desc1); 580 tor_free(desc1_str); 581 582 /* Create a descriptor with the same identity key but diff rev counter and 583 same blinded key */ 584 desc1 = hs_helper_build_hs_desc_with_rev_counter(&signing_kp1, 43); 585 tt_assert(desc1); 586 ret = hs_desc_encode_descriptor(desc1, &signing_kp1, NULL, &desc1_str); 587 tt_int_op(ret, OP_EQ, 0); 588 589 /* Store descriptor and check that stats are updated */ 590 ret = hs_cache_store_as_dir(desc1_str); 591 tt_int_op(ret, OP_EQ, 0); 592 tt_int_op(digest256map_size(hs_v3_stats->v3_onions_seen_this_period), 593 OP_EQ, 2); 594 595 /* cleanup */ 596 hs_descriptor_free(desc1); 597 tor_free(desc1_str); 598 599 /* Now let's skip to four days forward so that the blinded key rolls 600 forward */ 601 update_approx_time(approx_time() + 345600); 602 603 /* Now create a descriptor with the same identity key but diff rev counter 604 and different blinded key */ 605 desc1 = hs_helper_build_hs_desc_with_rev_counter(&signing_kp1, 44); 606 tt_assert(desc1); 607 ret = hs_desc_encode_descriptor(desc1, &signing_kp1, NULL, &desc1_str); 608 tt_int_op(ret, OP_EQ, 0); 609 610 /* Store descriptor and check that stats are updated */ 611 ret = hs_cache_store_as_dir(desc1_str); 612 tt_int_op(ret, OP_EQ, 0); 613 tt_int_op(digest256map_size(hs_v3_stats->v3_onions_seen_this_period), 614 OP_EQ, 3); 615 616 /* cleanup */ 617 hs_descriptor_free(desc1); 618 tor_free(desc1_str); 619 620 /* Because of differential privacy we can't actually check the stat value, 621 but let's just check that it's formatted correctly. */ 622 stats_string = rep_hist_format_hs_stats(approx_time(), true); 623 tt_assert(strstr(stats_string, "hidserv-dir-v3-onions-seen")); 624 625 done: 626 UNMOCK(should_collect_v3_stats); 627 tor_free(stats_string); 628 } 629 630 static void 631 test_load_stats_file(void *arg) 632 { 633 int ret; 634 char *content = NULL, *read_file_content = NULL, *fname = NULL; 635 636 (void) arg; 637 638 /* Load conn-stats. */ 639 fname = get_datadir_fname("conn-stats"); 640 tt_assert(fname); 641 read_file_content = tor_strdup( 642 "conn-bi-direct 2020-12-13 15:48:53 (86400 s) 12,34,56,78\n" 643 "ipv6-conn-bi-direct 2020-12-14 15:48:53 (86400 s) 21,43,65,87\n"); 644 write_str_to_file(fname, read_file_content, 0); 645 ret = load_stats_file("conn-stats", "conn-bi-direct", 1607874000, &content); 646 tt_int_op(ret, OP_EQ, 1); 647 tt_str_op(read_file_content, OP_EQ, content); 648 649 /* Load hidserv-stats. */ 650 tor_free(fname); 651 fname = get_datadir_fname("hidserv-stats"); 652 tt_assert(fname); 653 tor_free(read_file_content); 654 read_file_content = tor_strdup( 655 "hidserv-stats-end 2020-12-13 15:48:53 (86400 s)\n" 656 "hidserv-rend-relayed-cells 48754891 delta_f=2048 epsilon=0.30 " 657 "bin_size=1024\n" 658 "hidserv-dir-onions-seen 53 delta_f=8 epsilon=0.30 bin_size=8\n"); 659 write_str_to_file(fname, read_file_content, 0); 660 tor_free(content); 661 ret = load_stats_file("hidserv-stats", "hidserv-stats-end", 1607874000, 662 &content); 663 tt_int_op(ret, OP_EQ, 1); 664 tt_str_op(read_file_content, OP_EQ, content); 665 666 /* Load dirreq-stats. */ 667 tor_free(fname); 668 fname = get_datadir_fname("dirreq-stats"); 669 tt_assert(fname); 670 tor_free(read_file_content); 671 read_file_content = tor_strdup( 672 "dirreq-stats-end 2020-12-13 15:48:53 (86400 s)\n" 673 "dirreq-v3-ips ru=1728,us=1144,de=696,ir=432,gb=328,fr=304,in=296,ua=232\n" 674 "dirreq-v3-reqs ru=3616,us=3576,de=1896,fr=800,gb=632,ir=616\n" 675 "dirreq-v3-resp ok=18472,not-enough-sigs=0,unavailable=0,not-found=0," 676 "not-modified=3136,busy=0\n" 677 "dirreq-v3-direct-dl complete=0,timeout=0,running=0\n" 678 "dirreq-v3-tunneled-dl complete=18124,timeout=348,running=4,min=257," 679 "d1=133653,d2=221050,q1=261242,d3=300622,d4=399758,md=539051,d6=721322," 680 "d7=959866,q3=1103363,d8=1302035,d9=2046125,max=113404000\n"); 681 write_str_to_file(fname, read_file_content, 0); 682 tor_free(content); 683 ret = load_stats_file("dirreq-stats", "dirreq-stats-end", 1607874000, 684 &content); 685 tt_int_op(ret, OP_EQ, 1); 686 tt_str_op(read_file_content, OP_EQ, content); 687 688 /* Attempt to load future-stats file not starting with timestamp tag. */ 689 tor_free(fname); 690 fname = get_datadir_fname("future-stats"); 691 tt_assert(fname); 692 tor_free(read_file_content); 693 read_file_content = tor_strdup( 694 "future-stuff-at-file-start\n" 695 "future-stats 2020-12-13 15:48:53 (86400 s)\n"); 696 write_str_to_file(fname, read_file_content, 0); 697 tor_free(content); 698 ret = load_stats_file("future-stats", "future-stats", 1607874000, &content); 699 tt_int_op(ret, OP_EQ, 1); 700 tt_str_op(read_file_content, OP_EQ, content); 701 702 done: 703 tor_free(fname); 704 tor_free(read_file_content); 705 tor_free(content); 706 } 707 708 /** Test the overload stats logic. */ 709 static void 710 test_overload_stats(void *arg) 711 { 712 time_t current_time = 1010101010; 713 char *stats_str = NULL; 714 (void) arg; 715 716 /* Change time to 03-01-2002 23:36 UTC */ 717 /* This should make the extrainfo timestamp be "2002-01-03 23:00:00" */ 718 update_approx_time(current_time); 719 720 /* With an empty rephist we shouldn't get anything back */ 721 stats_str = rep_hist_get_overload_stats_lines(); 722 tt_assert(!stats_str); 723 724 /* Note an overload */ 725 rep_hist_note_overload(OVERLOAD_GENERAL); 726 727 /* Move the time forward one hour */ 728 current_time += 3600; 729 update_approx_time(current_time); 730 731 /* Now check the string */ 732 stats_str = rep_hist_get_overload_general_line(); 733 tt_str_op("overload-general 1 2002-01-03 23:00:00\n", OP_EQ, stats_str); 734 tor_free(stats_str); 735 736 /* Move the time forward 72 hours: see that the line has disappeared. */ 737 current_time += 3600*72; 738 update_approx_time(current_time); 739 740 stats_str = rep_hist_get_overload_general_line(); 741 tt_assert(!stats_str); 742 743 /* Now the time should be 2002-01-07 00:00:00 */ 744 745 /* Note an overload */ 746 rep_hist_note_overload(OVERLOAD_GENERAL); 747 748 stats_str = rep_hist_get_overload_general_line(); 749 tt_str_op("overload-general 1 2002-01-07 00:00:00\n", OP_EQ, stats_str); 750 tor_free(stats_str); 751 752 /* Also note an fd exhaustion event */ 753 rep_hist_note_overload(OVERLOAD_FD_EXHAUSTED); 754 755 stats_str = rep_hist_get_overload_general_line(); 756 tt_str_op("overload-general 1 2002-01-07 00:00:00\n", OP_EQ, stats_str); 757 tor_free(stats_str); 758 759 stats_str = rep_hist_get_overload_stats_lines(); 760 tt_str_op("overload-fd-exhausted 1 2002-01-07 00:00:00\n", OP_EQ, stats_str); 761 tor_free(stats_str); 762 763 /* Move the time forward. Register overload. See that the time changed */ 764 current_time += 3600*2; 765 update_approx_time(current_time); 766 767 rep_hist_note_overload(OVERLOAD_GENERAL); 768 769 stats_str = rep_hist_get_overload_general_line(); 770 tt_str_op("overload-general 1 2002-01-07 02:00:00\n", OP_EQ, stats_str); 771 tor_free(stats_str); 772 773 stats_str = rep_hist_get_overload_stats_lines(); 774 tt_str_op("overload-fd-exhausted 1 2002-01-07 00:00:00\n", OP_EQ, stats_str); 775 tor_free(stats_str); 776 777 /* Move the time forward. Register a bandwidth ratelimit event. See that the 778 string is added */ 779 current_time += 3600*2; 780 update_approx_time(current_time); 781 782 /* Register the rate limit event */ 783 rep_hist_note_overload(OVERLOAD_READ); 784 /* Also set some rate limiting values that should be reflected on the log */ 785 get_options_mutable()->BandwidthRate = 1000; 786 get_options_mutable()->BandwidthBurst = 2000; 787 788 stats_str = rep_hist_get_overload_general_line(); 789 tt_str_op("overload-general 1 2002-01-07 02:00:00\n", OP_EQ, stats_str); 790 tor_free(stats_str); 791 792 stats_str = rep_hist_get_overload_stats_lines(); 793 tt_str_op("overload-ratelimits 1 2002-01-07 04:00:00 1000 2000 1 0\n" 794 "overload-fd-exhausted 1 2002-01-07 00:00:00\n", OP_EQ, stats_str); 795 tor_free(stats_str); 796 797 /* Move the time forward 24 hours: no rate limit line anymore. */ 798 current_time += 3600*24; 799 update_approx_time(current_time); 800 801 stats_str = rep_hist_get_overload_general_line(); 802 tt_str_op("overload-general 1 2002-01-07 02:00:00\n", OP_EQ, stats_str); 803 tor_free(stats_str); 804 805 stats_str = rep_hist_get_overload_stats_lines(); 806 tt_str_op("overload-fd-exhausted 1 2002-01-07 00:00:00\n", OP_EQ, stats_str); 807 tor_free(stats_str); 808 809 /* Move the time forward 44 hours: no fd exhausted line anymore. */ 810 current_time += 3600*44; 811 update_approx_time(current_time); 812 813 stats_str = rep_hist_get_overload_general_line(); 814 tt_str_op("overload-general 1 2002-01-07 02:00:00\n", OP_EQ, stats_str); 815 tor_free(stats_str); 816 817 /* Move the time forward 2 hours: there is nothing left. */ 818 current_time += 3600*2; 819 update_approx_time(current_time); 820 821 stats_str = rep_hist_get_overload_general_line(); 822 tt_assert(!stats_str); 823 824 stats_str = rep_hist_get_overload_stats_lines(); 825 tt_assert(!stats_str); 826 827 /* Now test the rate-limit rate-limiter ;) */ 828 for (int i = 0; i < 10; i++) { 829 rep_hist_note_overload(OVERLOAD_READ); 830 } 831 /* We already have an event registered from the previous tests. We just 832 * registered ten more overload events, but only one should have been counted 833 * because of the rate limiter */ 834 stats_str = rep_hist_get_overload_stats_lines(); 835 tt_str_op("overload-ratelimits 1 2002-01-10 02:00:00 1000 2000 2 0\n", 836 OP_EQ, stats_str); 837 tor_free(stats_str); 838 839 /* Increment time by 59 secs and try again. No additional events should 840 register */ 841 current_time += 59; 842 update_approx_time(current_time); 843 844 for (int i = 0; i < 10; i++) { 845 rep_hist_note_overload(OVERLOAD_READ); 846 } 847 stats_str = rep_hist_get_overload_stats_lines(); 848 tt_str_op("overload-ratelimits 1 2002-01-10 02:00:00 1000 2000 2 0\n", 849 OP_EQ, stats_str); 850 tor_free(stats_str); 851 852 /* Now increment time by 2 secs -- taking it after the minute rate limiting 853 and see that events will register again */ 854 current_time += 2; 855 update_approx_time(current_time); 856 857 for (int i = 0; i < 10; i++) { 858 rep_hist_note_overload(OVERLOAD_READ); 859 rep_hist_note_overload(OVERLOAD_WRITE); 860 } 861 stats_str = rep_hist_get_overload_stats_lines(); 862 tt_str_op("overload-ratelimits 1 2002-01-10 02:00:00 1000 2000 3 1\n", 863 OP_EQ, stats_str); 864 tor_free(stats_str); 865 866 done: 867 tor_free(stats_str); 868 } 869 870 /** Test the overload stats logic. */ 871 static void 872 test_overload_onionskin_ntor(void *arg) 873 { 874 char *stats_str = NULL; 875 (void) arg; 876 uint16_t type = ONION_HANDSHAKE_TYPE_NTOR_V3; 877 878 /* Lets simulate a series of timeouts but below our default 1% threshold. */ 879 880 for (int i = 0; i < 1000; i++) { 881 rep_hist_note_circuit_handshake_requested(type); 882 /* This should trigger 9 drop which is just below 1% (10) */ 883 if (i > 0 && !(i % 100)) { 884 rep_hist_note_circuit_handshake_dropped(type); 885 } 886 } 887 888 /* No overload yet. */ 889 stats_str = rep_hist_get_overload_general_line(); 890 tt_assert(!stats_str); 891 892 /* Move it 6 hours in the future and see if we get a general overload. */ 893 update_approx_time(approx_time() + 21600); 894 895 /* This request should NOT trigger the general overload because we are below 896 * our default of 1%. */ 897 rep_hist_note_circuit_handshake_requested(type); 898 stats_str = rep_hist_get_overload_general_line(); 899 tt_assert(!stats_str); 900 901 /* We'll now go above our 1% threshold. */ 902 for (int i = 0; i < 1000; i++) { 903 rep_hist_note_circuit_handshake_requested(type); 904 /* This should trigger 10 timeouts which is our threshold of 1% (10) */ 905 if (!(i % 10)) { 906 rep_hist_note_circuit_handshake_dropped(type); 907 } 908 } 909 910 /* Move it 6 hours in the future and see if we get a general overload. */ 911 update_approx_time(approx_time() + 21600); 912 913 /* This request should trigger the general overload because above 1%. */ 914 rep_hist_note_circuit_handshake_requested(type); 915 stats_str = rep_hist_get_overload_general_line(); 916 tt_assert(stats_str); 917 tor_free(stats_str); 918 919 /* Move 72h in the future, we should NOT get an overload anymore. */ 920 update_approx_time(approx_time() + (72 * 3600)); 921 922 stats_str = rep_hist_get_overload_general_line(); 923 tt_assert(!stats_str); 924 925 done: 926 tor_free(stats_str); 927 } 928 929 #define ENT(name) \ 930 { #name, test_ ## name , 0, NULL, NULL } 931 #define FORK(name) \ 932 { #name, test_ ## name , TT_FORK, NULL, NULL } 933 934 struct testcase_t stats_tests[] = { 935 FORK(stats), 936 ENT(rephist_mtbf), 937 FORK(commit_max), 938 FORK(advance_obs), 939 FORK(add_obs), 940 FORK(fill_bandwidth_history), 941 FORK(get_bandwidth_lines), 942 FORK(rephist_v3_onions), 943 FORK(load_stats_file), 944 FORK(overload_stats), 945 FORK(overload_onionskin_ntor), 946 947 END_OF_TESTCASES 948 };