test_logging.c 4.7 KB

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