Line data Source code
1 : /* Copyright (c) 2010-2021, The Tor Project, Inc. */
2 : /* See LICENSE for licensing information */
3 :
4 : /**
5 : * \file status.c
6 : * \brief Collect status information and log heartbeat messages.
7 : *
8 : * This module is responsible for implementing the heartbeat log messages,
9 : * which periodically inform users and operators about basic facts to
10 : * do with their Tor instance. The log_heartbeat() function, invoked from
11 : * main.c, is the principle entry point. It collects data from elsewhere
12 : * in Tor, and logs it in a human-readable format.
13 : **/
14 :
15 : #define STATUS_PRIVATE
16 :
17 : #include "core/or/or.h"
18 : #include "core/or/circuituse.h"
19 : #include "app/config/config.h"
20 : #include "feature/dirclient/dirclient.h"
21 : #include "core/or/status.h"
22 : #include "feature/nodelist/nodelist.h"
23 : #include "core/or/relay.h"
24 : #include "feature/relay/router.h"
25 : #include "feature/relay/routermode.h"
26 : #include "core/or/circuitlist.h"
27 : #include "core/mainloop/mainloop.h"
28 : #include "feature/stats/rephist.h"
29 : #include "feature/hibernate/hibernate.h"
30 : #include "app/config/statefile.h"
31 : #include "feature/hs/hs_stats.h"
32 : #include "feature/hs/hs_service.h"
33 : #include "core/or/dos.h"
34 : #include "feature/stats/geoip_stats.h"
35 :
36 : #include "app/config/or_state_st.h"
37 : #include "feature/nodelist/routerinfo_st.h"
38 : #include "lib/tls/tortls.h"
39 :
40 : static void log_accounting(const time_t now, const or_options_t *options);
41 :
42 : /** Return the total number of circuits. */
43 : STATIC int
44 6 : count_circuits(void)
45 : {
46 6 : return smartlist_len(circuit_get_global_list());
47 : }
48 :
49 : /** Take seconds <b>secs</b> and return a newly allocated human-readable
50 : * uptime string. */
51 : STATIC char *
52 18 : secs_to_uptime(long secs)
53 : {
54 18 : long int days = secs / 86400;
55 18 : int hours = (int)((secs - (days * 86400)) / 3600);
56 18 : int minutes = (int)((secs - (days * 86400) - (hours * 3600)) / 60);
57 18 : char *uptime_string = NULL;
58 :
59 18 : switch (days) {
60 12 : case 0:
61 12 : tor_asprintf(&uptime_string, "%d:%02d hours", hours, minutes);
62 12 : break;
63 3 : case 1:
64 3 : tor_asprintf(&uptime_string, "%ld day %d:%02d hours",
65 : days, hours, minutes);
66 3 : break;
67 3 : default:
68 3 : tor_asprintf(&uptime_string, "%ld days %d:%02d hours",
69 : days, hours, minutes);
70 3 : break;
71 : }
72 :
73 18 : return uptime_string;
74 : }
75 :
76 : /** Take <b>bytes</b> and returns a newly allocated human-readable usage
77 : * string. */
78 : STATIC char *
79 26 : bytes_to_usage(uint64_t bytes)
80 : {
81 26 : char *bw_string = NULL;
82 :
83 26 : if (bytes < (1<<20)) { /* Less than a megabyte. */
84 18 : tor_asprintf(&bw_string, "%"PRIu64" kB", (bytes>>10));
85 8 : } else if (bytes < (1<<30)) { /* Megabytes. Let's add some precision. */
86 4 : double bw = ((double)bytes);
87 4 : tor_asprintf(&bw_string, "%.2f MB", bw/(1<<20));
88 : } else { /* Gigabytes. */
89 4 : double bw = ((double)bytes);
90 4 : tor_asprintf(&bw_string, "%.2f GB", bw/(1<<30));
91 : }
92 :
93 26 : return bw_string;
94 : }
95 :
96 : /** Log some usage info about our onion service(s). */
97 : static void
98 5 : log_onion_service_stats(void)
99 : {
100 5 : unsigned int num_services = hs_service_get_num_services();
101 :
102 : /* If there are no active onion services, no need to print logs */
103 5 : if (num_services == 0) {
104 : return;
105 : }
106 :
107 0 : log_notice(LD_HEARTBEAT,
108 : "Heartbeat: Our onion service%s received %u v3 INTRODUCE2 cells "
109 : "and attempted to launch %d rendezvous circuits.",
110 : num_services == 1 ? "" : "s",
111 : hs_stats_get_n_introduce2_v3_cells(),
112 : hs_stats_get_n_rendezvous_launches());
113 : }
114 :
115 : /**
116 : * @name connection counts for heartbeat
117 : *
118 : * Tracks incoming and outgoing connections on IPv4/IPv6, for heartbeat
119 : * logs.
120 : **/
121 : /**@{*/
122 : static unsigned n_incoming_ipv4;
123 : static unsigned n_incoming_ipv6;
124 : static unsigned n_outgoing_ipv4;
125 : static unsigned n_outgoing_ipv6;
126 : /**@}*/
127 :
128 : /**
129 : * Note that a connection has arrived or has been made, for use in the
130 : * heartbeat message.
131 : **/
132 : void
133 0 : note_connection(bool inbound, int family)
134 : {
135 0 : if (family == AF_INET) {
136 0 : if (inbound) {
137 0 : ++n_incoming_ipv4;
138 : } else {
139 0 : ++n_outgoing_ipv4;
140 : }
141 0 : } else if (family == AF_INET6) {
142 0 : if (inbound) {
143 0 : ++n_incoming_ipv6;
144 : } else {
145 0 : ++n_outgoing_ipv6;
146 : }
147 : }
148 0 : }
149 :
150 : /** Log a "heartbeat" message describing Tor's status and history so that the
151 : * user can know that there is indeed a running Tor. Return 0 on success and
152 : * -1 on failure. */
153 : int
154 6 : log_heartbeat(time_t now)
155 : {
156 6 : char *bw_sent = NULL;
157 6 : char *bw_rcvd = NULL;
158 6 : char *uptime = NULL;
159 6 : const routerinfo_t *me;
160 6 : double r = tls_get_write_overhead_ratio();
161 6 : const int hibernating = we_are_hibernating();
162 :
163 6 : const or_options_t *options = get_options();
164 :
165 6 : if (public_server_mode(options) && !hibernating) {
166 : /* Let's check if we are in the current cached consensus. */
167 2 : if (!(me = router_get_my_routerinfo()))
168 : return -1; /* Something stinks, we won't even attempt this. */
169 : else
170 1 : if (!node_get_by_id(me->cache_info.identity_digest))
171 1 : log_fn(LOG_NOTICE, LD_HEARTBEAT, "Heartbeat: It seems like we are not "
172 : "in the cached consensus.");
173 : }
174 :
175 5 : uptime = secs_to_uptime(get_uptime());
176 5 : bw_rcvd = bytes_to_usage(get_bytes_read());
177 5 : bw_sent = bytes_to_usage(get_bytes_written());
178 :
179 9 : log_fn(LOG_NOTICE, LD_HEARTBEAT, "Heartbeat: Tor's uptime is %s, with %d "
180 : "circuits open. I've sent %s and received %s. I've received %u "
181 : "connections on IPv4 and %u on IPv6. I've made %u connections "
182 : "with IPv4 and %u with IPv6.%s",
183 : uptime, count_circuits(), bw_sent, bw_rcvd,
184 : n_incoming_ipv4, n_incoming_ipv6,
185 : n_outgoing_ipv4, n_outgoing_ipv6,
186 : hibernating?" We are currently hibernating.":"");
187 :
188 5 : dirclient_dump_total_dls();
189 :
190 5 : if (server_mode(options) && accounting_is_enabled(options) && !hibernating) {
191 1 : log_accounting(now, options);
192 : }
193 :
194 5 : double fullness_pct = 100;
195 5 : if (stats_n_data_cells_packaged && !hibernating) {
196 1 : fullness_pct =
197 1 : 100*(((double)stats_n_data_bytes_packaged) /
198 1 : ((double)stats_n_data_cells_packaged*RELAY_PAYLOAD_SIZE));
199 : }
200 5 : const double overhead_pct = ( r - 1.0 ) * 100.0;
201 :
202 : #define FULLNESS_PCT_THRESHOLD 80
203 : #define TLS_OVERHEAD_THRESHOLD 15
204 :
205 4 : const int severity = (fullness_pct < FULLNESS_PCT_THRESHOLD ||
206 : overhead_pct > TLS_OVERHEAD_THRESHOLD)
207 5 : ? LOG_NOTICE : LOG_INFO;
208 :
209 5 : log_fn(severity, LD_HEARTBEAT,
210 : "Average packaged cell fullness: %2.3f%%. "
211 : "TLS write overhead: %.f%%", fullness_pct, overhead_pct);
212 :
213 5 : if (public_server_mode(options)) {
214 1 : rep_hist_log_circuit_handshake_stats(now);
215 1 : rep_hist_log_link_protocol_counts();
216 1 : dos_log_heartbeat();
217 : }
218 :
219 5 : circuit_log_ancient_one_hop_circuits(1800);
220 :
221 5 : if (options->BridgeRelay) {
222 0 : char *msg = NULL;
223 0 : msg = format_client_stats_heartbeat(now);
224 0 : if (msg)
225 0 : log_notice(LD_HEARTBEAT, "%s", msg);
226 0 : tor_free(msg);
227 : }
228 :
229 5 : if (options->MainloopStats) {
230 0 : const uint64_t main_loop_success_count = get_main_loop_success_count();
231 0 : const uint64_t main_loop_error_count = get_main_loop_error_count();
232 0 : const uint64_t main_loop_idle_count = get_main_loop_idle_count();
233 :
234 0 : log_fn(LOG_NOTICE, LD_HEARTBEAT, "Main event loop statistics: "
235 : "%"PRIu64 " successful returns, "
236 : "%"PRIu64 " erroneous returns, and "
237 : "%"PRIu64 " idle returns.",
238 : (main_loop_success_count),
239 : (main_loop_error_count),
240 : (main_loop_idle_count));
241 : }
242 :
243 : /** Now, if we are an HS service, log some stats about our usage */
244 5 : log_onion_service_stats();
245 :
246 5 : tor_free(uptime);
247 5 : tor_free(bw_sent);
248 5 : tor_free(bw_rcvd);
249 :
250 5 : return 0;
251 : }
252 :
253 : static void
254 1 : log_accounting(const time_t now, const or_options_t *options)
255 : {
256 1 : or_state_t *state = get_or_state();
257 1 : char *acc_rcvd = bytes_to_usage(state->AccountingBytesReadInInterval);
258 1 : char *acc_sent = bytes_to_usage(state->AccountingBytesWrittenInInterval);
259 1 : char *acc_used = bytes_to_usage(get_accounting_bytes());
260 1 : uint64_t acc_bytes = options->AccountingMax;
261 1 : char *acc_max;
262 1 : time_t interval_end = accounting_get_end_time();
263 1 : char end_buf[ISO_TIME_LEN + 1];
264 1 : char *remaining = NULL;
265 1 : acc_max = bytes_to_usage(acc_bytes);
266 1 : format_local_iso_time(end_buf, interval_end);
267 1 : remaining = secs_to_uptime(interval_end - now);
268 :
269 1 : const char *acc_rule;
270 1 : switch (options->AccountingRule) {
271 : case ACCT_MAX: acc_rule = "max";
272 : break;
273 0 : case ACCT_SUM: acc_rule = "sum";
274 0 : break;
275 0 : case ACCT_OUT: acc_rule = "out";
276 0 : break;
277 0 : case ACCT_IN: acc_rule = "in";
278 0 : break;
279 : default: acc_rule = "max";
280 : break;
281 : }
282 :
283 1 : log_notice(LD_HEARTBEAT, "Heartbeat: Accounting enabled. "
284 : "Sent: %s, Received: %s, Used: %s / %s, Rule: %s. The "
285 : "current accounting interval ends on %s, in %s.",
286 : acc_sent, acc_rcvd, acc_used, acc_max, acc_rule, end_buf, remaining);
287 :
288 1 : tor_free(acc_rcvd);
289 1 : tor_free(acc_sent);
290 1 : tor_free(acc_used);
291 1 : tor_free(acc_max);
292 1 : tor_free(remaining);
293 1 : }
|
