test_logging.c 5.0 KB

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