From e8815abff6444d1eed0335331447693679990b6c Mon Sep 17 00:00:00 2001 From: Daan De Meyer Date: Wed, 20 Mar 2024 09:34:46 +0100 Subject: [PATCH] log: Add per target log levels For CI in mkosi, I want to configure systemd to log at debug level to the journal, but not to the console. While we already have max level settings for journald's forwarding settings, not every log line goes to the journal, specifically during early boot and when units are connected directly to the console (think systemd-firstboot), so let's extend the log level options we already have to allow specifying a comma separated list of values and lets allow prefixing values with the log target they apply to to make this possible. --- man/common-variables.xml | 17 +++++--- src/basic/log.c | 87 ++++++++++++++++++++++++++++++++++++++-- src/basic/log.h | 8 ++-- src/core/execute.c | 8 ++-- src/core/main.c | 17 +++++--- 5 files changed, 115 insertions(+), 22 deletions(-) diff --git a/man/common-variables.xml b/man/common-variables.xml index 0113d1b6bb2..58a285c8335 100644 --- a/man/common-variables.xml +++ b/man/common-variables.xml @@ -11,13 +11,18 @@ $SYSTEMD_LOG_LEVEL The maximum log level of emitted messages (messages with a higher - log level, i.e. less important ones, will be suppressed). Either one of (in order of decreasing - importance) emerg, alert, crit, - err, warning, notice, - info, debug, or an integer in the range 0…7. See + log level, i.e. less important ones, will be suppressed). Takes a comma-separated list of values. A + value may be either one of (in order of decreasing importance) emerg, + alert, crit, err, + warning, notice, info, + debug, or an integer in the range 0…7. See syslog3 - for more information. - + for more information. Each value may optionally be prefixed with one of console, + syslog, kmsg or journal followed by a + colon to set the maximum log level for that specific log target (e.g. + SYSTEMD_LOG_LEVEL=debug,console:info specifies to log at debug level except when + logging to the console which should be at info level). Note that the global maximum log level takes + priority over any per target maximum log levels. diff --git a/src/basic/log.c b/src/basic/log.c index 4fc59e250c8..6faa6ad4fce 100644 --- a/src/basic/log.c +++ b/src/basic/log.c @@ -49,6 +49,12 @@ static void *log_syntax_callback_userdata = NULL; static LogTarget log_target = LOG_TARGET_CONSOLE; static int log_max_level = LOG_INFO; +static int log_target_max_level[] = { + [LOG_TARGET_CONSOLE] = INT_MAX, + [LOG_TARGET_KMSG] = INT_MAX, + [LOG_TARGET_SYSLOG] = INT_MAX, + [LOG_TARGET_JOURNAL] = INT_MAX, +}; static int log_facility = LOG_DAEMON; static bool ratelimit_kmsg = true; @@ -439,6 +445,9 @@ static int write_to_console( if (console_fd < 0) return 0; + if (LOG_PRI(level) > log_target_max_level[LOG_TARGET_CONSOLE]) + return 0; + if (log_target == LOG_TARGET_CONSOLE_PREFIXED) { xsprintf(prefix, "<%i>", level); iovec[n++] = IOVEC_MAKE_STRING(prefix); @@ -523,6 +532,9 @@ static int write_to_syslog( if (syslog_fd < 0) return 0; + if (LOG_PRI(level) > log_target_max_level[LOG_TARGET_SYSLOG]) + return 0; + xsprintf(header_priority, "<%i>", level); t = (time_t) (now(CLOCK_REALTIME) / USEC_PER_SEC); @@ -592,6 +604,9 @@ static int write_to_kmsg( if (kmsg_fd < 0) return 0; + if (LOG_PRI(level) > log_target_max_level[LOG_TARGET_KMSG]) + return 0; + if (ratelimit_kmsg && !ratelimit_below(&ratelimit)) { if (ratelimit_num_dropped(&ratelimit) > 1) return 0; @@ -719,6 +734,9 @@ static int write_to_journal( if (journal_fd < 0) return 0; + if (LOG_PRI(level) > log_target_max_level[LOG_TARGET_JOURNAL]) + return 0; + iovec_len = MIN(6 + _log_context_num_fields * 2, IOVEC_MAX); iovec = newa(struct iovec, iovec_len); @@ -1218,11 +1236,74 @@ int log_set_target_from_string(const char *e) { int log_set_max_level_from_string(const char *e) { int r; - r = log_level_from_string(e); + for (;;) { + _cleanup_free_ char *word = NULL, *prefix = NULL; + LogTarget target; + const char *colon; + + r = extract_first_word(&e, &word, ",", 0); + if (r < 0) + return r; + if (r == 0) + break; + + colon = strchr(word, ':'); + if (!colon) { + r = log_level_from_string(word); + if (r < 0) + return r; + + log_set_max_level(r); + continue; + } + + prefix = strndup(word, colon - word); + if (!prefix) + return -ENOMEM; + + target = log_target_from_string(prefix); + if (target < 0) + return target; + + if (target >= _LOG_TARGET_SINGLE_MAX) + return -EINVAL; + + r = log_level_from_string(colon + 1); + if (r < 0) + return r; + + log_target_max_level[target] = r; + } + + return 0; +} + +int log_max_levels_to_string(int level, char **ret) { + _cleanup_free_ char *s = NULL; + int r; + + assert(ret); + + r = log_level_to_string_alloc(level, &s); if (r < 0) return r; - log_set_max_level(r); + for (LogTarget target = 0; target < _LOG_TARGET_SINGLE_MAX; target++) { + _cleanup_free_ char *l = NULL; + + if (log_target_max_level[target] == INT_MAX) + continue; + + r = log_level_to_string_alloc(log_target_max_level[target], &l); + if (r < 0) + return r; + + r = strextendf_with_separator(&s, ",", "%s:%s", log_target_to_string(target), l); + if (r < 0) + return r; + } + + *ret = TAKE_PTR(s); return 0; } @@ -1273,7 +1354,7 @@ static int parse_proc_cmdline_item(const char *key, const char *value, void *dat return 0; if (log_set_max_level_from_string(value) < 0) - log_warning("Failed to parse log level '%s', ignoring.", value); + log_warning("Failed to parse log level setting '%s', ignoring.", value); } else if (proc_cmdline_key_streq(key, "systemd.log_color")) { diff --git a/src/basic/log.h b/src/basic/log.h index 23f54b88fb0..fc80902c450 100644 --- a/src/basic/log.h +++ b/src/basic/log.h @@ -18,15 +18,16 @@ struct signalfd_siginfo; typedef enum LogTarget{ LOG_TARGET_CONSOLE, - LOG_TARGET_CONSOLE_PREFIXED, LOG_TARGET_KMSG, LOG_TARGET_JOURNAL, - LOG_TARGET_JOURNAL_OR_KMSG, LOG_TARGET_SYSLOG, + LOG_TARGET_CONSOLE_PREFIXED, + LOG_TARGET_JOURNAL_OR_KMSG, LOG_TARGET_SYSLOG_OR_KMSG, LOG_TARGET_AUTO, /* console if stderr is not journal, JOURNAL_OR_KMSG otherwise */ LOG_TARGET_NULL, - _LOG_TARGET_MAX, + _LOG_TARGET_SINGLE_MAX = LOG_TARGET_SYSLOG + 1, + _LOG_TARGET_MAX = LOG_TARGET_NULL + 1, _LOG_TARGET_INVALID = -EINVAL, } LogTarget; @@ -59,6 +60,7 @@ void log_settle_target(void); void log_set_max_level(int level); int log_set_max_level_from_string(const char *e); int log_get_max_level(void) _pure_; +int log_max_levels_to_string(int level, char **ret); void log_set_facility(int facility); diff --git a/src/core/execute.c b/src/core/execute.c index fb3e9b79cbe..656547f9030 100644 --- a/src/core/execute.c +++ b/src/core/execute.c @@ -362,7 +362,7 @@ int exec_spawn(Unit *unit, PidRef *ret) { char serialization_fd_number[DECIMAL_STR_MAX(int) + 1]; - _cleanup_free_ char *subcgroup_path = NULL, *log_level = NULL, *executor_path = NULL; + _cleanup_free_ char *subcgroup_path = NULL, *max_log_levels = NULL, *executor_path = NULL; _cleanup_(pidref_done) PidRef pidref = PIDREF_NULL; _cleanup_fdset_free_ FDSet *fdset = NULL; _cleanup_fclose_ FILE *f = NULL; @@ -435,9 +435,9 @@ int exec_spawn(Unit *unit, /* If LogLevelMax= is specified, then let's use the specified log level at the beginning of the * executor process. To achieve that the specified log level is passed as an argument, rather than * the one for the manager process. */ - r = log_level_to_string_alloc(context->log_level_max >= 0 ? context->log_level_max : log_get_max_level(), &log_level); + r = log_max_levels_to_string(context->log_level_max >= 0 ? context->log_level_max : log_get_max_level(), &max_log_levels); if (r < 0) - return log_unit_error_errno(unit, r, "Failed to convert log level to string: %m"); + return log_unit_error_errno(unit, r, "Failed to convert max log levels to string: %m"); r = fd_get_path(unit->manager->executor_fd, &executor_path); if (r < 0) @@ -450,7 +450,7 @@ int exec_spawn(Unit *unit, FORMAT_PROC_FD_PATH(unit->manager->executor_fd), STRV_MAKE(executor_path, "--deserialize", serialization_fd_number, - "--log-level", log_level, + "--log-level", max_log_levels, "--log-target", log_target_to_string(manager_get_executor_log_target(unit->manager))), environ, cg_unified() > 0 ? subcgroup_path : NULL, diff --git a/src/core/main.c b/src/core/main.c index 551fb425c43..51f64bdc1de 100644 --- a/src/core/main.c +++ b/src/core/main.c @@ -1508,32 +1508,37 @@ static int become_shutdown(int objective, int retval) { [MANAGER_KEXEC] = "kexec", }; - char log_level[STRLEN("--log-level=") + DECIMAL_STR_MAX(int)], - timeout[STRLEN("--timeout=") + DECIMAL_STR_MAX(usec_t) + STRLEN("us")], + char timeout[STRLEN("--timeout=") + DECIMAL_STR_MAX(usec_t) + STRLEN("us")], exit_code[STRLEN("--exit-code=") + DECIMAL_STR_MAX(uint8_t)]; _cleanup_strv_free_ char **env_block = NULL; + _cleanup_free_ char *max_log_levels = NULL; usec_t watchdog_timer = 0; int r; assert(objective >= 0 && objective < _MANAGER_OBJECTIVE_MAX); assert(table[objective]); - xsprintf(log_level, "--log-level=%d", log_get_max_level()); xsprintf(timeout, "--timeout=%" PRI_USEC "us", arg_defaults.timeout_stop_usec); - const char* command_line[10] = { + const char* command_line[11] = { SYSTEMD_SHUTDOWN_BINARY_PATH, table[objective], - log_level, timeout, /* Note that the last position is a terminator and must contain NULL. */ }; - size_t pos = 4; + size_t pos = 3; assert(command_line[pos-1]); assert(!command_line[pos]); + (void) log_max_levels_to_string(log_get_max_level(), &max_log_levels); + + if (max_log_levels) { + command_line[pos++] = "--log-level"; + command_line[pos++] = max_log_levels; + } + switch (log_get_target()) { case LOG_TARGET_KMSG: