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