From 3a73f6612aad051e0d9a9228a136e06720748c16 Mon Sep 17 00:00:00 2001 From: Nick Mathewson Date: Thu, 17 Oct 2019 12:30:52 -0400 Subject: [PATCH 1/9] Replace add_temp_log() with add_default_log(). We used to have this function so that we could mark our initial log-to-stdout as specifically temporary so that we would delete it once regular logs were configured. But it's no longer necessary to mark these logs as temporary, since we now use a mark-and-sweep process to ensure that _all_ not-configured logs are closed when we change our configuration. Instead, this function will be the basis of a refactoring in how we handle default logs. --- src/app/main/main.c | 4 ++-- src/lib/log/log.c | 11 ++++------- src/lib/log/log.h | 2 +- 3 files changed, 7 insertions(+), 10 deletions(-) diff --git a/src/app/main/main.c b/src/app/main/main.c index 2d75793366..e6bd4f30b2 100644 --- a/src/app/main/main.c +++ b/src/app/main/main.c @@ -564,11 +564,11 @@ tor_init(int argc, char *argv[]) break; case QUIET_HUSH: /* --hush: log at warning or higher. */ - add_temp_log(LOG_WARN); + add_default_log(LOG_WARN); break; case QUIET_NONE: /* fall through */ default: - add_temp_log(LOG_NOTICE); + add_default_log(LOG_NOTICE); } quiet_level = quiet; diff --git a/src/lib/log/log.c b/src/lib/log/log.c index 83f04a3467..ddd0eac6e7 100644 --- a/src/lib/log/log.c +++ b/src/lib/log/log.c @@ -995,18 +995,16 @@ logs_set_domain_logging(int enabled) UNLOCK_LOGS(); } -/** Add a log handler to receive messages during startup (before the real - * logs are initialized). +/** Add a log handler to accept messages when no other log is configured. */ void -add_temp_log(int min_severity) +add_default_log(int min_severity) { log_severity_list_t *s = tor_malloc_zero(sizeof(log_severity_list_t)); set_log_severity_config(min_severity, LOG_ERR, s); LOCK_LOGS(); - add_stream_log_impl(s, "", fileno(stdout)); + add_stream_log_impl(s, "", fileno(stdout)); tor_free(s); - logfiles->is_temporary = 1; UNLOCK_LOGS(); } @@ -1149,8 +1147,7 @@ flush_log_messages_from_startup(void) UNLOCK_LOGS(); } -/** Close any log handlers added by add_temp_log() or marked by - * mark_logs_temp(). */ +/** Close any log handlers marked by mark_logs_temp(). */ void close_temp_logs(void) { diff --git a/src/lib/log/log.h b/src/lib/log/log.h index 8e36012616..4dead0fd2c 100644 --- a/src/lib/log/log.h +++ b/src/lib/log/log.h @@ -185,7 +185,7 @@ int get_min_log_level(void); void switch_logs_debug(void); void logs_free_all(void); void logs_close_sigsafe(void); -void add_temp_log(int min_severity); +void add_default_log(int min_severity); void close_temp_logs(void); void rollback_log_changes(void); void mark_logs_temp(void); From db18ff91208e0065c38e5f4d0dd57eb8a0ae513c Mon Sep 17 00:00:00 2001 From: Nick Mathewson Date: Thu, 17 Oct 2019 12:48:39 -0400 Subject: [PATCH 2/9] Move code to add default log into quiet_level.c I'm about to unify the code for handling this between main.c and config.c. --- src/app/config/quiet_level.c | 33 +++++++++++++++++++++++++++++++++ src/app/config/quiet_level.h | 2 ++ src/app/main/main.c | 23 +---------------------- src/core/include.am | 1 + 4 files changed, 37 insertions(+), 22 deletions(-) create mode 100644 src/app/config/quiet_level.c diff --git a/src/app/config/quiet_level.c b/src/app/config/quiet_level.c new file mode 100644 index 0000000000..f00d6b5a3b --- /dev/null +++ b/src/app/config/quiet_level.c @@ -0,0 +1,33 @@ +/* Copyright (c) 2001 Matej Pfajfar. + * Copyright (c) 2001-2004, Roger Dingledine. + * Copyright (c) 2004-2006, Roger Dingledine, Nick Mathewson. + * Copyright (c) 2007-2019, The Tor Project, Inc. */ +/* See LICENSE for licensing information */ + +#include "orconfig.h" +#include "lib/log/log.h" +#include "app/config/quiet_level.h" + +/** Decides our behavior when no logs are configured/before any logs have been + * configured. For QUIET_NONE, we log notice to stdout as normal. For + * QUIET_HUSH, we log warnings only. For QUIET_SILENT, we log nothing. + */ +quiet_level_t quiet_level = 0; + +/** Add a default log (or not), depending on the value of quiet. */ +void +add_default_log_for_quiet_level(quiet_level_t quiet) +{ + switch (quiet) { + case QUIET_SILENT: + /* --quiet: no initial logging */ + return; + case QUIET_HUSH: + /* --hush: log at warning or higher. */ + add_default_log(LOG_WARN); + break; + case QUIET_NONE: /* fall through */ + default: + add_default_log(LOG_NOTICE); + } +} diff --git a/src/app/config/quiet_level.h b/src/app/config/quiet_level.h index e90ec3f276..03e3f58fb0 100644 --- a/src/app/config/quiet_level.h +++ b/src/app/config/quiet_level.h @@ -25,4 +25,6 @@ typedef enum { /** How quietly should Tor log at startup? */ extern quiet_level_t quiet_level; +void add_default_log_for_quiet_level(quiet_level_t quiet); + #endif /* !defined(QUIET_LEVEL_H) */ diff --git a/src/app/main/main.c b/src/app/main/main.c index e6bd4f30b2..fad2e0b62f 100644 --- a/src/app/main/main.c +++ b/src/app/main/main.c @@ -109,16 +109,6 @@ static void dumpmemusage(int severity); static void dumpstats(int severity); /* log stats */ static void process_signal(int sig); -/********* START VARIABLES **********/ - -/** Decides our behavior when no logs are configured/before any logs have been - * configured. For QUIET_NONE, we log notice to stdout as normal. For - * QUIET_HUSH, we log warnings only. For QUIET_SILENT, we log nothing. - */ -quiet_level_t quiet_level = 0; - -/********* END VARIABLES ************/ - /** Called when we get a SIGHUP: reload configuration files and keys, * retry all connections, and so on. */ static int @@ -558,18 +548,7 @@ tor_init(int argc, char *argv[]) } /* give it somewhere to log to initially */ - switch (quiet) { - case QUIET_SILENT: - /* --quiet: no initial logging */ - break; - case QUIET_HUSH: - /* --hush: log at warning or higher. */ - add_default_log(LOG_WARN); - break; - case QUIET_NONE: /* fall through */ - default: - add_default_log(LOG_NOTICE); - } + add_default_log_for_quiet_level(quiet); quiet_level = quiet; { diff --git a/src/core/include.am b/src/core/include.am index f6ae3f2b51..fb2f93d81e 100644 --- a/src/core/include.am +++ b/src/core/include.am @@ -9,6 +9,7 @@ endif # ADD_C_FILE: INSERT SOURCES HERE. LIBTOR_APP_A_SOURCES = \ src/app/config/config.c \ + src/app/config/quiet_level.c \ src/app/config/statefile.c \ src/app/main/main.c \ src/app/main/shutdown.c \ From e07b19d3055f9ce080efaf2295f1ca096b10db3c Mon Sep 17 00:00:00 2001 From: Nick Mathewson Date: Thu, 17 Oct 2019 13:13:52 -0400 Subject: [PATCH 3/9] Rationalize handling of quiet_level in config.c Formerly, we would use quiet_level as an excuse to rewrite the log configuration, adding a default log line if none existed, and if RunAsDaemon was not set, and if we were not being invoked via setconf (!). This is against our best practices for several reasons: * We should not be changing configured options except when the user tells us to do so. * We should especially not be changing options in the options_validate function. * Distinguishing whether we are being called from setconf adds a risky special-case. Instead, this patch take a simpler approach: it changes the interpretation of having no logging lines set to mean: If there is a stdout, add a default log based on quiet_level. Solves ticket 31999. --- src/app/config/config.c | 23 +++++++++-------------- 1 file changed, 9 insertions(+), 14 deletions(-) diff --git a/src/app/config/config.c b/src/app/config/config.c index 37eab22912..0a8c0d536d 100644 --- a/src/app/config/config.c +++ b/src/app/config/config.c @@ -3428,20 +3428,17 @@ options_validate_single_onion(or_options_t *options, char **msg) * normalizing the contents of options. * * On error, tor_strdup an error explanation into *msg. - * - * XXX - * If from_setconf, we were called by the controller, and our - * Log line should stay empty. If it's 0, then give us a default log - * if there are no logs defined. */ STATIC int options_validate(or_options_t *old_options, or_options_t *options, - or_options_t *default_options, int from_setconf, char **msg) + or_options_t *default_options, int from_setconf_unused, + char **msg) { config_line_t *cl; const char *uname = get_uname(); int n_ports=0; int world_writable_control_socket=0; + (void)from_setconf_unused; /* 29211 TODO: Remove this from the API. */ tor_assert(msg); *msg = NULL; @@ -3504,14 +3501,6 @@ options_validate(or_options_t *old_options, or_options_t *options, check_network_configuration(server_mode(options)); - /* Special case on first boot if no Log options are given. */ - if (!options->Logs && !options->RunAsDaemon && !from_setconf) { - if (quiet_level == 0) - config_line_append(&options->Logs, "Log", "notice stdout"); - else if (quiet_level == 1) - config_line_append(&options->Logs, "Log", "warn stdout"); - } - /* Validate the tor_log(s) */ if (options_init_logs(old_options, options, 1)<0) REJECT("Failed to validate Log options. See logs for details."); @@ -5733,6 +5722,12 @@ options_init_logs(const or_options_t *old_options, or_options_t *options, ok = 1; elts = smartlist_new(); + if (options->Logs == NULL && !run_as_daemon && !validate_only) { + /* When no logs are given, the default behavior is to log nothing (if + RunAsDaemon is set) or to log based on the quiet level otherwise. */ + add_default_log_for_quiet_level(quiet_level); + } + for (opt = options->Logs; opt; opt = opt->next) { log_severity_list_t *severity; const char *cfg = opt->value; From 98c3b3bb4ca7679a5045f285db7fd30b5d069615 Mon Sep 17 00:00:00 2001 From: Nick Mathewson Date: Thu, 17 Oct 2019 13:23:11 -0400 Subject: [PATCH 4/9] Update tests to handle new interpretation of quiet_level. Two things needed to be changed. First, we used to set quiet_level to the default (QUIET_NONE) when running tests, since we would not call anything that acted based upon it. But since we sometimes call options_init_logs(), we need to pre-set quiet_level to QUIET_SILENT in the logs so that we don't add the default logs. This did not cause test failure: just unwanted logs. Second, we had a test that checked whether options_validate was messing with options->Logs correctly. Since options_validate no longer messes with the logs, we no longer want a test for this. --- src/test/test_options.c | 6 ++---- src/test/testing_common.c | 3 +++ 2 files changed, 5 insertions(+), 4 deletions(-) diff --git a/src/test/test_options.c b/src/test/test_options.c index 69407a999b..0a7cd03e57 100644 --- a/src/test/test_options.c +++ b/src/test/test_options.c @@ -678,8 +678,7 @@ test_options_validate__logs(void *ignored) tdata->opt->RunAsDaemon = 0; ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); - tt_str_op(tdata->opt->Logs->key, OP_EQ, "Log"); - tt_str_op(tdata->opt->Logs->value, OP_EQ, "notice stdout"); + tt_assert(!tdata->opt->Logs); tor_free(msg); tt_int_op(ret, OP_EQ, -1); @@ -689,8 +688,7 @@ test_options_validate__logs(void *ignored) tdata->opt->RunAsDaemon = 0; quiet_level = 1; ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); - tt_str_op(tdata->opt->Logs->key, OP_EQ, "Log"); - tt_str_op(tdata->opt->Logs->value, OP_EQ, "warn stdout"); + tt_assert(!tdata->opt->Logs); tor_free(msg); tt_int_op(ret, OP_EQ, -1); diff --git a/src/test/testing_common.c b/src/test/testing_common.c index ff6028ddb4..e14a169407 100644 --- a/src/test/testing_common.c +++ b/src/test/testing_common.c @@ -272,6 +272,9 @@ main(int c, const char **v) control_initialize_event_queue(); + /* Don't add default logs; the tests manage their own. */ + quiet_level = QUIET_SILENT; + for (i_out = i = 1; i < c; ++i) { if (!strcmp(v[i], "--warn")) { loglevel = LOG_WARN; From ac3136a6fb52500d849db7622b4af0af42038a91 Mon Sep 17 00:00:00 2001 From: Nick Mathewson Date: Thu, 17 Oct 2019 15:28:07 -0400 Subject: [PATCH 5/9] Make options_init_logs STATIC for testing. --- src/app/config/config.c | 4 +--- src/app/config/config.h | 2 ++ 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/src/app/config/config.c b/src/app/config/config.c index 0a8c0d536d..1c04dcaf08 100644 --- a/src/app/config/config.c +++ b/src/app/config/config.c @@ -836,8 +836,6 @@ static int check_server_ports(const smartlist_t *ports, static int validate_data_directories(or_options_t *options); static int write_configuration_file(const char *fname, const or_options_t *options); -static int options_init_logs(const or_options_t *old_options, - or_options_t *options, int validate_only); static void init_libevent(const or_options_t *options); static int opt_streq(const char *s1, const char *s2); @@ -5676,7 +5674,7 @@ open_and_add_file_log(const log_severity_list_t *severity, /** * Initialize the logs based on the configuration file. */ -static int +STATIC int options_init_logs(const or_options_t *old_options, or_options_t *options, int validate_only) { diff --git a/src/app/config/config.h b/src/app/config/config.h index e5b687c311..0c61fc7c0f 100644 --- a/src/app/config/config.h +++ b/src/app/config/config.h @@ -309,6 +309,8 @@ STATIC uint64_t compute_real_max_mem_in_queues(const uint64_t val, STATIC int open_and_add_file_log(const log_severity_list_t *severity, const char *fname, int truncate_log); +STATIC int options_init_logs(const or_options_t *old_options, + or_options_t *options, int validate_only); #endif /* defined(CONFIG_PRIVATE) */ From f4fc633937b56e52087c0e1c7a962a3a8cd7d2d4 Mon Sep 17 00:00:00 2001 From: Nick Mathewson Date: Mon, 21 Oct 2019 11:42:20 -0400 Subject: [PATCH 6/9] Make a pair of add_*_log() functions mockable. --- src/lib/log/log.c | 18 +++++++++--------- src/lib/log/log.h | 14 ++++++++------ 2 files changed, 17 insertions(+), 15 deletions(-) diff --git a/src/lib/log/log.c b/src/lib/log/log.c index ddd0eac6e7..dc53b386b0 100644 --- a/src/lib/log/log.c +++ b/src/lib/log/log.c @@ -276,8 +276,8 @@ static int log_time_granularity = 1; /** Define log time granularity for all logs to be granularity_msec * milliseconds. */ -void -set_log_time_granularity(int granularity_msec) +MOCK_IMPL(void, +set_log_time_granularity,(int granularity_msec)) { log_time_granularity = granularity_msec; tor_log_sigsafe_err_set_granularity(granularity_msec); @@ -937,9 +937,9 @@ set_log_severity_config(int loglevelMin, int loglevelMax, /** Add a log handler named name to send all messages in severity * to fd. Copies severity. Helper: does no locking. */ -static void -add_stream_log_impl(const log_severity_list_t *severity, - const char *name, int fd) +MOCK_IMPL(STATIC void, +add_stream_log_impl,(const log_severity_list_t *severity, + const char *name, int fd)) { logfile_t *lf; lf = tor_malloc_zero(sizeof(logfile_t)); @@ -1199,10 +1199,10 @@ mark_logs_temp(void) * opening the logfile failed, -1 is returned and errno is set appropriately * (by open(2)). Takes ownership of fd. */ -int -add_file_log(const log_severity_list_t *severity, - const char *filename, - int fd) +MOCK_IMPL(int, +add_file_log,(const log_severity_list_t *severity, + const char *filename, + int fd)) { logfile_t *lf; diff --git a/src/lib/log/log.h b/src/lib/log/log.h index 4dead0fd2c..374db76e12 100644 --- a/src/lib/log/log.h +++ b/src/lib/log/log.h @@ -163,11 +163,11 @@ int parse_log_severity_config(const char **cfg, log_severity_list_t *severity_out); void set_log_severity_config(int minSeverity, int maxSeverity, log_severity_list_t *severity_out); -void add_stream_log(const log_severity_list_t *severity, const char *name, - int fd); -int add_file_log(const log_severity_list_t *severity, - const char *filename, - int fd); +void add_stream_log(const log_severity_list_t *severity, + const char *name, int fd); +MOCK_DECL(int, add_file_log,(const log_severity_list_t *severity, + const char *filename, + int fd)); #ifdef HAVE_SYSLOG_H int add_syslog_log(const log_severity_list_t *severity, @@ -194,7 +194,7 @@ void change_callback_log_severity(int loglevelMin, int loglevelMax, void flush_pending_log_callbacks(void); void flush_log_messages_from_startup(void); void log_set_application_name(const char *name); -void set_log_time_granularity(int granularity_msec); +MOCK_DECL(void, set_log_time_granularity,(int granularity_msec)); void truncate_logs(void); void tor_log(int severity, log_domain_mask_t domain, const char *format, ...) @@ -306,6 +306,8 @@ extern const log_domain_mask_t LD_GENERAL_; MOCK_DECL(STATIC void, logv, (int severity, log_domain_mask_t domain, const char *funcname, const char *suffix, const char *format, va_list ap) CHECK_PRINTF(5,0)); +MOCK_DECL(STATIC void, add_stream_log_impl,( + const log_severity_list_t *severity, const char *name, int fd)); #endif #if defined(LOG_PRIVATE) || defined(TOR_UNIT_TESTS) From 9ac2c71cbd4f2acd6b066bdbe0d37c8576dc9930 Mon Sep 17 00:00:00 2001 From: Nick Mathewson Date: Mon, 21 Oct 2019 11:42:40 -0400 Subject: [PATCH 7/9] Add tests for options_init_logs() --- src/test/test_options.c | 190 ++++++++++++++++++++++++++++++++++++++++ 1 file changed, 190 insertions(+) diff --git a/src/test/test_options.c b/src/test/test_options.c index 0a7cd03e57..8885ecfdd3 100644 --- a/src/test/test_options.c +++ b/src/test/test_options.c @@ -4,6 +4,7 @@ /* See LICENSE for licensing information */ #define CONFIG_PRIVATE +#define LOG_PRIVATE #include "core/or/or.h" #include "lib/confmgt/confparse.h" #include "app/config/config.h" @@ -4164,6 +4165,191 @@ test_options_validate__accel(void *ignored) tor_free(msg); } +static int mocked_granularity; + +static void +mock_set_log_time_granularity(int g) +{ + mocked_granularity = g; +} + +static void +test_options_init_logs_granularity(void *arg) +{ + options_test_data_t *tdata = get_options_test_data(""); + int rv; + (void) arg; + + MOCK(set_log_time_granularity, mock_set_log_time_granularity); + + /* Reasonable value. */ + tdata->opt->LogTimeGranularity = 100; + mocked_granularity = -1; + rv = options_init_logs(NULL, tdata->opt, 0); + tt_int_op(rv, OP_EQ, 0); + tt_int_op(mocked_granularity, OP_EQ, 100); + + /* Doesn't divide 1000. */ + tdata->opt->LogTimeGranularity = 249; + mocked_granularity = -1; + rv = options_init_logs(NULL, tdata->opt, 0); + tt_int_op(rv, OP_EQ, 0); + tt_int_op(mocked_granularity, OP_EQ, 250); + + /* Doesn't divide 1000. */ + tdata->opt->LogTimeGranularity = 3; + mocked_granularity = -1; + rv = options_init_logs(NULL, tdata->opt, 0); + tt_int_op(rv, OP_EQ, 0); + tt_int_op(mocked_granularity, OP_EQ, 4); + + /* Not a multiple of 1000. */ + tdata->opt->LogTimeGranularity = 1500; + mocked_granularity = -1; + rv = options_init_logs(NULL, tdata->opt, 0); + tt_int_op(rv, OP_EQ, 0); + tt_int_op(mocked_granularity, OP_EQ, 2000); + + /* Reasonable value. */ + tdata->opt->LogTimeGranularity = 3000; + mocked_granularity = -1; + rv = options_init_logs(NULL, tdata->opt, 0); + tt_int_op(rv, OP_EQ, 0); + tt_int_op(mocked_granularity, OP_EQ, 3000); + + /* Negative. (Shouldn't be allowed by rest of config parsing.) */ + tdata->opt->LogTimeGranularity = -1; + mocked_granularity = -1; + rv = options_init_logs(NULL, tdata->opt, 0); + tt_int_op(rv, OP_EQ, -1); + + /* Very big */ + tdata->opt->LogTimeGranularity = 3600 * 1000; + mocked_granularity = -1; + rv = options_init_logs(NULL, tdata->opt, 0); + tt_int_op(rv, OP_EQ, 0); + tt_int_op(mocked_granularity, OP_EQ, 3600 * 1000); + + done: + free_options_test_data(tdata); + UNMOCK(set_log_time_granularity); +} + +typedef struct { + char *name; + log_severity_list_t sev; + int fd; + bool stream; +} added_log_t; + +static smartlist_t *added_logs = NULL; + +static void +mock_add_stream_log_impl(const log_severity_list_t *sev, const char *name, + int fd) +{ + added_log_t *a = tor_malloc_zero(sizeof(added_log_t)); + a->name = tor_strdup(name); + memcpy(&a->sev, sev, sizeof(log_severity_list_t)); + a->fd = fd; + a->stream = true; + smartlist_add(added_logs, a); +} + +static int +mock_add_file_log(const log_severity_list_t *sev, const char *name, int fd) +{ + added_log_t *a = tor_malloc_zero(sizeof(added_log_t)); + a->name = tor_strdup(name); + memcpy(&a->sev, sev, sizeof(log_severity_list_t)); + a->fd = fd; + smartlist_add(added_logs, a); + return 0; +} + +static void +clear_added_logs(void) +{ + SMARTLIST_FOREACH(added_logs, added_log_t *, a, + { tor_free(a->name); tor_free(a); }); + smartlist_clear(added_logs); +} + +static void +test_options_init_logs_quiet(void *arg) +{ + (void)arg; + char *cfg = NULL; + options_test_data_t *tdata = get_options_test_data(""); + char *fn1 = tor_strdup(get_fname_rnd("log")); + const added_log_t *a; + int rv; + tdata->opt->RunAsDaemon = 0; + + added_logs = smartlist_new(); + MOCK(add_stream_log_impl, mock_add_stream_log_impl); + MOCK(add_file_log, mock_add_file_log); + + tt_ptr_op(tdata->opt->Logs, OP_EQ, NULL); + + /* First, try with no configured logs, and make sure that our configured + logs match the quiet level. */ + quiet_level = QUIET_SILENT; + rv = options_init_logs(NULL, tdata->opt, 0); + tt_int_op(rv, OP_EQ, 0); + tt_int_op(smartlist_len(added_logs), OP_EQ, 0); + + quiet_level = QUIET_HUSH; + rv = options_init_logs(NULL, tdata->opt, 0); + tt_int_op(rv, OP_EQ, 0); + tt_int_op(smartlist_len(added_logs), OP_EQ, 1); + a = smartlist_get(added_logs, 0); + tt_assert(a); + tt_assert(a->stream); + tt_int_op(a->fd, OP_EQ, fileno(stdout)); + tt_int_op(a->sev.masks[LOG_INFO-LOG_ERR], OP_EQ, 0); + tt_int_op(a->sev.masks[LOG_NOTICE-LOG_ERR], OP_EQ, 0); + tt_int_op(a->sev.masks[LOG_WARN-LOG_ERR], OP_EQ, LD_ALL_DOMAINS); + clear_added_logs(); + + quiet_level = QUIET_NONE; + rv = options_init_logs(NULL, tdata->opt, 0); + tt_int_op(rv, OP_EQ, 0); + tt_int_op(smartlist_len(added_logs), OP_EQ, 1); + a = smartlist_get(added_logs, 0); + tt_assert(a); + tt_assert(a->stream); + tt_int_op(a->fd, OP_EQ, fileno(stdout)); + tt_int_op(a->sev.masks[LOG_INFO-LOG_ERR], OP_EQ, 0); + tt_int_op(a->sev.masks[LOG_NOTICE-LOG_ERR], OP_EQ, LD_ALL_DOMAINS); + tt_int_op(a->sev.masks[LOG_WARN-LOG_ERR], OP_EQ, LD_ALL_DOMAINS); + clear_added_logs(); + + /* Make sure that adding a configured log makes the default logs go away. */ + tor_asprintf(&cfg, "Log info file %s\n", fn1); + free_options_test_data(tdata); + tdata = get_options_test_data(cfg); + rv = options_init_logs(NULL, tdata->opt, 0); + tt_int_op(rv, OP_EQ, 0); + tt_int_op(smartlist_len(added_logs), OP_EQ, 1); + a = smartlist_get(added_logs, 0); + tt_assert(a); + tt_assert(! a->stream); + tt_int_op(a->fd, OP_NE, fileno(stdout)); + tt_int_op(a->sev.masks[LOG_INFO-LOG_ERR], OP_EQ, LD_ALL_DOMAINS); + tt_int_op(a->sev.masks[LOG_NOTICE-LOG_ERR], OP_EQ, LD_ALL_DOMAINS); + tt_int_op(a->sev.masks[LOG_WARN-LOG_ERR], OP_EQ, LD_ALL_DOMAINS); + + done: + free_options_test_data(tdata); + tor_free(fn1); + tor_free(cfg); + clear_added_logs(); + smartlist_free(added_logs); + UNMOCK(add_stream_log_impl); + UNMOCK(add_file_log); +} + #define LOCAL_VALIDATE_TEST(name) \ { "validate__" #name, test_options_validate__ ## name, TT_FORK, NULL, NULL } @@ -4211,5 +4397,9 @@ struct testcase_t options_tests[] = { LOCAL_VALIDATE_TEST(virtual_addr), LOCAL_VALIDATE_TEST(testing_options), LOCAL_VALIDATE_TEST(accel), + { "init_logs/granularity", test_options_init_logs_granularity, TT_FORK, + NULL, NULL }, + { "init_logs/quiet", test_options_init_logs_quiet, TT_FORK, + NULL, NULL }, END_OF_TESTCASES /* */ }; From 6d15fab2dc377503aa20086723b6faf41a0a0d34 Mon Sep 17 00:00:00 2001 From: Nick Mathewson Date: Mon, 21 Oct 2019 11:58:53 -0400 Subject: [PATCH 8/9] Extract log-granularity code into its own function. This pleases practracker. --- src/app/config/config.c | 45 +++++++++++++++++++++++++++-------------- 1 file changed, 30 insertions(+), 15 deletions(-) diff --git a/src/app/config/config.c b/src/app/config/config.c index 1c04dcaf08..5f59ce32ff 100644 --- a/src/app/config/config.c +++ b/src/app/config/config.c @@ -5672,22 +5672,14 @@ open_and_add_file_log(const log_severity_list_t *severity, } /** - * Initialize the logs based on the configuration file. - */ -STATIC int -options_init_logs(const or_options_t *old_options, or_options_t *options, - int validate_only) + * Try to set our global log granularity from `options->LogGranularity`, + * adjusting it as needed so that we are an even divisor of a second, or an + * even multiple of seconds. Return 0 on success, -1 on failure. + **/ +static int +options_init_log_granularity(const or_options_t *options, + int validate_only) { - config_line_t *opt; - int ok; - smartlist_t *elts; - int run_as_daemon = -#ifdef _WIN32 - 0; -#else - options->RunAsDaemon; -#endif - if (options->LogTimeGranularity <= 0) { log_warn(LD_CONFIG, "Log time granularity '%d' has to be positive.", options->LogTimeGranularity); @@ -5717,6 +5709,29 @@ options_init_logs(const or_options_t *old_options, or_options_t *options, set_log_time_granularity(options->LogTimeGranularity); } + return 0; +} + +/** + * Initialize the logs based on the configuration file. + */ +STATIC int +options_init_logs(const or_options_t *old_options, or_options_t *options, + int validate_only) +{ + config_line_t *opt; + int ok; + smartlist_t *elts; + int run_as_daemon = +#ifdef _WIN32 + 0; +#else + options->RunAsDaemon; +#endif + + if (options_init_log_granularity(options, validate_only) < 0) + return -1; + ok = 1; elts = smartlist_new(); From 0bb2e77283abb6a7550eb9615df1d7360e7dcbbb Mon Sep 17 00:00:00 2001 From: Nick Mathewson Date: Mon, 21 Oct 2019 12:07:44 -0400 Subject: [PATCH 9/9] changes file for 31999 --- changes/ticket31999 | 6 ++++++ 1 file changed, 6 insertions(+) create mode 100644 changes/ticket31999 diff --git a/changes/ticket31999 b/changes/ticket31999 new file mode 100644 index 0000000000..31f230ee20 --- /dev/null +++ b/changes/ticket31999 @@ -0,0 +1,6 @@ + o Code simplification and refactoring: + - Our default log (which ordinarily sends NOTICE-level message to + standard output) is now handled in a more logical manner. Previously, + we replaced the configured log options if they were empty. + Now, we interpret an empty set of log options as meaning "use the + default log". Closes ticket 31999.