X-Git-Url: https://www.chiark.greenend.org.uk/ucgi/~ianmdlvl/git?p=elogind.git;a=blobdiff_plain;f=src%2Flog.c;h=9fffc1dbc00ba2123cae35afbf3d4eb0156865eb;hp=a47285cb2129130e463ed822767ac1fa501d3088;hb=3eff4208ffecedd778fec260f0d4b18e94dab443;hpb=541d6159c6b82c6786730d70b761d1aefffa8deb diff --git a/src/log.c b/src/log.c index a47285cb2..9fffc1dbc 100644 --- a/src/log.c +++ b/src/log.c @@ -1,4 +1,4 @@ -/*-*- Mode: C; c-basic-offset: 8 -*-*/ +/*-*- Mode: C; c-basic-offset: 8; indent-tabs-mode: nil -*-*/ /*** This file is part of systemd. @@ -26,25 +26,30 @@ #include #include #include +#include #include "log.h" #include "util.h" #include "macro.h" +#include "socket-util.h" -#define SYSLOG_TIMEOUT_USEC (5*USEC_PER_SEC) -#define LOG_BUFFER_MAX 1024 +#define SNDBUF_SIZE (8*1024*1024) 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 syslog_fd = -1; static int kmsg_fd = -1; +static int journal_fd = -1; + +static bool syslog_is_stream = false; static bool show_color = false; static bool show_location = false; -/* Akin to glibc's __abort_msg; which is private and we hance cannot +/* Akin to glibc's __abort_msg; which is private and we hence cannot * use here. */ static char *log_abort_msg = NULL; @@ -68,12 +73,13 @@ static int log_open_console(void) { if (getpid() == 1) { - if ((console_fd = open_terminal("/dev/console", O_WRONLY|O_NOCTTY|O_CLOEXEC)) < 0) { + console_fd = open_terminal("/dev/console", O_WRONLY|O_NOCTTY|O_CLOEXEC); + if (console_fd < 0) { log_error("Failed to open /dev/console for logging: %s", strerror(-console_fd)); return console_fd; } - log_info("Succesfully opened /dev/console for logging."); + log_debug("Successfully opened /dev/console for logging."); } else console_fd = STDERR_FILENO; @@ -94,12 +100,13 @@ static int log_open_kmsg(void) { if (kmsg_fd >= 0) return 0; - if ((kmsg_fd = open("/dev/kmsg", O_WRONLY|O_NOCTTY|O_CLOEXEC)) < 0) { - log_info("Failed to open /dev/kmsg for logging: %s", strerror(errno)); + kmsg_fd = open("/dev/kmsg", O_WRONLY|O_NOCTTY|O_CLOEXEC); + if (kmsg_fd < 0) { + log_error("Failed to open /dev/kmsg for logging: %s", strerror(errno)); return -errno; } - log_info("Succesfully opened /dev/kmsg for logging."); + log_debug("Successfully opened /dev/kmsg for logging."); return 0; } @@ -113,46 +120,107 @@ void log_close_syslog(void) { syslog_fd = -1; } +static int create_log_socket(int type) { + int fd; + + /* All output to the syslog/journal fds we do asynchronously, + * and if the buffers are full we just drop the messages */ + + fd = socket(AF_UNIX, type|SOCK_CLOEXEC|SOCK_NONBLOCK, 0); + if (fd < 0) + return -errno; + + fd_inc_sndbuf(fd, SNDBUF_SIZE); + + return fd; +} + static int log_open_syslog(void) { - union { - struct sockaddr sa; - struct sockaddr_un un; - } sa; - struct timeval tv; + union sockaddr_union sa; int r; if (syslog_fd >= 0) return 0; - if ((syslog_fd = socket(AF_UNIX, SOCK_DGRAM|SOCK_CLOEXEC, 0)) < 0) { - r = -errno; + zero(sa); + sa.un.sun_family = AF_UNIX; + strncpy(sa.un.sun_path, "/dev/log", sizeof(sa.un.sun_path)); + + syslog_fd = create_log_socket(SOCK_DGRAM); + if (syslog_fd < 0) { + r = syslog_fd; goto fail; } - /* Make sure we don't block for more than 5s when talking to - * syslog */ - timeval_store(&tv, SYSLOG_TIMEOUT_USEC); - if (setsockopt(syslog_fd, SOL_SOCKET, SO_SNDTIMEO, &tv, sizeof(tv)) < 0) { - r = -errno; + if (connect(syslog_fd, &sa.sa, offsetof(struct sockaddr_un, sun_path) + strlen(sa.un.sun_path)) < 0) { + close_nointr_nofail(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; + } + + if (connect(syslog_fd, &sa.sa, offsetof(struct sockaddr_un, sun_path) + strlen(sa.un.sun_path)) < 0) { + r = -errno; + goto fail; + } + + syslog_is_stream = true; + } else + syslog_is_stream = false; + + log_debug("Successfully opened syslog for logging."); + + return 0; + +fail: + log_close_syslog(); + log_debug("Failed to open syslog for logging: %s", strerror(-r)); + return r; +} + +void log_close_journal(void) { + + if (journal_fd < 0) + return; + + close_nointr_nofail(journal_fd); + journal_fd = -1; +} + +static int log_open_journal(void) { + union sockaddr_union sa; + int r; + + if (journal_fd >= 0) + return 0; + + journal_fd = create_log_socket(SOCK_DGRAM); + if (journal_fd < 0) { + r = journal_fd; goto fail; } zero(sa); sa.un.sun_family = AF_UNIX; - strncpy(sa.un.sun_path, "/dev/log", sizeof(sa.un.sun_path)); + strncpy(sa.un.sun_path, "/run/systemd/journal/socket", sizeof(sa.un.sun_path)); - if (connect(syslog_fd, &sa.sa, sizeof(sa)) < 0) { + if (connect(journal_fd, &sa.sa, offsetof(struct sockaddr_un, sun_path) + strlen(sa.un.sun_path)) < 0) { r = -errno; goto fail; } - log_info("Succesfully opened syslog for logging."); + log_debug("Successfully opened journal for logging."); return 0; fail: - log_close_syslog(); - log_info("Failed to open syslog for logging: %s", strerror(-r)); + log_close_journal(); + log_debug("Failed to open journal for logging: %s", strerror(-r)); return r; } @@ -166,27 +234,56 @@ int log_open(void) { * 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 (log_target == LOG_TARGET_SYSLOG_OR_KMSG || - log_target == LOG_TARGET_SYSLOG) - if ((r = log_open_syslog()) >= 0) { - log_close_console(); - return r; + if (log_target != LOG_TARGET_AUTO || + getpid() == 1 || + isatty(STDERR_FILENO) <= 0) { + + if (log_target == LOG_TARGET_AUTO || + log_target == LOG_TARGET_JOURNAL_OR_KMSG || + log_target == LOG_TARGET_JOURNAL) { + r = log_open_journal(); + if (r >= 0) { + log_close_syslog(); + log_close_console(); + return r; + } + } + + if (log_target == LOG_TARGET_SYSLOG_OR_KMSG || + log_target == LOG_TARGET_SYSLOG) { + r = log_open_syslog(); + if (r >= 0) { + log_close_journal(); + log_close_console(); + return r; + } } - if (log_target == LOG_TARGET_SYSLOG_OR_KMSG || - log_target == LOG_TARGET_KMSG) - if ((r = log_open_kmsg()) >= 0) { - log_close_syslog(); - log_close_console(); - return r; + if (log_target == LOG_TARGET_AUTO || + log_target == LOG_TARGET_JOURNAL_OR_KMSG || + log_target == LOG_TARGET_SYSLOG_OR_KMSG || + log_target == 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(); + + /* Get the real /dev/console if we are PID=1, hence reopen */ + log_close_console(); return log_open_console(); } @@ -197,18 +294,33 @@ void log_set_target(LogTarget target) { log_target = target; } +void log_close(void) { + log_close_journal(); + log_close_syslog(); + log_close_kmsg(); + log_close_console(); +} + +void log_forget_fds(void) { + console_fd = kmsg_fd = syslog_fd = journal_fd = -1; +} + void log_set_max_level(int level) { assert((level & LOG_PRIMASK) == level); log_max_level = level; } +void log_set_facility(int facility) { + log_facility = facility; +} + static int write_to_console( - int level, - const char*file, - int line, - const char *func, - const char *buffer) { + int level, + const char*file, + int line, + const char *func, + const char *buffer) { char location[64]; struct iovec iovec[5]; @@ -218,19 +330,21 @@ static int write_to_console( if (console_fd < 0) return 0; - snprintf(location, sizeof(location), "(%s:%u) ", file, line); - char_array_0(location); - highlight = LOG_PRI(level) <= LOG_ERR && show_color; zero(iovec); - if (show_location) + + if (show_location) { + snprintf(location, sizeof(location), "(%s:%u) ", file, line); + char_array_0(location); IOVEC_SET_STRING(iovec[n++], location); + } + if (highlight) - IOVEC_SET_STRING(iovec[n++], "\x1B[1;31m"); + IOVEC_SET_STRING(iovec[n++], ANSI_HIGHLIGHT_RED_ON); IOVEC_SET_STRING(iovec[n++], buffer); if (highlight) - IOVEC_SET_STRING(iovec[n++], "\x1B[0m"); + IOVEC_SET_STRING(iovec[n++], ANSI_HIGHLIGHT_OFF); IOVEC_SET_STRING(iovec[n++], "\n"); if (writev(console_fd, iovec, n) < 0) @@ -255,7 +369,7 @@ static int write_to_syslog( if (syslog_fd < 0) return 0; - snprintf(header_priority, sizeof(header_priority), "<%i>", LOG_MAKEPRI(LOG_DAEMON, LOG_PRI(level))); + snprintf(header_priority, sizeof(header_priority), "<%i>", level); char_array_0(header_priority); t = (time_t) (now(CLOCK_REALTIME) / USEC_PER_SEC); @@ -275,12 +389,27 @@ static int write_to_syslog( IOVEC_SET_STRING(iovec[3], header_pid); IOVEC_SET_STRING(iovec[4], buffer); + /* When using syslog via SOCK_STREAM separate the messages by NUL chars */ + if (syslog_is_stream) + iovec[4].iov_len++; + zero(msghdr); msghdr.msg_iov = iovec; msghdr.msg_iovlen = ELEMENTSOF(iovec); - if (sendmsg(syslog_fd, &msghdr, 0) < 0) - return -errno; + for (;;) { + ssize_t n; + + n = sendmsg(syslog_fd, &msghdr, MSG_NOSIGNAL); + if (n < 0) + return -errno; + + if (!syslog_is_stream || + (size_t) n >= IOVEC_TOTAL_SIZE(iovec, ELEMENTSOF(iovec))) + break; + + IOVEC_INCREMENT(iovec, ELEMENTSOF(iovec), n); + } return 1; } @@ -298,7 +427,7 @@ static int write_to_kmsg( if (kmsg_fd < 0) return 0; - snprintf(header_priority, sizeof(header_priority), "<%i>", LOG_PRI(level)); + snprintf(header_priority, sizeof(header_priority), "<%i>", level); char_array_0(header_priority); snprintf(header_pid, sizeof(header_pid), "[%lu]: ", (unsigned long) getpid()); @@ -317,6 +446,50 @@ static int write_to_kmsg( return 1; } +static int write_to_journal( + int level, + const char*file, + int line, + const char *func, + const char *buffer) { + + char header[LINE_MAX]; + struct iovec iovec[3]; + struct msghdr mh; + + if (journal_fd < 0) + return 0; + + snprintf(header, sizeof(header), + "PRIORITY=%i\n" + "SYSLOG_FACILITY=%i\n" + "CODE_FILE=%s\n" + "CODE_LINE=%i\n" + "CODE_FUNCTION=%s\n" + "MESSAGE=", + LOG_PRI(level), + LOG_FAC(level), + file, + line, + func); + + char_array_0(header); + + zero(iovec); + IOVEC_SET_STRING(iovec[0], header); + IOVEC_SET_STRING(iovec[1], buffer); + IOVEC_SET_STRING(iovec[2], "\n"); + + zero(mh); + mh.msg_iov = iovec; + mh.msg_iovlen = ELEMENTSOF(iovec); + + if (sendmsg(journal_fd, &mh, MSG_NOSIGNAL) < 0) + return -errno; + + return 1; +} + static int log_dispatch( int level, const char*file, @@ -329,9 +502,13 @@ static int log_dispatch( if (log_target == LOG_TARGET_NULL) return 0; + /* Patch in LOG_DAEMON facility if necessary */ + if ((level & LOG_FACMASK) == 0) + level = log_facility | LOG_PRI(level); + do { char *e; - int k; + int k = 0; buffer += strspn(buffer, NEWLINE); @@ -341,28 +518,49 @@ static int log_dispatch( if ((e = strpbrk(buffer, NEWLINE))) *(e++) = 0; + if (log_target == LOG_TARGET_AUTO || + log_target == LOG_TARGET_JOURNAL_OR_KMSG || + log_target == LOG_TARGET_JOURNAL) { + + k = write_to_journal(level, file, line, func, buffer); + if (k < 0) { + if (k != -EAGAIN) + log_close_journal(); + log_open_kmsg(); + } else if (k > 0) + r++; + } + if (log_target == LOG_TARGET_SYSLOG_OR_KMSG || log_target == LOG_TARGET_SYSLOG) { - if ((r = write_to_syslog(level, file, line, func, buffer)) < 0) { - log_close_syslog(); + k = write_to_syslog(level, file, line, func, buffer); + if (k < 0) { + if (k != -EAGAIN) + log_close_syslog(); log_open_kmsg(); - } else if (r > 0) + } else if (k > 0) r++; } - if (log_target == LOG_TARGET_SYSLOG_OR_KMSG || - log_target == LOG_TARGET_KMSG) { + if (k <= 0 && + (log_target == LOG_TARGET_AUTO || + log_target == LOG_TARGET_SYSLOG_OR_KMSG || + log_target == LOG_TARGET_KMSG)) { - if ((r = write_to_kmsg(level, file, line, func, buffer)) < 0) { + k = write_to_kmsg(level, file, line, func, buffer); + if (k < 0) { log_close_kmsg(); log_open_console(); - } else if (r > 0) + } else if (k > 0) r++; } - if ((k = write_to_console(level, file, line, func, buffer)) < 0) - return k; + if (k <= 0) { + k = write_to_console(level, file, line, func, buffer); + if (k < 0) + return k; + } buffer = e; } while (buffer); @@ -391,26 +589,22 @@ int log_dump_internal( return r; } -int log_meta( +int log_metav( int level, const char*file, int line, const char *func, - const char *format, ...) { + const char *format, + va_list ap) { - char buffer[LOG_BUFFER_MAX]; + char buffer[LINE_MAX]; int saved_errno, r; - va_list ap; if (_likely_(LOG_PRI(level) > log_max_level)) return 0; saved_errno = errno; - - va_start(ap, format); vsnprintf(buffer, sizeof(buffer), format, ap); - va_end(ap); - char_array_0(buffer); r = log_dispatch(level, file, line, func, buffer); @@ -419,34 +613,51 @@ int log_meta( return r; } -void log_assert( +int log_meta( + int level, const char*file, int line, const char *func, const char *format, ...) { - static char buffer[LOG_BUFFER_MAX]; - int saved_errno = errno; + int r; va_list ap; va_start(ap, format); - vsnprintf(buffer, sizeof(buffer), format, ap); + r = log_metav(level, file, line, func, format, ap); va_end(ap); + return r; +} + +#pragma GCC diagnostic push +#pragma GCC diagnostic ignored "-Wformat-nonliteral" +_noreturn_ static void log_assert(const char *text, const char *file, int line, const char *func, const char *format) { + static char buffer[LINE_MAX]; + + snprintf(buffer, sizeof(buffer), format, text, file, line, func); + char_array_0(buffer); log_abort_msg = buffer; log_dispatch(LOG_CRIT, file, line, func, buffer); abort(); +} +#pragma GCC diagnostic pop - /* If the user chose to ignore this SIGABRT, we are happy to go on, as if nothing happened. */ - errno = saved_errno; +_noreturn_ void log_assert_failed(const char *text, const char *file, int line, const char *func) { + log_assert(text, file, line, func, "Assertion '%s' failed at %s:%u, function %s(). Aborting."); +} + +_noreturn_ void log_assert_failed_unreachable(const char *text, const char *file, int line, const char *func) { + log_assert(text, file, line, func, "Code should not be reached '%s' at %s:%u, function %s(). Aborting."); } int log_set_target_from_string(const char *e) { LogTarget t; - if ((t = log_target_from_string(e)) < 0) + t = log_target_from_string(e); + if (t < 0) return -EINVAL; log_set_target(t); @@ -456,8 +667,9 @@ int log_set_target_from_string(const char *e) { int log_set_max_level_from_string(const char *e) { int t; - if ((t = log_level_from_string(e)) < 0) - return -EINVAL; + t = log_level_from_string(e); + if (t < 0) + return t; log_set_max_level(t); return 0; @@ -478,10 +690,9 @@ void log_parse_environment(void) { if (log_show_color_from_string(e) < 0) log_warning("Failed to parse bool %s. Ignoring.", e); - if ((e = getenv("SYSTEMD_LOG_LOCATION"))) { + if ((e = getenv("SYSTEMD_LOG_LOCATION"))) if (log_show_location_from_string(e) < 0) log_warning("Failed to parse bool %s. Ignoring.", e); - } } LogTarget log_get_target(void) { @@ -503,8 +714,9 @@ void log_show_location(bool b) { int log_show_color_from_string(const char *e) { int t; - if ((t = parse_boolean(e)) < 0) - return -EINVAL; + t = parse_boolean(e); + if (t < 0) + return t; log_show_color(t); return 0; @@ -513,8 +725,9 @@ int log_show_color_from_string(const char *e) { int log_show_location_from_string(const char *e) { int t; - if ((t = parse_boolean(e)) < 0) - return -EINVAL; + t = parse_boolean(e); + if (t < 0) + return t; log_show_location(t); return 0; @@ -522,9 +735,12 @@ int log_show_location_from_string(const char *e) { static const char *const log_target_table[] = { [LOG_TARGET_CONSOLE] = "console", - [LOG_TARGET_SYSLOG] = "syslog", [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" };