Line data Source code
1 : /* Copyright (c) 2004-2006, Roger Dingledine, Nick Mathewson.
2 : * Copyright (c) 2007-2021, The Tor Project, Inc. */
3 : /* See LICENSE for licensing information */
4 :
5 : /**
6 : * \file control_bootstrap.c
7 : * \brief Provide bootstrap progress events for the control port.
8 : */
9 : #include "core/or/or.h"
10 :
11 : #include "app/config/config.h"
12 : #include "core/mainloop/connection.h"
13 : #include "core/or/connection_or.h"
14 : #include "core/or/connection_st.h"
15 : #include "core/or/or_connection_st.h"
16 : #include "core/or/reasons.h"
17 : #include "feature/control/control_events.h"
18 : #include "feature/hibernate/hibernate.h"
19 : #include "lib/malloc/malloc.h"
20 :
21 : /** A sufficiently large size to record the last bootstrap phase string. */
22 : #define BOOTSTRAP_MSG_LEN 1024
23 :
24 : /** What was the last bootstrap phase message we sent? We keep track
25 : * of this so we can respond to getinfo status/bootstrap-phase queries. */
26 : static char last_sent_bootstrap_message[BOOTSTRAP_MSG_LEN];
27 :
28 : /** Table to convert bootstrap statuses to strings. */
29 : static const struct {
30 : bootstrap_status_t status;
31 : const char *tag;
32 : const char *summary;
33 : } boot_to_str_tab[] = {
34 : { BOOTSTRAP_STATUS_UNDEF, "undef", "Undefined" },
35 : { BOOTSTRAP_STATUS_STARTING, "starting", "Starting" },
36 :
37 : /* Initial connection to any relay */
38 :
39 : { BOOTSTRAP_STATUS_CONN_PT, "conn_pt", "Connecting to pluggable transport" },
40 : { BOOTSTRAP_STATUS_CONN_DONE_PT, "conn_done_pt",
41 : "Connected to pluggable transport" },
42 : { BOOTSTRAP_STATUS_CONN_PROXY, "conn_proxy", "Connecting to proxy" },
43 : { BOOTSTRAP_STATUS_CONN_DONE_PROXY, "conn_done_proxy",
44 : "Connected to proxy" },
45 : { BOOTSTRAP_STATUS_CONN, "conn", "Connecting to a relay" },
46 : { BOOTSTRAP_STATUS_CONN_DONE, "conn_done", "Connected to a relay" },
47 : { BOOTSTRAP_STATUS_HANDSHAKE, "handshake",
48 : "Handshaking with a relay" },
49 : { BOOTSTRAP_STATUS_HANDSHAKE_DONE, "handshake_done",
50 : "Handshake with a relay done" },
51 :
52 : /* Loading directory info */
53 :
54 : { BOOTSTRAP_STATUS_ONEHOP_CREATE, "onehop_create",
55 : "Establishing an encrypted directory connection" },
56 : { BOOTSTRAP_STATUS_REQUESTING_STATUS, "requesting_status",
57 : "Asking for networkstatus consensus" },
58 : { BOOTSTRAP_STATUS_LOADING_STATUS, "loading_status",
59 : "Loading networkstatus consensus" },
60 : { BOOTSTRAP_STATUS_LOADING_KEYS, "loading_keys",
61 : "Loading authority key certs" },
62 : { BOOTSTRAP_STATUS_REQUESTING_DESCRIPTORS, "requesting_descriptors",
63 : "Asking for relay descriptors" },
64 : { BOOTSTRAP_STATUS_LOADING_DESCRIPTORS, "loading_descriptors",
65 : "Loading relay descriptors" },
66 : { BOOTSTRAP_STATUS_ENOUGH_DIRINFO, "enough_dirinfo",
67 : "Loaded enough directory info to build circuits" },
68 :
69 : /* Connecting to a relay for AP circuits */
70 :
71 : { BOOTSTRAP_STATUS_AP_CONN_PT, "ap_conn_pt",
72 : "Connecting to pluggable transport to build circuits" },
73 : { BOOTSTRAP_STATUS_AP_CONN_DONE_PT, "ap_conn_done_pt",
74 : "Connected to pluggable transport to build circuits" },
75 : { BOOTSTRAP_STATUS_AP_CONN_PROXY, "ap_conn_proxy",
76 : "Connecting to proxy to build circuits" },
77 : { BOOTSTRAP_STATUS_AP_CONN_DONE_PROXY, "ap_conn_done_proxy",
78 : "Connected to proxy to build circuits" },
79 : { BOOTSTRAP_STATUS_AP_CONN, "ap_conn",
80 : "Connecting to a relay to build circuits" },
81 : { BOOTSTRAP_STATUS_AP_CONN_DONE, "ap_conn_done",
82 : "Connected to a relay to build circuits" },
83 : { BOOTSTRAP_STATUS_AP_HANDSHAKE, "ap_handshake",
84 : "Finishing handshake with a relay to build circuits" },
85 : { BOOTSTRAP_STATUS_AP_HANDSHAKE_DONE, "ap_handshake_done",
86 : "Handshake finished with a relay to build circuits" },
87 :
88 : /* Creating AP circuits */
89 :
90 : { BOOTSTRAP_STATUS_CIRCUIT_CREATE, "circuit_create",
91 : "Establishing a Tor circuit" },
92 : { BOOTSTRAP_STATUS_DONE, "done", "Done" },
93 : };
94 : #define N_BOOT_TO_STR (sizeof(boot_to_str_tab)/sizeof(boot_to_str_tab[0]))
95 :
96 : /** Convert the name of a bootstrapping phase <b>s</b> into strings
97 : * <b>tag</b> and <b>summary</b> suitable for display by the controller. */
98 : static int
99 32 : bootstrap_status_to_string(bootstrap_status_t s, const char **tag,
100 : const char **summary)
101 : {
102 364 : for (size_t i = 0; i < N_BOOT_TO_STR; i++) {
103 364 : if (s == boot_to_str_tab[i].status) {
104 32 : *tag = boot_to_str_tab[i].tag;
105 32 : *summary = boot_to_str_tab[i].summary;
106 32 : return 0;
107 : }
108 : }
109 :
110 0 : *tag = *summary = "unknown";
111 0 : return -1;
112 : }
113 :
114 : /** What percentage through the bootstrap process are we? We remember
115 : * this so we can avoid sending redundant bootstrap status events, and
116 : * so we can guess context for the bootstrap messages which are
117 : * ambiguous. It starts at 'undef', but gets set to 'starting' while
118 : * Tor initializes. */
119 : static int bootstrap_percent = BOOTSTRAP_STATUS_UNDEF;
120 :
121 : /** Like bootstrap_percent, but only takes on the enumerated values in
122 : * bootstrap_status_t.
123 : */
124 : static int bootstrap_phase = BOOTSTRAP_STATUS_UNDEF;
125 :
126 : /** As bootstrap_percent, but holds the bootstrapping level at which we last
127 : * logged a NOTICE-level message. We use this, plus BOOTSTRAP_PCT_INCREMENT,
128 : * to avoid flooding the log with a new message every time we get a few more
129 : * microdescriptors */
130 : static int notice_bootstrap_percent = 0;
131 :
132 : /** How many problems have we had getting to the next bootstrapping phase?
133 : * These include failure to establish a connection to a Tor relay,
134 : * failures to finish the TLS handshake, failures to validate the
135 : * consensus document, etc. */
136 : static int bootstrap_problems = 0;
137 :
138 : /** We only tell the controller once we've hit a threshold of problems
139 : * for the current phase. */
140 : #define BOOTSTRAP_PROBLEM_THRESHOLD 10
141 :
142 : /** When our bootstrapping progress level changes, but our bootstrapping
143 : * status has not advanced, we only log at NOTICE when we have made at least
144 : * this much progress.
145 : */
146 : #define BOOTSTRAP_PCT_INCREMENT 5
147 :
148 : /** Do the actual logging and notifications for
149 : * control_event_bootstrap(). Doesn't change any state beyond that.
150 : */
151 : static void
152 32 : control_event_bootstrap_core(int loglevel, bootstrap_status_t status,
153 : int progress)
154 : {
155 32 : char buf[BOOTSTRAP_MSG_LEN];
156 32 : const char *tag, *summary;
157 :
158 32 : bootstrap_status_to_string(status, &tag, &summary);
159 : /* Locally reset status if there's incremental progress */
160 32 : if (progress)
161 2 : status = progress;
162 :
163 32 : tor_log(loglevel, LD_CONTROL,
164 : "Bootstrapped %d%% (%s): %s", status, tag, summary);
165 32 : tor_snprintf(buf, sizeof(buf),
166 : "BOOTSTRAP PROGRESS=%d TAG=%s SUMMARY=\"%s\"",
167 : status, tag, summary);
168 32 : tor_snprintf(last_sent_bootstrap_message,
169 : sizeof(last_sent_bootstrap_message),
170 : "NOTICE %s", buf);
171 32 : control_event_client_status(LOG_NOTICE, "%s", buf);
172 32 : }
173 :
174 : int
175 0 : control_get_bootstrap_percent(void)
176 : {
177 0 : return bootstrap_percent;
178 : }
179 :
180 : /** Called when Tor has made progress at bootstrapping its directory
181 : * information and initial circuits.
182 : *
183 : * <b>status</b> is the new status, that is, what task we will be doing
184 : * next. <b>progress</b> is zero if we just started this task, else it
185 : * represents progress on the task.
186 : */
187 : void
188 36 : control_event_bootstrap(bootstrap_status_t status, int progress)
189 : {
190 36 : int loglevel = LOG_NOTICE;
191 :
192 36 : if (bootstrap_percent == BOOTSTRAP_STATUS_DONE)
193 : return; /* already bootstrapped; nothing to be done here. */
194 :
195 36 : if (status <= bootstrap_percent) {
196 : /* If there's no new progress, return early. */
197 4 : if (!progress || progress <= bootstrap_percent)
198 : return;
199 : /* Log at INFO if not enough progress happened. */
200 0 : if (progress < notice_bootstrap_percent + BOOTSTRAP_PCT_INCREMENT)
201 0 : loglevel = LOG_INFO;
202 : }
203 :
204 32 : control_event_bootstrap_core(loglevel, status, progress);
205 :
206 32 : if (status > bootstrap_percent) {
207 32 : bootstrap_phase = status; /* new milestone reached */
208 32 : bootstrap_percent = status;
209 : }
210 32 : if (progress > bootstrap_percent) {
211 : /* incremental progress within a milestone */
212 0 : bootstrap_percent = progress;
213 0 : bootstrap_problems = 0; /* Progress! Reset our problem counter. */
214 : }
215 32 : if (loglevel == LOG_NOTICE &&
216 32 : bootstrap_percent > notice_bootstrap_percent) {
217 : /* Remember that we gave a notice at this level. */
218 30 : notice_bootstrap_percent = bootstrap_percent;
219 : }
220 : }
221 :
222 : /** Flag whether we've opened an OR_CONN yet */
223 : static int bootstrap_first_orconn = 0;
224 :
225 : /** Like bootstrap_phase, but for (possibly deferred) directory progress */
226 : static int bootstrap_dir_phase = BOOTSTRAP_STATUS_UNDEF;
227 :
228 : /** Like bootstrap_problems, but for (possibly deferred) directory progress */
229 : static int bootstrap_dir_progress = BOOTSTRAP_STATUS_UNDEF;
230 :
231 : /** Defer directory info bootstrap events until we have successfully
232 : * completed our first connection to a router. */
233 : void
234 3 : control_event_boot_dir(bootstrap_status_t status, int progress)
235 : {
236 3 : if (status > bootstrap_dir_progress) {
237 3 : bootstrap_dir_progress = status;
238 3 : bootstrap_dir_phase = status;
239 : }
240 3 : if (progress && progress >= bootstrap_dir_progress) {
241 0 : bootstrap_dir_progress = progress;
242 : }
243 :
244 : /* Don't report unless we have successfully opened at least one OR_CONN */
245 3 : if (!bootstrap_first_orconn)
246 : return;
247 :
248 0 : control_event_bootstrap(status, progress);
249 : }
250 :
251 : /** Set a flag to allow reporting of directory bootstrap progress.
252 : * (Code that reports completion of an OR_CONN calls this.) Also,
253 : * report directory progress so far. */
254 : void
255 5 : control_event_boot_first_orconn(void)
256 : {
257 5 : bootstrap_first_orconn = 1;
258 5 : control_event_bootstrap(bootstrap_dir_phase, bootstrap_dir_progress);
259 5 : }
260 :
261 : /** Called when Tor has failed to make bootstrapping progress in a way
262 : * that indicates a problem. <b>warn</b> gives a human-readable hint
263 : * as to why, and <b>reason</b> provides a controller-facing short
264 : * tag. <b>conn</b> is the connection that caused this problem and
265 : * can be NULL if a connection cannot be easily identified.
266 : */
267 : void
268 0 : control_event_bootstrap_problem(const char *warn, const char *reason,
269 : const connection_t *conn, int dowarn)
270 : {
271 0 : int status = bootstrap_percent;
272 0 : const char *tag = "", *summary = "";
273 0 : char buf[BOOTSTRAP_MSG_LEN];
274 0 : const char *recommendation = "ignore";
275 0 : int severity;
276 0 : char *or_id = NULL, *hostaddr = NULL;
277 0 : const or_connection_t *or_conn = NULL;
278 :
279 : /* bootstrap_percent must not be in "undefined" state here. */
280 0 : tor_assert(status >= 0);
281 :
282 0 : if (bootstrap_percent == 100)
283 0 : return; /* already bootstrapped; nothing to be done here. */
284 :
285 0 : bootstrap_problems++;
286 :
287 0 : if (bootstrap_problems >= BOOTSTRAP_PROBLEM_THRESHOLD)
288 0 : dowarn = 1;
289 :
290 : /* Don't warn about our bootstrapping status if we are hibernating or
291 : * shutting down. */
292 0 : if (we_are_hibernating())
293 0 : dowarn = 0;
294 :
295 0 : tor_assert(bootstrap_status_to_string(bootstrap_phase, &tag, &summary) == 0);
296 :
297 0 : severity = dowarn ? LOG_WARN : LOG_INFO;
298 :
299 0 : if (dowarn)
300 0 : recommendation = "warn";
301 :
302 0 : if (conn && conn->type == CONN_TYPE_OR) {
303 : /* XXX TO_OR_CONN can't deal with const */
304 0 : or_conn = CONST_TO_OR_CONN(conn);
305 0 : or_id = tor_strdup(hex_str(or_conn->identity_digest, DIGEST_LEN));
306 : } else {
307 0 : or_id = tor_strdup("?");
308 : }
309 :
310 0 : if (conn)
311 0 : tor_asprintf(&hostaddr, "%s:%d", conn->address, (int)conn->port);
312 : else
313 0 : hostaddr = tor_strdup("?");
314 :
315 0 : log_fn(severity,
316 : LD_CONTROL, "Problem bootstrapping. Stuck at %d%% (%s): %s. (%s; %s; "
317 : "count %d; recommendation %s; host %s at %s)",
318 : status, tag, summary, warn, reason,
319 : bootstrap_problems, recommendation,
320 : or_id, hostaddr);
321 :
322 0 : connection_or_report_broken_states(severity, LD_HANDSHAKE);
323 :
324 0 : tor_snprintf(buf, sizeof(buf),
325 : "BOOTSTRAP PROGRESS=%d TAG=%s SUMMARY=\"%s\" WARNING=\"%s\" REASON=%s "
326 : "COUNT=%d RECOMMENDATION=%s HOSTID=\"%s\" HOSTADDR=\"%s\"",
327 : bootstrap_percent, tag, summary, warn, reason, bootstrap_problems,
328 : recommendation,
329 : or_id, hostaddr);
330 :
331 0 : tor_snprintf(last_sent_bootstrap_message,
332 : sizeof(last_sent_bootstrap_message),
333 : "WARN %s", buf);
334 0 : control_event_client_status(LOG_WARN, "%s", buf);
335 :
336 0 : tor_free(hostaddr);
337 0 : tor_free(or_id);
338 : }
339 :
340 : /** Called when Tor has failed to make bootstrapping progress in a way
341 : * that indicates a problem. <b>warn</b> gives a hint as to why, and
342 : * <b>reason</b> provides an "or_conn_end_reason" tag. <b>or_conn</b>
343 : * is the connection that caused this problem.
344 : */
345 0 : MOCK_IMPL(void,
346 : control_event_bootstrap_prob_or, (const char *warn, int reason,
347 : or_connection_t *or_conn))
348 : {
349 0 : int dowarn = 0;
350 :
351 0 : if (! or_conn->potentially_used_for_bootstrapping) {
352 : /* We never decided that this channel was a good match for one of our
353 : * origin_circuit_t objects. That means that we probably launched it
354 : * for somebody else, most likely in response to an EXTEND cell.
355 : *
356 : * Since EXTEND cells can contain arbitrarily broken descriptions of
357 : * relays, a failure on this connection here won't necessarily indicate a
358 : * bootstrapping problem.
359 : */
360 : return;
361 : }
362 :
363 0 : if (or_conn->have_noted_bootstrap_problem)
364 : return;
365 :
366 0 : or_conn->have_noted_bootstrap_problem = 1;
367 :
368 0 : if (reason == END_OR_CONN_REASON_NO_ROUTE)
369 0 : dowarn = 1;
370 :
371 : /* If we are using bridges and all our OR connections are now
372 : closed, it means that we totally failed to connect to our
373 : bridges. Throw a warning. */
374 0 : if (get_options()->UseBridges && !any_other_active_or_conns(or_conn))
375 0 : dowarn = 1;
376 :
377 0 : control_event_bootstrap_problem(warn,
378 : orconn_end_reason_to_control_string(reason),
379 0 : TO_CONN(or_conn), dowarn);
380 : }
381 :
382 : /** Return a copy of the last sent bootstrap message. */
383 : char *
384 0 : control_event_boot_last_msg(void)
385 : {
386 0 : return tor_strdup(last_sent_bootstrap_message);
387 : }
388 :
389 : /** Reset bootstrap tracking state. */
390 : void
391 235 : control_event_bootstrap_reset(void)
392 : {
393 235 : bootstrap_percent = BOOTSTRAP_STATUS_UNDEF;
394 235 : bootstrap_phase = BOOTSTRAP_STATUS_UNDEF;
395 235 : notice_bootstrap_percent = 0;
396 235 : bootstrap_problems = 0;
397 235 : bootstrap_first_orconn = 0;
398 235 : bootstrap_dir_progress = BOOTSTRAP_STATUS_UNDEF;
399 235 : bootstrap_dir_phase = BOOTSTRAP_STATUS_UNDEF;
400 235 : memset(last_sent_bootstrap_message, 0, sizeof(last_sent_bootstrap_message));
401 235 : }
|
