Tor  0.4.8.0-alpha-dev
status.c
Go to the documentation of this file.
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"
21 #include "core/or/status.h"
23 #include "core/or/relay.h"
24 #include "feature/relay/router.h"
26 #include "core/or/circuitlist.h"
27 #include "core/mainloop/mainloop.h"
28 #include "feature/stats/rephist.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/connection_st.h"
34 #include "core/or/dos.h"
36 
37 #include "app/config/or_state_st.h"
39 #include "lib/tls/tortls.h"
40 
41 static void log_accounting(const time_t now, const or_options_t *options);
42 
43 /** Return the total number of circuits. */
44 STATIC int
46 {
47  return smartlist_len(circuit_get_global_list());
48 }
49 
50 /** Take seconds <b>secs</b> and return a newly allocated human-readable
51  * uptime string. */
52 STATIC char *
53 secs_to_uptime(long secs)
54 {
55  long int days = secs / 86400;
56  int hours = (int)((secs - (days * 86400)) / 3600);
57  int minutes = (int)((secs - (days * 86400) - (hours * 3600)) / 60);
58  char *uptime_string = NULL;
59 
60  switch (days) {
61  case 0:
62  tor_asprintf(&uptime_string, "%d:%02d hours", hours, minutes);
63  break;
64  case 1:
65  tor_asprintf(&uptime_string, "%ld day %d:%02d hours",
66  days, hours, minutes);
67  break;
68  default:
69  tor_asprintf(&uptime_string, "%ld days %d:%02d hours",
70  days, hours, minutes);
71  break;
72  }
73 
74  return uptime_string;
75 }
76 
77 /** Take <b>bytes</b> and returns a newly allocated human-readable usage
78  * string. */
79 STATIC char *
80 bytes_to_usage(uint64_t bytes)
81 {
82  char *bw_string = NULL;
83 
84  if (bytes < (1<<20)) { /* Less than a megabyte. */
85  tor_asprintf(&bw_string, "%"PRIu64" kB", (bytes>>10));
86  } else if (bytes < (1<<30)) { /* Megabytes. Let's add some precision. */
87  double bw = ((double)bytes);
88  tor_asprintf(&bw_string, "%.2f MB", bw/(1<<20));
89  } else { /* Gigabytes. */
90  double bw = ((double)bytes);
91  tor_asprintf(&bw_string, "%.2f GB", bw/(1<<30));
92  }
93 
94  return bw_string;
95 }
96 
97 /** Log some usage info about our onion service(s). */
98 static void
100 {
101  unsigned int num_services = hs_service_get_num_services();
102 
103  /* If there are no active onion services, no need to print logs */
104  if (num_services == 0) {
105  return;
106  }
107 
108  log_notice(LD_HEARTBEAT,
109  "Heartbeat: Our onion service%s received %u v3 INTRODUCE2 cells "
110  "and attempted to launch %d rendezvous circuits.",
111  num_services == 1 ? "" : "s",
114 }
115 
116 /**
117  * @name connection counts for heartbeat
118  *
119  * Tracks incoming and outgoing connections on IPv4/IPv6, for heartbeat
120  * logs.
121  **/
122 /**@{*/
123 static unsigned n_incoming_ipv4;
124 static unsigned n_incoming_ipv6;
125 static unsigned n_outgoing_ipv4;
126 static unsigned n_outgoing_ipv6;
127 /**@}*/
128 
129 /**
130  * Note that a connection has arrived or has been made, for use in the
131  * heartbeat message.
132  **/
133 void
134 note_connection(bool inbound, const connection_t *conn)
135 {
136  if (conn->socket_family == AF_INET) {
137  if (inbound) {
138  ++n_incoming_ipv4;
139  } else {
140  ++n_outgoing_ipv4;
141  }
142  } else if (conn->socket_family == AF_INET6) {
143  if (inbound) {
144  ++n_incoming_ipv6;
145  } else {
146  ++n_outgoing_ipv6;
147  }
148  }
149 
150  rep_hist_note_conn_opened(inbound, conn->type, conn->socket_family);
151 }
152 
153 /**
154  * @name Counters for unrecognized cells
155  *
156  * Track cells that we drop because they are unrecognized and we have
157  * nobody to send them to.
158  **/
159 /**@{*/
160 static unsigned n_circs_closed_for_unrecognized_cells;
161 static uint64_t n_unrecognized_cells_discarded;
162 static uint64_t n_secs_on_circs_with_unrecognized_cells;
163 /**@}*/
164 
165 /**
166  * Note that a circuit has closed @a n_seconds after having been created,
167  * because of one or more unrecognized cells. Also note the number of
168  * unrecognized cells @a n_cells.
169  */
170 void
171 note_circ_closed_for_unrecognized_cells(time_t n_seconds, uint32_t n_cells)
172 {
173  ++n_circs_closed_for_unrecognized_cells;
174  n_unrecognized_cells_discarded += n_cells;
175  if (n_seconds >= 0)
176  n_secs_on_circs_with_unrecognized_cells += (uint64_t) n_seconds;
177 }
178 
179 /** Log a "heartbeat" message describing Tor's status and history so that the
180  * user can know that there is indeed a running Tor. Return 0 on success and
181  * -1 on failure. */
182 int
183 log_heartbeat(time_t now)
184 {
185  char *bw_sent = NULL;
186  char *bw_rcvd = NULL;
187  char *uptime = NULL;
188  const routerinfo_t *me;
189  double r = tls_get_write_overhead_ratio();
190  const int hibernating = we_are_hibernating();
191 
192  const or_options_t *options = get_options();
193 
194  if (public_server_mode(options) && !hibernating) {
195  /* Let's check if we are in the current cached consensus. */
196  if (!(me = router_get_my_routerinfo()))
197  return -1; /* Something stinks, we won't even attempt this. */
198  else
199  if (!node_get_by_id(me->cache_info.identity_digest))
200  log_fn(LOG_NOTICE, LD_HEARTBEAT, "Heartbeat: It seems like we are not "
201  "in the cached consensus.");
202  }
203 
204  uptime = secs_to_uptime(get_uptime());
205  bw_rcvd = bytes_to_usage(get_bytes_read());
206  bw_sent = bytes_to_usage(get_bytes_written());
207 
208  log_fn(LOG_NOTICE, LD_HEARTBEAT, "Heartbeat: Tor's uptime is %s, with %d "
209  "circuits open. I've sent %s and received %s. I've received %u "
210  "connections on IPv4 and %u on IPv6. I've made %u connections "
211  "with IPv4 and %u with IPv6.%s",
212  uptime, count_circuits(), bw_sent, bw_rcvd,
213  n_incoming_ipv4, n_incoming_ipv6,
214  n_outgoing_ipv4, n_outgoing_ipv6,
215  hibernating?" We are currently hibernating.":"");
216 
218 
219  if (server_mode(options) && accounting_is_enabled(options) && !hibernating) {
220  log_accounting(now, options);
221  }
222 
223  double fullness_pct = 100;
224  if (stats_n_data_cells_packaged && !hibernating) {
225  fullness_pct =
226  100*(((double)stats_n_data_bytes_packaged) /
228  }
229  const double overhead_pct = ( r - 1.0 ) * 100.0;
230 
231 #define FULLNESS_PCT_THRESHOLD 80
232 #define TLS_OVERHEAD_THRESHOLD 15
233 
234  const int severity = (fullness_pct < FULLNESS_PCT_THRESHOLD ||
235  overhead_pct > TLS_OVERHEAD_THRESHOLD)
236  ? LOG_NOTICE : LOG_INFO;
237 
238  log_fn(severity, LD_HEARTBEAT,
239  "Average packaged cell fullness: %2.3f%%. "
240  "TLS write overhead: %.f%%", fullness_pct, overhead_pct);
241 
242  if (public_server_mode(options)) {
245  dos_log_heartbeat();
246  }
247 
249 
250  if (options->BridgeRelay) {
251  char *msg = NULL;
253  if (msg)
254  log_notice(LD_HEARTBEAT, "%s", msg);
255  tor_free(msg);
256  }
257 
258  if (options->MainloopStats) {
259  const uint64_t main_loop_success_count = get_main_loop_success_count();
260  const uint64_t main_loop_error_count = get_main_loop_error_count();
261  const uint64_t main_loop_idle_count = get_main_loop_idle_count();
262 
263  log_fn(LOG_NOTICE, LD_HEARTBEAT, "Main event loop statistics: "
264  "%"PRIu64 " successful returns, "
265  "%"PRIu64 " erroneous returns, and "
266  "%"PRIu64 " idle returns.",
267  (main_loop_success_count),
268  (main_loop_error_count),
269  (main_loop_idle_count));
270  }
271 
272  if (n_circs_closed_for_unrecognized_cells) {
273  double avg_time_alive = ((double) n_secs_on_circs_with_unrecognized_cells)
274  / n_circs_closed_for_unrecognized_cells;
275  double avg_cells = ((double) n_unrecognized_cells_discarded)
276  / n_circs_closed_for_unrecognized_cells;
278  "Since our last heartbeat, %u circuits were closed because of "
279  "unrecognized cells while we were the last hop. On average, each "
280  "one was alive for %lf seconds, and had %lf unrecognized cells.",
281  n_circs_closed_for_unrecognized_cells,
282  avg_time_alive,
283  avg_cells);
284  n_circs_closed_for_unrecognized_cells = 0;
285  n_unrecognized_cells_discarded = 0;
286  n_secs_on_circs_with_unrecognized_cells = 0;
287  }
288 
289  /** Now, if we are an HS service, log some stats about our usage */
291 
292  tor_free(uptime);
293  tor_free(bw_sent);
294  tor_free(bw_rcvd);
295 
296  return 0;
297 }
298 
299 static void
300 log_accounting(const time_t now, const or_options_t *options)
301 {
302  or_state_t *state = get_or_state();
303  char *acc_rcvd = bytes_to_usage(state->AccountingBytesReadInInterval);
304  char *acc_sent = bytes_to_usage(state->AccountingBytesWrittenInInterval);
305  char *acc_used = bytes_to_usage(get_accounting_bytes());
306  uint64_t acc_bytes = options->AccountingMax;
307  char *acc_max;
308  time_t interval_end = accounting_get_end_time();
309  char end_buf[ISO_TIME_LEN + 1];
310  char *remaining = NULL;
311  acc_max = bytes_to_usage(acc_bytes);
312  format_local_iso_time(end_buf, interval_end);
313  remaining = secs_to_uptime(interval_end - now);
314 
315  const char *acc_rule;
316  switch (options->AccountingRule) {
317  case ACCT_MAX: acc_rule = "max";
318  break;
319  case ACCT_SUM: acc_rule = "sum";
320  break;
321  case ACCT_OUT: acc_rule = "out";
322  break;
323  case ACCT_IN: acc_rule = "in";
324  break;
325  default: acc_rule = "max";
326  break;
327  }
328 
329  log_notice(LD_HEARTBEAT, "Heartbeat: Accounting enabled. "
330  "Sent: %s, Received: %s, Used: %s / %s, Rule: %s. The "
331  "current accounting interval ends on %s, in %s.",
332  acc_sent, acc_rcvd, acc_used, acc_max, acc_rule, end_buf, remaining);
333 
334  tor_free(acc_rcvd);
335  tor_free(acc_sent);
336  tor_free(acc_used);
337  tor_free(acc_max);
338  tor_free(remaining);
339 }
smartlist_t * circuit_get_global_list(void)
Definition: circuitlist.c:705
Header file for circuitlist.c.
void circuit_log_ancient_one_hop_circuits(int age)
Definition: circuituse.c:836
Header file for circuituse.c.
const or_options_t * get_options(void)
Definition: config.c:926
Header file for config.c.
Base connection structure.
void dirclient_dump_total_dls(void)
Definition: dirclient.c:1976
Header file for dirclient.c.
Header file for geoip_stats.c.
char * format_client_stats_heartbeat(time_t now)
Definition: geoip_stats.c:1207
time_t accounting_get_end_time(void)
Definition: hibernate.c:322
int accounting_is_enabled(const or_options_t *options)
Definition: hibernate.c:305
int we_are_hibernating(void)
Definition: hibernate.c:937
uint64_t get_accounting_bytes(void)
Definition: hibernate.c:478
Header file for hibernate.c.
unsigned int hs_service_get_num_services(void)
Definition: hs_service.c:3963
Header file containing service data for the HS subsystem.
uint32_t hs_stats_get_n_introduce2_v3_cells(void)
Definition: hs_stats.c:27
uint32_t hs_stats_get_n_rendezvous_launches(void)
Definition: hs_stats.c:41
Header file for hs_stats.c.
#define log_fn(severity, domain, args,...)
Definition: log.h:283
#define LD_HEARTBEAT
Definition: log.h:103
#define LOG_NOTICE
Definition: log.h:50
#define LOG_INFO
Definition: log.h:45
uint64_t get_bytes_read(void)
Definition: mainloop.c:455
uint64_t get_main_loop_error_count(void)
Definition: mainloop.c:540
uint64_t get_main_loop_idle_count(void)
Definition: mainloop.c:554
uint64_t get_main_loop_success_count(void)
Definition: mainloop.c:526
uint64_t get_bytes_written(void)
Definition: mainloop.c:465
long get_uptime(void)
Definition: mainloop.c:2547
Header file for mainloop.c.
#define tor_free(p)
Definition: malloc.h:56
const node_t * node_get_by_id(const char *identity_digest)
Definition: nodelist.c:226
Header file for nodelist.c.
Master header file for Tor-specific functionality.
#define RELAY_PAYLOAD_SIZE
Definition: or.h:485
The or_state_t structure, which represents Tor's state file.
int tor_asprintf(char **strp, const char *fmt,...)
Definition: printf.c:75
uint64_t stats_n_data_cells_packaged
Definition: relay.c:2117
uint64_t stats_n_data_bytes_packaged
Definition: relay.c:2121
Header file for relay.c.
void rep_hist_log_link_protocol_counts(void)
Definition: rephist.c:2958
void rep_hist_note_conn_opened(bool from_listener, unsigned int type, int af)
Definition: rephist.c:1707
void rep_hist_log_circuit_handshake_stats(time_t now)
Definition: rephist.c:2437
Header file for rephist.c.
const routerinfo_t * router_get_my_routerinfo(void)
Definition: router.c:1801
Header file for router.c.
Router descriptor structure.
int public_server_mode(const or_options_t *options)
Definition: routermode.c:43
int server_mode(const or_options_t *options)
Definition: routermode.c:34
Header file for routermode.c.
or_state_t * get_or_state(void)
Definition: statefile.c:220
Header for statefile.c.
STATIC char * bytes_to_usage(uint64_t bytes)
Definition: status.c:80
STATIC int count_circuits(void)
Definition: status.c:45
void note_circ_closed_for_unrecognized_cells(time_t n_seconds, uint32_t n_cells)
Definition: status.c:171
static void log_onion_service_stats(void)
Definition: status.c:99
STATIC char * secs_to_uptime(long secs)
Definition: status.c:53
void note_connection(bool inbound, const connection_t *conn)
Definition: status.c:134
int log_heartbeat(time_t now)
Definition: status.c:183
Header for status.c.
unsigned int type
Definition: connection_st.h:50
uint64_t AccountingMax
char identity_digest[DIGEST_LEN]
#define STATIC
Definition: testsupport.h:32
void format_local_iso_time(char *buf, time_t t)
Definition: time_fmt.c:316
Headers for tortls.c.
double tls_get_write_overhead_ratio(void)
Definition: tortls_nss.c:709