test_logging.c (5327B)
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 };