src/test/test_logging.c

   1 /* Copyright (c) 2013-2021, The Tor Project, Inc. */
   2 /* See LICENSE for licensing information */
   3
   4 #define CONFIG_PRIVATE
   5
   6 #include "orconfig.h"
   7 #include "core/or/or.h"
   8 #include "app/config/config.h"
   9 #include "lib/err/torerr.h"
  10 #include "lib/log/log.h"
  11 #include "test/test.h"
  12
  13 #ifdef HAVE_UNISTD_H
  14 #include <unistd.h>
  15 #endif
  16
  17 static void
  18 dummy_cb_fn(int severity, log_domain_mask_t domain, const char *msg)
  19 {
  20   (void)severity; (void)domain; (void)msg;
  21 }
  22
  23 static void
  24 test_get_sigsafe_err_fds(void *arg)
  25 {
  26   const int *fds;
  27   int n;
  28   log_severity_list_t include_bug, no_bug, no_bug2;
  29   (void) arg;
  30   init_logging(1);
  31
  32   n = tor_log_get_sigsafe_err_fds(&fds);
  33   tt_int_op(n, OP_EQ, 1);
  34   tt_int_op(fds[0], OP_EQ, STDERR_FILENO);
  35
  36   set_log_severity_config(LOG_WARN, LOG_ERR, &include_bug);
  37   set_log_severity_config(LOG_WARN, LOG_ERR, &no_bug);
  38   no_bug.masks[SEVERITY_MASK_IDX(LOG_ERR)] &= ~(LD_BUG|LD_GENERAL);
  39   set_log_severity_config(LOG_INFO, LOG_NOTICE, &no_bug2);
  40
  41   /* Add some logs; make sure the output is as expected. */
  42   mark_logs_temp();
  43   add_stream_log(&include_bug, "dummy-1", 3);
  44   add_stream_log(&no_bug, "dummy-2", 4);
  45   add_stream_log(&no_bug2, "dummy-3", 5);
  46   add_callback_log(&include_bug, dummy_cb_fn);
  47   close_temp_logs();
  48   tor_log_update_sigsafe_err_fds();
  49
  50   n = tor_log_get_sigsafe_err_fds(&fds);
  51   tt_int_op(n, OP_EQ, 2);
  52   tt_int_op(fds[0], OP_EQ, STDERR_FILENO);
  53   tt_int_op(fds[1], OP_EQ, 3);
  54
  55   /* Allow STDOUT to replace STDERR. */
  56   add_stream_log(&include_bug, "dummy-4", STDOUT_FILENO);
  57   tor_log_update_sigsafe_err_fds();
  58   n = tor_log_get_sigsafe_err_fds(&fds);
  59   tt_int_op(n, OP_EQ, 2);
  60   tt_int_op(fds[0], OP_EQ, 3);
  61   tt_int_op(fds[1], OP_EQ, STDOUT_FILENO);
  62
  63   /* But don't allow it to replace explicit STDERR. */
  64   add_stream_log(&include_bug, "dummy-5", STDERR_FILENO);
  65   tor_log_update_sigsafe_err_fds();
  66   n = tor_log_get_sigsafe_err_fds(&fds);
  67   tt_int_op(n, OP_EQ, 3);
  68   tt_int_op(fds[0], OP_EQ, STDERR_FILENO);
  69   tt_int_op(fds[1], OP_EQ, STDOUT_FILENO);
  70   tt_int_op(fds[2], OP_EQ, 3);
  71
  72   /* Don't overflow the array. */
  73   {
  74     int i;
  75     for (i=5; i<20; ++i) {
  76       add_stream_log(&include_bug, "x-dummy", i);
  77     }
  78   }
  79   tor_log_update_sigsafe_err_fds();
  80   n = tor_log_get_sigsafe_err_fds(&fds);
  81   tt_int_op(n, OP_EQ, 8);
  82
  83  done:
  84   ;
  85 }
  86
  87 static void
  88 test_sigsafe_err(void *arg)
  89 {
  90   const char *fn=get_fname("sigsafe_err_log");
  91   char *content=NULL;
  92   log_severity_list_t include_bug;
  93   smartlist_t *lines = smartlist_new();
  94   (void)arg;
  95
  96   set_log_severity_config(LOG_WARN, LOG_ERR, &include_bug);
  97
  98   init_logging(1);
  99   mark_logs_temp();
 100   open_and_add_file_log(&include_bug, fn, 0);
 101   tor_log_update_sigsafe_err_fds();
 102   close_temp_logs();
 103
 104   close(STDERR_FILENO);
 105   log_err(LD_BUG, "Say, this isn't too cool.");
 106   tor_log_err_sigsafe("Minimal.\n", NULL);
 107
 108   set_log_time_granularity(100*1000);
 109   tor_log_err_sigsafe("Testing any ",
 110                       "attempt to manually log ",
 111                       "from a signal.\n",
 112                       NULL);
 113   mark_logs_temp();
 114   close_temp_logs();
 115   close(STDERR_FILENO);
 116   content = read_file_to_str(fn, 0, NULL);
 117
 118   tt_ptr_op(content, OP_NE, NULL);
 119   smartlist_split_string(lines, content, "\n", 0, 0);
 120   tt_int_op(smartlist_len(lines), OP_GE, 5);
 121
 122   if (strstr(smartlist_get(lines, 0), "opening new log file")) {
 123     void *item = smartlist_get(lines, 0);
 124     smartlist_del_keeporder(lines, 0);
 125     tor_free(item);
 126   }
 127
 128   tt_assert(strstr(smartlist_get(lines, 0), "Say, this isn't too cool"));
 129   tt_str_op(smartlist_get(lines, 1), OP_EQ, "");
 130   tt_assert(!strcmpstart(smartlist_get(lines, 2), "=============="));
 131   tt_assert(!strcmpstart(smartlist_get(lines, 3), "Minimal."));
 132   tt_str_op(smartlist_get(lines, 4), OP_EQ, "");
 133   tt_assert(!strcmpstart(smartlist_get(lines, 5), "=============="));
 134   tt_str_op(smartlist_get(lines, 6), OP_EQ,
 135             "Testing any attempt to manually log from a signal.");
 136
 137  done:
 138   tor_free(content);
 139   SMARTLIST_FOREACH(lines, char *, x, tor_free(x));
 140   smartlist_free(lines);
 141 }
 142
 143 static void
 144 test_ratelim(void *arg)
 145 {
 146   (void) arg;
 147   ratelim_t ten_min = RATELIM_INIT(10*60);
 148
 149   const time_t start = 1466091600;
 150   time_t now = start;
 151   /* Initially, we're ready. */
 152
 153   char *msg = NULL;
 154
 155   msg = rate_limit_log(&ten_min, now);
 156   tt_ptr_op(msg, OP_NE, NULL);
 157   tt_str_op(msg, OP_EQ, ""); /* nothing was suppressed. */
 158
 159   tt_int_op(ten_min.last_allowed, OP_EQ, now);
 160   tor_free(msg);
 161
 162   int i;
 163   time_t first_suppressed_at = now + 60;
 164   for (i = 0; i < 9; ++i) {
 165     now += 60; /* one minute has passed. */
 166     msg = rate_limit_log(&ten_min, now);
 167     tt_ptr_op(msg, OP_EQ, NULL);
 168     tt_int_op(ten_min.last_allowed, OP_EQ, start);
 169     tt_int_op(ten_min.n_calls_since_last_time, OP_EQ, i + 1);
 170   }
 171   tt_i64_op(ten_min.started_limiting, OP_EQ, first_suppressed_at);
 172
 173   now += 240; /* Okay, we can be done. */
 174   msg = rate_limit_log(&ten_min, now);
 175   tt_ptr_op(msg, OP_NE, NULL);
 176   tt_str_op(msg, OP_EQ,
 177             " [9 similar message(s) suppressed in last 720 seconds]");
 178   tt_i64_op(now, OP_EQ, first_suppressed_at + 720);
 179
 180  done:
 181   tor_free(msg);
 182 }
 183
 184 struct testcase_t logging_tests[] = {
 185   { "sigsafe_err_fds", test_get_sigsafe_err_fds, TT_FORK, NULL, NULL },
 186   { "sigsafe_err", test_sigsafe_err, TT_FORK, NULL, NULL },
 187   { "ratelim", test_ratelim, 0, NULL, NULL },
 188   END_OF_TESTCASES
 189 };