diff options
Diffstat (limited to 'src/basic/log.c')
-rw-r--r-- | src/basic/log.c | 1524 |
1 files changed, 1524 insertions, 0 deletions
diff --git a/src/basic/log.c b/src/basic/log.c new file mode 100644 index 0000000..3162eab --- /dev/null +++ b/src/basic/log.c @@ -0,0 +1,1524 @@ +/* SPDX-License-Identifier: LGPL-2.1-or-later */ + +#include <errno.h> +#include <fcntl.h> +#include <inttypes.h> +#include <limits.h> +#include <stdarg.h> +#include <stddef.h> +#include <sys/signalfd.h> +#include <sys/stat.h> +#include <sys/time.h> +#include <sys/uio.h> +#include <sys/un.h> +#include <unistd.h> + +#include "sd-messages.h" + +#include "alloc-util.h" +#include "errno-util.h" +#include "fd-util.h" +#include "format-util.h" +#include "io-util.h" +#include "log.h" +#include "macro.h" +#include "missing_syscall.h" +#include "missing_threads.h" +#include "parse-util.h" +#include "proc-cmdline.h" +#include "process-util.h" +#include "ratelimit.h" +#include "signal-util.h" +#include "socket-util.h" +#include "stdio-util.h" +#include "string-table.h" +#include "string-util.h" +#include "syslog-util.h" +#include "terminal-util.h" +#include "time-util.h" +#include "utf8.h" + +#define SNDBUF_SIZE (8*1024*1024) + +static log_syntax_callback_t log_syntax_callback = NULL; +static void *log_syntax_callback_userdata = NULL; + +static LogTarget log_target = LOG_TARGET_CONSOLE; +static int log_max_level = LOG_INFO; +static int log_facility = LOG_DAEMON; + +static int console_fd = STDERR_FILENO; +static int console_fd_is_tty = -1; /* tri-state: -1 means don't know */ +static int syslog_fd = -1; +static int kmsg_fd = -1; +static int journal_fd = -1; + +static bool syslog_is_stream = false; + +static int show_color = -1; /* tristate */ +static bool show_location = false; +static bool show_time = false; +static bool show_tid = false; + +static bool upgrade_syslog_to_journal = false; +static bool always_reopen_console = false; +static bool open_when_needed = false; +static bool prohibit_ipc = false; + +/* Akin to glibc's __abort_msg; which is private and we hence cannot + * use here. */ +static char *log_abort_msg = NULL; + +#if LOG_MESSAGE_VERIFICATION || defined(__COVERITY__) +bool _log_message_dummy = false; /* Always false */ +#endif + +/* An assert to use in logging functions that does not call recursively + * into our logging functions (since that might lead to a loop). */ +#define assert_raw(expr) \ + do { \ + if (_unlikely_(!(expr))) { \ + fputs(#expr "\n", stderr); \ + abort(); \ + } \ + } while (false) + +static void log_close_console(void) { + /* See comment in log_close_journal() */ + (void) safe_close_above_stdio(TAKE_FD(console_fd)); + console_fd_is_tty = -1; +} + +static int log_open_console(void) { + + if (!always_reopen_console) { + console_fd = STDERR_FILENO; + console_fd_is_tty = -1; + return 0; + } + + if (console_fd < 3) { + int fd; + + fd = open_terminal("/dev/console", O_WRONLY|O_NOCTTY|O_CLOEXEC); + if (fd < 0) + return fd; + + console_fd = fd_move_above_stdio(fd); + console_fd_is_tty = true; + } + + return 0; +} + +static void log_close_kmsg(void) { + /* See comment in log_close_journal() */ + (void) safe_close(TAKE_FD(kmsg_fd)); +} + +static int log_open_kmsg(void) { + + if (kmsg_fd >= 0) + return 0; + + kmsg_fd = open("/dev/kmsg", O_WRONLY|O_NOCTTY|O_CLOEXEC); + if (kmsg_fd < 0) + return -errno; + + kmsg_fd = fd_move_above_stdio(kmsg_fd); + return 0; +} + +static void log_close_syslog(void) { + /* See comment in log_close_journal() */ + (void) safe_close(TAKE_FD(syslog_fd)); +} + +static int create_log_socket(int type) { + struct timeval tv; + int fd; + + fd = socket(AF_UNIX, type|SOCK_CLOEXEC, 0); + if (fd < 0) + return -errno; + + fd = fd_move_above_stdio(fd); + (void) fd_inc_sndbuf(fd, SNDBUF_SIZE); + + /* We need a blocking fd here since we'd otherwise lose messages way too early. However, let's not hang forever + * in the unlikely case of a deadlock. */ + if (getpid_cached() == 1) + timeval_store(&tv, 10 * USEC_PER_MSEC); + else + timeval_store(&tv, 10 * USEC_PER_SEC); + (void) setsockopt(fd, SOL_SOCKET, SO_SNDTIMEO, &tv, sizeof(tv)); + + return fd; +} + +static int log_open_syslog(void) { + int r; + + if (syslog_fd >= 0) + return 0; + + syslog_fd = create_log_socket(SOCK_DGRAM); + if (syslog_fd < 0) { + r = syslog_fd; + goto fail; + } + + r = connect_unix_path(syslog_fd, AT_FDCWD, "/dev/log"); + if (r < 0) { + safe_close(syslog_fd); + + /* Some legacy syslog systems still use stream sockets. They really shouldn't. But what can + * we do... */ + syslog_fd = create_log_socket(SOCK_STREAM); + if (syslog_fd < 0) { + r = syslog_fd; + goto fail; + } + + r = connect_unix_path(syslog_fd, AT_FDCWD, "/dev/log"); + if (r < 0) + goto fail; + + syslog_is_stream = true; + } else + syslog_is_stream = false; + + return 0; + +fail: + log_close_syslog(); + return r; +} + +static void log_close_journal(void) { + /* If the journal FD is bad, safe_close will fail, and will try to log, which will fail, so we'll + * try to close the journal FD, which is bad, so safe_close will fail... Whether we can close it + * or not, invalidate it immediately so that we don't get in a recursive loop until we run out of + * stack. */ + (void) safe_close(TAKE_FD(journal_fd)); +} + +static int log_open_journal(void) { + int r; + + if (journal_fd >= 0) + return 0; + + journal_fd = create_log_socket(SOCK_DGRAM); + if (journal_fd < 0) { + r = journal_fd; + goto fail; + } + + r = connect_unix_path(journal_fd, AT_FDCWD, "/run/systemd/journal/socket"); + if (r < 0) + goto fail; + + return 0; + +fail: + log_close_journal(); + return r; +} + +static bool stderr_is_journal(void) { + _cleanup_free_ char *w = NULL; + const char *e; + uint64_t dev, ino; + struct stat st; + + e = getenv("JOURNAL_STREAM"); + if (!e) + return false; + + if (extract_first_word(&e, &w, ":", EXTRACT_DONT_COALESCE_SEPARATORS) <= 0) + return false; + if (!e) + return false; + + if (safe_atou64(w, &dev) < 0) + return false; + if (safe_atou64(e, &ino) < 0) + return false; + + if (fstat(STDERR_FILENO, &st) < 0) + return false; + + return st.st_dev == dev && st.st_ino == ino; +} + +int log_open(void) { + int r; + + /* Do not call from library code. */ + + /* This function is often called in preparation for logging. Let's make sure we don't clobber errno, + * so that a call to a logging function immediately following a log_open() call can still easily + * reference an error that happened immediately before the log_open() call. */ + PROTECT_ERRNO; + + /* If we don't use the console, we close it here to not get killed by SAK. If we don't use syslog, we + * close it here too, so that we are not confused by somebody deleting the socket in the fs, and to + * make sure we don't use it if prohibit_ipc is set. If we don't use /dev/kmsg we still keep it open, + * because there is no reason to close it. */ + + if (log_target == LOG_TARGET_NULL) { + log_close_journal(); + log_close_syslog(); + log_close_console(); + return 0; + } + + if (getpid_cached() == 1 || + stderr_is_journal() || + IN_SET(log_target, + LOG_TARGET_KMSG, + LOG_TARGET_JOURNAL, + LOG_TARGET_JOURNAL_OR_KMSG, + LOG_TARGET_SYSLOG, + LOG_TARGET_SYSLOG_OR_KMSG)) { + + if (!prohibit_ipc) { + if (IN_SET(log_target, + LOG_TARGET_AUTO, + LOG_TARGET_JOURNAL_OR_KMSG, + LOG_TARGET_JOURNAL)) { + + r = log_open_journal(); + if (r >= 0) { + log_close_syslog(); + log_close_console(); + return r; + } + } + + if (IN_SET(log_target, + LOG_TARGET_SYSLOG_OR_KMSG, + LOG_TARGET_SYSLOG)) { + + r = log_open_syslog(); + if (r >= 0) { + log_close_journal(); + log_close_console(); + return r; + } + } + } + + if (IN_SET(log_target, LOG_TARGET_AUTO, + LOG_TARGET_JOURNAL_OR_KMSG, + LOG_TARGET_SYSLOG_OR_KMSG, + LOG_TARGET_KMSG)) { + r = log_open_kmsg(); + if (r >= 0) { + log_close_journal(); + log_close_syslog(); + log_close_console(); + return r; + } + } + } + + log_close_journal(); + log_close_syslog(); + + return log_open_console(); +} + +void log_set_target(LogTarget target) { + assert(target >= 0); + assert(target < _LOG_TARGET_MAX); + + if (upgrade_syslog_to_journal) { + if (target == LOG_TARGET_SYSLOG) + target = LOG_TARGET_JOURNAL; + else if (target == LOG_TARGET_SYSLOG_OR_KMSG) + target = LOG_TARGET_JOURNAL_OR_KMSG; + } + + log_target = target; +} + +void log_close(void) { + /* Do not call from library code. */ + + log_close_journal(); + log_close_syslog(); + log_close_kmsg(); + log_close_console(); +} + +void log_forget_fds(void) { + /* Do not call from library code. */ + + console_fd = kmsg_fd = syslog_fd = journal_fd = -1; + console_fd_is_tty = -1; +} + +void log_set_max_level(int level) { + assert(level == LOG_NULL || (level & LOG_PRIMASK) == level); + + log_max_level = level; +} + +void log_set_facility(int facility) { + log_facility = facility; +} + +static bool check_console_fd_is_tty(void) { + if (console_fd < 0) + return false; + + if (console_fd_is_tty < 0) + console_fd_is_tty = isatty(console_fd) > 0; + + return console_fd_is_tty; +} + +static int write_to_console( + int level, + int error, + const char *file, + int line, + const char *func, + const char *buffer) { + + char location[256], + header_time[FORMAT_TIMESTAMP_MAX], + prefix[1 + DECIMAL_STR_MAX(int) + 2], + tid_string[3 + DECIMAL_STR_MAX(pid_t) + 1]; + struct iovec iovec[9]; + const char *on = NULL, *off = NULL; + size_t n = 0; + + if (console_fd < 0) + return 0; + + if (log_target == LOG_TARGET_CONSOLE_PREFIXED) { + xsprintf(prefix, "<%i>", level); + iovec[n++] = IOVEC_MAKE_STRING(prefix); + } + + if (show_time && + format_timestamp(header_time, sizeof(header_time), now(CLOCK_REALTIME))) { + iovec[n++] = IOVEC_MAKE_STRING(header_time); + iovec[n++] = IOVEC_MAKE_STRING(" "); + } + + if (show_tid) { + xsprintf(tid_string, "(" PID_FMT ") ", gettid()); + iovec[n++] = IOVEC_MAKE_STRING(tid_string); + } + + if (log_get_show_color()) + get_log_colors(LOG_PRI(level), &on, &off, NULL); + + if (show_location) { + const char *lon = "", *loff = ""; + if (log_get_show_color()) { + lon = ansi_highlight_yellow4(); + loff = ansi_normal(); + } + + (void) snprintf(location, sizeof location, "%s%s:%i%s: ", lon, file, line, loff); + iovec[n++] = IOVEC_MAKE_STRING(location); + } + + if (on) + iovec[n++] = IOVEC_MAKE_STRING(on); + iovec[n++] = IOVEC_MAKE_STRING(buffer); + if (off) + iovec[n++] = IOVEC_MAKE_STRING(off); + + /* When writing to a TTY we output an extra '\r' (i.e. CR) first, to generate CRNL rather than just + * NL. This is a robustness thing in case the TTY is currently in raw mode (specifically: has the + * ONLCR flag off). We want that subsequent output definitely starts at the beginning of the line + * again, after all. If the TTY is not in raw mode the extra CR should not hurt. */ + iovec[n++] = IOVEC_MAKE_STRING((check_console_fd_is_tty() ? "\r\n" : "\n")); + + if (writev(console_fd, iovec, n) < 0) { + + if (errno == EIO && getpid_cached() == 1) { + + /* If somebody tried to kick us from our console tty (via vhangup() or suchlike), try + * to reconnect. */ + + log_close_console(); + (void) log_open_console(); + if (console_fd < 0) + return 0; + + if (writev(console_fd, iovec, n) < 0) + return -errno; + } else + return -errno; + } + + return 1; +} + +static int write_to_syslog( + int level, + int error, + const char *file, + int line, + const char *func, + const char *buffer) { + + char header_priority[2 + DECIMAL_STR_MAX(int) + 1], + header_time[64], + header_pid[4 + DECIMAL_STR_MAX(pid_t) + 1]; + time_t t; + struct tm tm; + + if (syslog_fd < 0) + return 0; + + xsprintf(header_priority, "<%i>", level); + + t = (time_t) (now(CLOCK_REALTIME) / USEC_PER_SEC); + if (!localtime_r(&t, &tm)) + return -EINVAL; + + if (strftime(header_time, sizeof(header_time), "%h %e %T ", &tm) <= 0) + return -EINVAL; + + xsprintf(header_pid, "["PID_FMT"]: ", getpid_cached()); + + struct iovec iovec[] = { + IOVEC_MAKE_STRING(header_priority), + IOVEC_MAKE_STRING(header_time), + IOVEC_MAKE_STRING(program_invocation_short_name), + IOVEC_MAKE_STRING(header_pid), + IOVEC_MAKE_STRING(buffer), + }; + const struct msghdr msghdr = { + .msg_iov = iovec, + .msg_iovlen = ELEMENTSOF(iovec), + }; + + /* When using syslog via SOCK_STREAM separate the messages by NUL chars */ + if (syslog_is_stream) + iovec[ELEMENTSOF(iovec) - 1].iov_len++; + + for (;;) { + ssize_t n; + + n = sendmsg(syslog_fd, &msghdr, MSG_NOSIGNAL); + if (n < 0) + return -errno; + + if (!syslog_is_stream) + break; + + if (IOVEC_INCREMENT(iovec, ELEMENTSOF(iovec), n)) + break; + } + + return 1; +} + +static int write_to_kmsg( + int level, + int error, + const char *file, + int line, + const char *func, + const char *buffer) { + + /* Set a ratelimit on the amount of messages logged to /dev/kmsg. This is mostly supposed to be a + * safety catch for the case where start indiscriminately logging in a loop. It will not catch cases + * where we log excessively, but not in a tight loop. + * + * Note that this ratelimit is per-emitter, so we might still overwhelm /dev/kmsg with multiple + * loggers. + */ + static thread_local RateLimit ratelimit = { 5 * USEC_PER_SEC, 200 }; + + char header_priority[2 + DECIMAL_STR_MAX(int) + 1], + header_pid[4 + DECIMAL_STR_MAX(pid_t) + 1]; + + if (kmsg_fd < 0) + return 0; + + if (!ratelimit_below(&ratelimit)) + return 0; + + xsprintf(header_priority, "<%i>", level); + xsprintf(header_pid, "["PID_FMT"]: ", getpid_cached()); + + const struct iovec iovec[] = { + IOVEC_MAKE_STRING(header_priority), + IOVEC_MAKE_STRING(program_invocation_short_name), + IOVEC_MAKE_STRING(header_pid), + IOVEC_MAKE_STRING(buffer), + IOVEC_MAKE_STRING("\n"), + }; + + if (writev(kmsg_fd, iovec, ELEMENTSOF(iovec)) < 0) + return -errno; + + return 1; +} + +static int log_do_header( + char *header, + size_t size, + int level, + int error, + const char *file, int line, const char *func, + const char *object_field, const char *object, + const char *extra_field, const char *extra) { + int r; + + error = IS_SYNTHETIC_ERRNO(error) ? 0 : ERRNO_VALUE(error); + + r = snprintf(header, size, + "PRIORITY=%i\n" + "SYSLOG_FACILITY=%i\n" + "TID=" PID_FMT "\n" + "%s%.256s%s" /* CODE_FILE */ + "%s%.*i%s" /* CODE_LINE */ + "%s%.256s%s" /* CODE_FUNC */ + "%s%.*i%s" /* ERRNO */ + "%s%.256s%s" /* object */ + "%s%.256s%s" /* extra */ + "SYSLOG_IDENTIFIER=%.256s\n", + LOG_PRI(level), + LOG_FAC(level), + gettid(), + isempty(file) ? "" : "CODE_FILE=", + isempty(file) ? "" : file, + isempty(file) ? "" : "\n", + line ? "CODE_LINE=" : "", + line ? 1 : 0, line, /* %.0d means no output too, special case for 0 */ + line ? "\n" : "", + isempty(func) ? "" : "CODE_FUNC=", + isempty(func) ? "" : func, + isempty(func) ? "" : "\n", + error ? "ERRNO=" : "", + error ? 1 : 0, error, + error ? "\n" : "", + isempty(object) ? "" : object_field, + isempty(object) ? "" : object, + isempty(object) ? "" : "\n", + isempty(extra) ? "" : extra_field, + isempty(extra) ? "" : extra, + isempty(extra) ? "" : "\n", + program_invocation_short_name); + assert_raw((size_t) r < size); + + return 0; +} + +static int write_to_journal( + int level, + int error, + const char *file, + int line, + const char *func, + const char *object_field, + const char *object, + const char *extra_field, + const char *extra, + const char *buffer) { + + char header[LINE_MAX]; + + if (journal_fd < 0) + return 0; + + log_do_header(header, sizeof(header), level, error, file, line, func, object_field, object, extra_field, extra); + + struct iovec iovec[4] = { + IOVEC_MAKE_STRING(header), + IOVEC_MAKE_STRING("MESSAGE="), + IOVEC_MAKE_STRING(buffer), + IOVEC_MAKE_STRING("\n"), + }; + const struct msghdr msghdr = { + .msg_iov = iovec, + .msg_iovlen = ELEMENTSOF(iovec), + }; + + if (sendmsg(journal_fd, &msghdr, MSG_NOSIGNAL) < 0) + return -errno; + + return 1; +} + +int log_dispatch_internal( + int level, + int error, + const char *file, + int line, + const char *func, + const char *object_field, + const char *object, + const char *extra_field, + const char *extra, + char *buffer) { + + assert_raw(buffer); + + if (log_target == LOG_TARGET_NULL) + return -ERRNO_VALUE(error); + + /* Patch in LOG_DAEMON facility if necessary */ + if ((level & LOG_FACMASK) == 0) + level |= log_facility; + + if (open_when_needed) + (void) log_open(); + + do { + char *e; + int k = 0; + + buffer += strspn(buffer, NEWLINE); + + if (buffer[0] == 0) + break; + + if ((e = strpbrk(buffer, NEWLINE))) + *(e++) = 0; + + if (IN_SET(log_target, LOG_TARGET_AUTO, + LOG_TARGET_JOURNAL_OR_KMSG, + LOG_TARGET_JOURNAL)) { + + k = write_to_journal(level, error, file, line, func, object_field, object, extra_field, extra, buffer); + if (k < 0 && k != -EAGAIN) + log_close_journal(); + } + + if (IN_SET(log_target, LOG_TARGET_SYSLOG_OR_KMSG, + LOG_TARGET_SYSLOG)) { + + k = write_to_syslog(level, error, file, line, func, buffer); + if (k < 0 && k != -EAGAIN) + log_close_syslog(); + } + + if (k <= 0 && + IN_SET(log_target, LOG_TARGET_AUTO, + LOG_TARGET_SYSLOG_OR_KMSG, + LOG_TARGET_JOURNAL_OR_KMSG, + LOG_TARGET_KMSG)) { + + if (k < 0) + log_open_kmsg(); + + k = write_to_kmsg(level, error, file, line, func, buffer); + if (k < 0) { + log_close_kmsg(); + (void) log_open_console(); + } + } + + if (k <= 0) + (void) write_to_console(level, error, file, line, func, buffer); + + buffer = e; + } while (buffer); + + if (open_when_needed) + log_close(); + + return -ERRNO_VALUE(error); +} + +int log_dump_internal( + int level, + int error, + const char *file, + int line, + const char *func, + char *buffer) { + + PROTECT_ERRNO; + + /* This modifies the buffer... */ + + if (_likely_(LOG_PRI(level) > log_max_level)) + return -ERRNO_VALUE(error); + + return log_dispatch_internal(level, error, file, line, func, NULL, NULL, NULL, NULL, buffer); +} + +int log_internalv( + int level, + int error, + const char *file, + int line, + const char *func, + const char *format, + va_list ap) { + + if (_likely_(LOG_PRI(level) > log_max_level)) + return -ERRNO_VALUE(error); + + /* Make sure that %m maps to the specified error (or "Success"). */ + char buffer[LINE_MAX]; + LOCAL_ERRNO(ERRNO_VALUE(error)); + + (void) vsnprintf(buffer, sizeof buffer, format, ap); + + return log_dispatch_internal(level, error, file, line, func, NULL, NULL, NULL, NULL, buffer); +} + +int log_internal( + int level, + int error, + const char *file, + int line, + const char *func, + const char *format, ...) { + + va_list ap; + int r; + + va_start(ap, format); + r = log_internalv(level, error, file, line, func, format, ap); + va_end(ap); + + return r; +} + +int log_object_internalv( + int level, + int error, + const char *file, + int line, + const char *func, + const char *object_field, + const char *object, + const char *extra_field, + const char *extra, + const char *format, + va_list ap) { + + char *buffer, *b; + + if (_likely_(LOG_PRI(level) > log_max_level)) + return -ERRNO_VALUE(error); + + /* Make sure that %m maps to the specified error (or "Success"). */ + LOCAL_ERRNO(ERRNO_VALUE(error)); + + /* Prepend the object name before the message */ + if (object) { + size_t n; + + n = strlen(object); + buffer = newa(char, n + 2 + LINE_MAX); + b = stpcpy(stpcpy(buffer, object), ": "); + } else + b = buffer = newa(char, LINE_MAX); + + (void) vsnprintf(b, LINE_MAX, format, ap); + + return log_dispatch_internal(level, error, file, line, func, + object_field, object, extra_field, extra, buffer); +} + +int log_object_internal( + int level, + int error, + const char *file, + int line, + const char *func, + const char *object_field, + const char *object, + const char *extra_field, + const char *extra, + const char *format, ...) { + + va_list ap; + int r; + + va_start(ap, format); + r = log_object_internalv(level, error, file, line, func, object_field, object, extra_field, extra, format, ap); + va_end(ap); + + return r; +} + +static void log_assert( + int level, + const char *text, + const char *file, + int line, + const char *func, + const char *format) { + + static char buffer[LINE_MAX]; + + if (_likely_(LOG_PRI(level) > log_max_level)) + return; + + DISABLE_WARNING_FORMAT_NONLITERAL; + (void) snprintf(buffer, sizeof buffer, format, text, file, line, func); + REENABLE_WARNING; + + log_abort_msg = buffer; + + log_dispatch_internal(level, 0, file, line, func, NULL, NULL, NULL, NULL, buffer); +} + +_noreturn_ void log_assert_failed( + const char *text, + const char *file, + int line, + const char *func) { + log_assert(LOG_CRIT, text, file, line, func, + "Assertion '%s' failed at %s:%u, function %s(). Aborting."); + abort(); +} + +_noreturn_ void log_assert_failed_unreachable( + const char *file, + int line, + const char *func) { + log_assert(LOG_CRIT, "Code should not be reached", file, line, func, + "%s at %s:%u, function %s(). Aborting. 💥"); + abort(); +} + +void log_assert_failed_return( + const char *text, + const char *file, + int line, + const char *func) { + PROTECT_ERRNO; + log_assert(LOG_DEBUG, text, file, line, func, + "Assertion '%s' failed at %s:%u, function %s(). Ignoring."); +} + +int log_oom_internal(int level, const char *file, int line, const char *func) { + return log_internal(level, ENOMEM, file, line, func, "Out of memory."); +} + +int log_format_iovec( + struct iovec *iovec, + size_t iovec_len, + size_t *n, + bool newline_separator, + int error, + const char *format, + va_list ap) { + + static const char nl = '\n'; + + while (format && *n + 1 < iovec_len) { + va_list aq; + char *m; + int r; + + /* We need to copy the va_list structure, + * since vasprintf() leaves it afterwards at + * an undefined location */ + + errno = ERRNO_VALUE(error); + + va_copy(aq, ap); + r = vasprintf(&m, format, aq); + va_end(aq); + if (r < 0) + return -EINVAL; + + /* Now, jump enough ahead, so that we point to + * the next format string */ + VA_FORMAT_ADVANCE(format, ap); + + iovec[(*n)++] = IOVEC_MAKE_STRING(m); + if (newline_separator) + iovec[(*n)++] = IOVEC_MAKE((char *)&nl, 1); + + format = va_arg(ap, char *); + } + return 0; +} + +int log_struct_internal( + int level, + int error, + const char *file, + int line, + const char *func, + const char *format, ...) { + + char buf[LINE_MAX]; + bool found = false; + PROTECT_ERRNO; + va_list ap; + + if (_likely_(LOG_PRI(level) > log_max_level) || + log_target == LOG_TARGET_NULL) + return -ERRNO_VALUE(error); + + if ((level & LOG_FACMASK) == 0) + level |= log_facility; + + if (IN_SET(log_target, + LOG_TARGET_AUTO, + LOG_TARGET_JOURNAL_OR_KMSG, + LOG_TARGET_JOURNAL)) { + + if (open_when_needed) + log_open_journal(); + + if (journal_fd >= 0) { + char header[LINE_MAX]; + struct iovec iovec[17]; + size_t n = 0; + int r; + bool fallback = false; + + /* If the journal is available do structured logging. + * Do not report the errno if it is synthetic. */ + log_do_header(header, sizeof(header), level, error, file, line, func, NULL, NULL, NULL, NULL); + iovec[n++] = IOVEC_MAKE_STRING(header); + + va_start(ap, format); + r = log_format_iovec(iovec, ELEMENTSOF(iovec), &n, true, error, format, ap); + if (r < 0) + fallback = true; + else { + const struct msghdr msghdr = { + .msg_iov = iovec, + .msg_iovlen = n, + }; + + (void) sendmsg(journal_fd, &msghdr, MSG_NOSIGNAL); + } + + va_end(ap); + for (size_t i = 1; i < n; i += 2) + free(iovec[i].iov_base); + + if (!fallback) { + if (open_when_needed) + log_close(); + + return -ERRNO_VALUE(error); + } + } + } + + /* Fallback if journal logging is not available or didn't work. */ + + va_start(ap, format); + while (format) { + va_list aq; + + errno = ERRNO_VALUE(error); + + va_copy(aq, ap); + (void) vsnprintf(buf, sizeof buf, format, aq); + va_end(aq); + + if (startswith(buf, "MESSAGE=")) { + found = true; + break; + } + + VA_FORMAT_ADVANCE(format, ap); + + format = va_arg(ap, char *); + } + va_end(ap); + + if (!found) { + if (open_when_needed) + log_close(); + + return -ERRNO_VALUE(error); + } + + return log_dispatch_internal(level, error, file, line, func, NULL, NULL, NULL, NULL, buf + 8); +} + +int log_struct_iovec_internal( + int level, + int error, + const char *file, + int line, + const char *func, + const struct iovec input_iovec[], + size_t n_input_iovec) { + + PROTECT_ERRNO; + + if (_likely_(LOG_PRI(level) > log_max_level) || + log_target == LOG_TARGET_NULL) + return -ERRNO_VALUE(error); + + if ((level & LOG_FACMASK) == 0) + level |= log_facility; + + if (IN_SET(log_target, LOG_TARGET_AUTO, + LOG_TARGET_JOURNAL_OR_KMSG, + LOG_TARGET_JOURNAL) && + journal_fd >= 0) { + + char header[LINE_MAX]; + log_do_header(header, sizeof(header), level, error, file, line, func, NULL, NULL, NULL, NULL); + + struct iovec iovec[1 + n_input_iovec*2]; + iovec[0] = IOVEC_MAKE_STRING(header); + for (size_t i = 0; i < n_input_iovec; i++) { + iovec[1+i*2] = input_iovec[i]; + iovec[1+i*2+1] = IOVEC_MAKE_STRING("\n"); + } + + const struct msghdr msghdr = { + .msg_iov = iovec, + .msg_iovlen = 1 + n_input_iovec*2, + }; + + if (sendmsg(journal_fd, &msghdr, MSG_NOSIGNAL) >= 0) + return -ERRNO_VALUE(error); + } + + for (size_t i = 0; i < n_input_iovec; i++) + if (memory_startswith(input_iovec[i].iov_base, input_iovec[i].iov_len, "MESSAGE=")) { + char *m; + + m = strndupa_safe((char*) input_iovec[i].iov_base + STRLEN("MESSAGE="), + input_iovec[i].iov_len - STRLEN("MESSAGE=")); + + return log_dispatch_internal(level, error, file, line, func, NULL, NULL, NULL, NULL, m); + } + + /* Couldn't find MESSAGE=. */ + return -ERRNO_VALUE(error); +} + +int log_set_target_from_string(const char *e) { + LogTarget t; + + t = log_target_from_string(e); + if (t < 0) + return t; + + log_set_target(t); + return 0; +} + +int log_set_max_level_from_string(const char *e) { + int t; + + t = log_level_from_string(e); + if (t < 0) + return t; + + log_set_max_level(t); + return 0; +} + +static int parse_proc_cmdline_item(const char *key, const char *value, void *data) { + + /* + * The systemd.log_xyz= settings are parsed by all tools, and + * so is "debug". + * + * However, "quiet" is only parsed by PID 1, and only turns of + * status output to /dev/console, but does not alter the log + * level. + */ + + if (streq(key, "debug") && !value) + log_set_max_level(LOG_DEBUG); + + else if (proc_cmdline_key_streq(key, "systemd.log_target")) { + + if (proc_cmdline_value_missing(key, value)) + return 0; + + if (log_set_target_from_string(value) < 0) + log_warning("Failed to parse log target '%s'. Ignoring.", value); + + } else if (proc_cmdline_key_streq(key, "systemd.log_level")) { + + if (proc_cmdline_value_missing(key, value)) + return 0; + + if (log_set_max_level_from_string(value) < 0) + 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); + + } 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); + + } 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); + + } 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); + + } + + return 0; +} + +static bool should_parse_proc_cmdline(void) { + /* PID1 always reads the kernel command line. */ + if (getpid_cached() == 1) + return true; + + /* Otherwise, parse the commandline if invoked directly by systemd. */ + return invoked_by_systemd(); +} + +void log_parse_environment_variables(void) { + const char *e; + + e = getenv("SYSTEMD_LOG_TARGET"); + if (e && log_set_target_from_string(e) < 0) + 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); + + e = getenv("SYSTEMD_LOG_COLOR"); + if (e && log_show_color_from_string(e) < 0) + 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); + + e = getenv("SYSTEMD_LOG_TIME"); + if (e && log_show_time_from_string(e) < 0) + 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); +} + +void log_parse_environment(void) { + /* Do not call from library code. */ + + if (should_parse_proc_cmdline()) + (void) proc_cmdline_parse(parse_proc_cmdline_item, NULL, PROC_CMDLINE_STRIP_RD_PREFIX); + + log_parse_environment_variables(); +} + +LogTarget log_get_target(void) { + return log_target; +} + +void log_settle_target(void) { + + /* If we're using LOG_TARGET_AUTO and opening the log again on every single log call, we'll check if + * stderr is attached to the journal every single log call. However, if we then close all file + * descriptors later, that will stop working because stderr will be closed as well. To avoid that + * problem, this function is used to permanently change the log target depending on whether stderr is + * connected to the journal or not. */ + + LogTarget t = log_get_target(); + + if (t != LOG_TARGET_AUTO) + return; + + t = getpid_cached() == 1 || stderr_is_journal() ? (prohibit_ipc ? LOG_TARGET_KMSG : LOG_TARGET_JOURNAL_OR_KMSG) + : LOG_TARGET_CONSOLE; + log_set_target(t); +} + +int log_get_max_level(void) { + return log_max_level; +} + +void log_show_color(bool b) { + show_color = b; +} + +bool log_get_show_color(void) { + return show_color > 0; /* Defaults to false. */ +} + +void log_show_location(bool b) { + show_location = b; +} + +bool log_get_show_location(void) { + return show_location; +} + +void log_show_time(bool b) { + show_time = b; +} + +bool log_get_show_time(void) { + return show_time; +} + +void log_show_tid(bool b) { + show_tid = b; +} + +bool log_get_show_tid(void) { + return show_tid; +} + +int log_show_color_from_string(const char *e) { + int t; + + t = parse_boolean(e); + if (t < 0) + return t; + + log_show_color(t); + return 0; +} + +int log_show_location_from_string(const char *e) { + int t; + + t = parse_boolean(e); + if (t < 0) + return t; + + log_show_location(t); + return 0; +} + +int log_show_time_from_string(const char *e) { + int t; + + t = parse_boolean(e); + if (t < 0) + return t; + + log_show_time(t); + return 0; +} + +int log_show_tid_from_string(const char *e) { + int t; + + t = parse_boolean(e); + if (t < 0) + return t; + + log_show_tid(t); + return 0; +} + +bool log_on_console(void) { + if (IN_SET(log_target, LOG_TARGET_CONSOLE, + LOG_TARGET_CONSOLE_PREFIXED)) + return true; + + return syslog_fd < 0 && kmsg_fd < 0 && journal_fd < 0; +} + +static const char *const log_target_table[_LOG_TARGET_MAX] = { + [LOG_TARGET_CONSOLE] = "console", + [LOG_TARGET_CONSOLE_PREFIXED] = "console-prefixed", + [LOG_TARGET_KMSG] = "kmsg", + [LOG_TARGET_JOURNAL] = "journal", + [LOG_TARGET_JOURNAL_OR_KMSG] = "journal-or-kmsg", + [LOG_TARGET_SYSLOG] = "syslog", + [LOG_TARGET_SYSLOG_OR_KMSG] = "syslog-or-kmsg", + [LOG_TARGET_AUTO] = "auto", + [LOG_TARGET_NULL] = "null", +}; + +DEFINE_STRING_TABLE_LOOKUP(log_target, LogTarget); + +void log_received_signal(int level, const struct signalfd_siginfo *si) { + assert(si); + + if (pid_is_valid(si->ssi_pid)) { + _cleanup_free_ char *p = NULL; + + (void) get_process_comm(si->ssi_pid, &p); + + log_full(level, + "Received SIG%s from PID %"PRIu32" (%s).", + signal_to_string(si->ssi_signo), + si->ssi_pid, strna(p)); + } else + log_full(level, + "Received SIG%s.", + signal_to_string(si->ssi_signo)); +} + +void set_log_syntax_callback(log_syntax_callback_t cb, void *userdata) { + assert(!log_syntax_callback || !cb); + assert(!log_syntax_callback_userdata || !userdata); + + log_syntax_callback = cb; + log_syntax_callback_userdata = userdata; +} + +int log_syntax_internal( + const char *unit, + int level, + const char *config_file, + unsigned config_line, + int error, + const char *file, + int line, + const char *func, + const char *format, ...) { + + PROTECT_ERRNO; + + if (log_syntax_callback) + log_syntax_callback(unit, level, log_syntax_callback_userdata); + + if (_likely_(LOG_PRI(level) > log_max_level) || + log_target == LOG_TARGET_NULL) + return -ERRNO_VALUE(error); + + char buffer[LINE_MAX]; + va_list ap; + const char *unit_fmt = NULL; + + errno = ERRNO_VALUE(error); + + va_start(ap, format); + (void) vsnprintf(buffer, sizeof buffer, format, ap); + va_end(ap); + + if (unit) + unit_fmt = getpid_cached() == 1 ? "UNIT=%s" : "USER_UNIT=%s"; + + if (config_file) { + if (config_line > 0) + return log_struct_internal( + level, + error, + file, line, func, + "MESSAGE_ID=" SD_MESSAGE_INVALID_CONFIGURATION_STR, + "CONFIG_FILE=%s", config_file, + "CONFIG_LINE=%u", config_line, + LOG_MESSAGE("%s:%u: %s", config_file, config_line, buffer), + unit_fmt, unit, + NULL); + else + return log_struct_internal( + level, + error, + file, line, func, + "MESSAGE_ID=" SD_MESSAGE_INVALID_CONFIGURATION_STR, + "CONFIG_FILE=%s", config_file, + LOG_MESSAGE("%s: %s", config_file, buffer), + unit_fmt, unit, + NULL); + } else if (unit) + return log_struct_internal( + level, + error, + file, line, func, + "MESSAGE_ID=" SD_MESSAGE_INVALID_CONFIGURATION_STR, + LOG_MESSAGE("%s: %s", unit, buffer), + unit_fmt, unit, + NULL); + else + return log_struct_internal( + level, + error, + file, line, func, + "MESSAGE_ID=" SD_MESSAGE_INVALID_CONFIGURATION_STR, + LOG_MESSAGE("%s", buffer), + NULL); +} + +int log_syntax_invalid_utf8_internal( + const char *unit, + int level, + const char *config_file, + unsigned config_line, + const char *file, + int line, + const char *func, + const char *rvalue) { + + _cleanup_free_ char *p = NULL; + + if (rvalue) + p = utf8_escape_invalid(rvalue); + + return log_syntax_internal(unit, level, config_file, config_line, + SYNTHETIC_ERRNO(EINVAL), file, line, func, + "String is not UTF-8 clean, ignoring assignment: %s", strna(p)); +} + +void log_set_upgrade_syslog_to_journal(bool b) { + upgrade_syslog_to_journal = b; + + /* Make the change effective immediately */ + if (b) { + if (log_target == LOG_TARGET_SYSLOG) + log_target = LOG_TARGET_JOURNAL; + else if (log_target == LOG_TARGET_SYSLOG_OR_KMSG) + log_target = LOG_TARGET_JOURNAL_OR_KMSG; + } +} + +void log_set_always_reopen_console(bool b) { + always_reopen_console = b; +} + +void log_set_open_when_needed(bool b) { + open_when_needed = b; +} + +void log_set_prohibit_ipc(bool b) { + prohibit_ipc = b; +} + +int log_emergency_level(void) { + /* Returns the log level to use for log_emergency() logging. We use LOG_EMERG only when we are PID 1, as only + * then the system of the whole system is obviously affected. */ + + return getpid_cached() == 1 ? LOG_EMERG : LOG_ERR; +} + +int log_dup_console(void) { + int copy; + + /* Duplicate the fd we use for fd logging if it's < 3 and use the copy from now on. This call is useful + * whenever we want to continue logging through the original fd, but want to rearrange stderr. */ + + if (console_fd < 0 || console_fd >= 3) + return 0; + + copy = fcntl(console_fd, F_DUPFD_CLOEXEC, 3); + if (copy < 0) + return -errno; + + console_fd = copy; + return 0; +} + +void log_setup(void) { + log_set_target(LOG_TARGET_AUTO); + log_parse_environment(); + (void) log_open(); + if (log_on_console() && show_color < 0) + log_show_color(true); +} |