status.c 7.4 KB

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