tor

The Tor anonymity network
git clone https://git.dasho.dev/tor.git
Log | Files | Refs | README | LICENSE

status.c (10550B)

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