From 2e52b6c661e3d1f80a9d0b8f8b5a38307bbcd344 Mon Sep 17 00:00:00 2001 From: Daan De Meyer Date: Sun, 17 Mar 2024 16:16:52 +0100 Subject: [PATCH 1/2] log: Make warning messages more consistent Use our usual pattern of ", ignoring.". --- src/basic/log.c | 30 +++++++++++++++--------------- 1 file changed, 15 insertions(+), 15 deletions(-) diff --git a/src/basic/log.c b/src/basic/log.c index 172a2c8ada..4fc59e250c 100644 --- a/src/basic/log.c +++ b/src/basic/log.c @@ -988,7 +988,7 @@ void log_assert_failed_return( PROTECT_ERRNO; log_assert(LOG_DEBUG, text, file, line, func, - "Assertion '%s' failed at %s:%u, function %s(). Ignoring."); + "Assertion '%s' failed at %s:%u, function %s(), ignoring."); } int log_oom_internal(int level, const char *file, int line, const char *func) { @@ -1265,7 +1265,7 @@ static int parse_proc_cmdline_item(const char *key, const char *value, void *dat return 0; if (log_set_target_from_string(value) < 0) - log_warning("Failed to parse log target '%s'. Ignoring.", value); + log_warning("Failed to parse log target '%s', ignoring.", value); } else if (proc_cmdline_key_streq(key, "systemd.log_level")) { @@ -1273,32 +1273,32 @@ 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 '%s', ignoring.", value); } else if (proc_cmdline_key_streq(key, "systemd.log_color")) { if (log_show_color_from_string(value ?: "1") < 0) - log_warning("Failed to parse log color setting '%s'. Ignoring.", value); + log_warning("Failed to parse log color setting '%s', ignoring.", value); } else if (proc_cmdline_key_streq(key, "systemd.log_location")) { if (log_show_location_from_string(value ?: "1") < 0) - log_warning("Failed to parse log location setting '%s'. Ignoring.", value); + log_warning("Failed to parse log location setting '%s', ignoring.", value); } else if (proc_cmdline_key_streq(key, "systemd.log_tid")) { if (log_show_tid_from_string(value ?: "1") < 0) - log_warning("Failed to parse log tid setting '%s'. Ignoring.", value); + log_warning("Failed to parse log tid setting '%s', ignoring.", value); } else if (proc_cmdline_key_streq(key, "systemd.log_time")) { if (log_show_time_from_string(value ?: "1") < 0) - log_warning("Failed to parse log time setting '%s'. Ignoring.", value); + log_warning("Failed to parse log time setting '%s', ignoring.", value); } else if (proc_cmdline_key_streq(key, "systemd.log_ratelimit_kmsg")) { if (log_set_ratelimit_kmsg_from_string(value ?: "1") < 0) - log_warning("Failed to parse log ratelimit kmsg boolean '%s'. Ignoring.", value); + log_warning("Failed to parse log ratelimit kmsg boolean '%s', ignoring.", value); } return 0; @@ -1318,31 +1318,31 @@ void log_parse_environment_variables(void) { e = getenv("SYSTEMD_LOG_TARGET"); if (e && log_set_target_from_string(e) < 0) - log_warning("Failed to parse log target '%s'. Ignoring.", e); + log_warning("Failed to parse log target '%s', ignoring.", e); e = getenv("SYSTEMD_LOG_LEVEL"); if (e && log_set_max_level_from_string(e) < 0) - log_warning("Failed to parse log level '%s'. Ignoring.", e); + log_warning("Failed to parse log level '%s', ignoring.", e); e = getenv("SYSTEMD_LOG_COLOR"); if (e && log_show_color_from_string(e) < 0) - log_warning("Failed to parse log color '%s'. Ignoring.", e); + log_warning("Failed to parse log color '%s', ignoring.", e); e = getenv("SYSTEMD_LOG_LOCATION"); if (e && log_show_location_from_string(e) < 0) - log_warning("Failed to parse log location '%s'. Ignoring.", e); + log_warning("Failed to parse log location '%s', ignoring.", e); e = getenv("SYSTEMD_LOG_TIME"); if (e && log_show_time_from_string(e) < 0) - log_warning("Failed to parse log time '%s'. Ignoring.", e); + log_warning("Failed to parse log time '%s', ignoring.", e); e = getenv("SYSTEMD_LOG_TID"); if (e && log_show_tid_from_string(e) < 0) - log_warning("Failed to parse log tid '%s'. Ignoring.", e); + log_warning("Failed to parse log tid '%s', ignoring.", e); e = getenv("SYSTEMD_LOG_RATELIMIT_KMSG"); if (e && log_set_ratelimit_kmsg_from_string(e) < 0) - log_warning("Failed to parse log ratelimit kmsg boolean '%s'. Ignoring.", e); + log_warning("Failed to parse log ratelimit kmsg boolean '%s', ignoring.", e); } void log_parse_environment(void) { From e8815abff6444d1eed0335331447693679990b6c Mon Sep 17 00:00:00 2001 From: Daan De Meyer Date: Wed, 20 Mar 2024 09:34:46 +0100 Subject: [PATCH 2/2] 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 0113d1b6bb..58a285c833 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 4fc59e250c..6faa6ad4fc 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 23f54b88fb..fc80902c45 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 fb3e9b79cb..656547f903 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 551fb425c4..51f64bdc1d 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: