chiark / gitweb /
logind: log with AUTH facility
[elogind.git] / src / log.c
index 7b4db4c77a4134f78a7ecd657637248a06049e40..9fffc1dbc00ba2123cae35afbf3d4eb0156865eb 100644 (file)
--- 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.
 #include <fcntl.h>
 #include <sys/socket.h>
 #include <sys/un.h>
+#include <stddef.h>
 
 #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_DEBUG;
+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;
 
-/* Akin to glibc's __abort_msg; which is private and we hance cannot
+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 hence cannot
  * use here. */
 static char *log_abort_msg = NULL;
 
@@ -65,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;
 
@@ -91,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;
 }
@@ -110,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;
 }
 
@@ -162,22 +233,57 @@ int log_open(void) {
          * the fs. 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_SYSLOG_OR_KMSG ||
-            log_target == LOG_TARGET_SYSLOG)
-                if ((r = log_open_syslog()) >= 0) {
-                        log_close_console();
-                        return r;
+        if (log_target == LOG_TARGET_NULL) {
+                log_close_journal();
+                log_close_syslog();
+                log_close_console();
+                return 0;
+        }
+
+        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_KMSG)
-                if ((r = log_open_kmsg()) >= 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_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();
 }
 
@@ -188,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];
@@ -209,18 +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;
+        highlight = LOG_PRI(level) <= LOG_ERR && show_color;
 
         zero(iovec);
-        IOVEC_SET_STRING(iovec[n++], 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)
@@ -245,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);
@@ -255,22 +379,37 @@ static int write_to_syslog(
         if (strftime(header_time, sizeof(header_time), "%h %e %T ", tm) <= 0)
                 return -EINVAL;
 
-        snprintf(header_pid, sizeof(header_pid), "[%llu]: ", (unsigned long long) getpid());
+        snprintf(header_pid, sizeof(header_pid), "[%lu]: ", (unsigned long) getpid());
         char_array_0(header_pid);
 
         zero(iovec);
         IOVEC_SET_STRING(iovec[0], header_priority);
         IOVEC_SET_STRING(iovec[1], header_time);
-        IOVEC_SET_STRING(iovec[2], __progname);
+        IOVEC_SET_STRING(iovec[2], program_invocation_short_name);
         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;
 }
@@ -288,15 +427,15 @@ 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), "[%llu]: ", (unsigned long long) getpid());
+        snprintf(header_pid, sizeof(header_pid), "[%lu]: ", (unsigned long) getpid());
         char_array_0(header_pid);
 
         zero(iovec);
         IOVEC_SET_STRING(iovec[0], header_priority);
-        IOVEC_SET_STRING(iovec[1], __progname);
+        IOVEC_SET_STRING(iovec[1], program_invocation_short_name);
         IOVEC_SET_STRING(iovec[2], header_pid);
         IOVEC_SET_STRING(iovec[3], buffer);
         IOVEC_SET_STRING(iovec[4], "\n");
@@ -307,58 +446,165 @@ static int write_to_kmsg(
         return 1;
 }
 
-static int log_dispatch(
+static int write_to_journal(
         int level,
         const char*file,
         int line,
         const char *func,
         const char *buffer) {
 
-        int r;
+        char header[LINE_MAX];
+        struct iovec iovec[3];
+        struct msghdr mh;
 
-        if (log_target == LOG_TARGET_SYSLOG_OR_KMSG ||
-            log_target == LOG_TARGET_SYSLOG) {
+        if (journal_fd < 0)
+                return 0;
 
-                if ((r = write_to_syslog(level, file, line, func, buffer)) < 0) {
-                        log_close_syslog();
-                        log_open_kmsg();
-                } else if (r > 0)
-                        return r;
-        }
+        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);
 
-        if (log_target == LOG_TARGET_SYSLOG_OR_KMSG ||
-            log_target == LOG_TARGET_KMSG) {
+        zero(iovec);
+        IOVEC_SET_STRING(iovec[0], header);
+        IOVEC_SET_STRING(iovec[1], buffer);
+        IOVEC_SET_STRING(iovec[2], "\n");
 
-                if ((r = write_to_kmsg(level, file, line, func, buffer)) < 0) {
-                        log_close_kmsg();
-                        log_open_console();
-                } else if (r > 0)
-                        return r;
-        }
+        zero(mh);
+        mh.msg_iov = iovec;
+        mh.msg_iovlen = ELEMENTSOF(iovec);
+
+        if (sendmsg(journal_fd, &mh, MSG_NOSIGNAL) < 0)
+                return -errno;
 
-        return write_to_console(level, file, line, func, buffer);
+        return 1;
 }
 
-int log_meta(
+static int log_dispatch(
         int level,
         const char*file,
         int line,
         const char *func,
-        const char *format, ...) {
+        char *buffer) {
+
+        int r = 0;
+
+        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 = 0;
+
+                buffer += strspn(buffer, NEWLINE);
+
+                if (buffer[0] == 0)
+                        break;
+
+                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) {
+
+                        k = write_to_syslog(level, file, line, func, buffer);
+                        if (k < 0) {
+                                if (k != -EAGAIN)
+                                        log_close_syslog();
+                                log_open_kmsg();
+                        } else if (k > 0)
+                                r++;
+                }
+
+                if (k <= 0 &&
+                    (log_target == LOG_TARGET_AUTO ||
+                     log_target == LOG_TARGET_SYSLOG_OR_KMSG ||
+                     log_target == LOG_TARGET_KMSG)) {
+
+                        k = write_to_kmsg(level, file, line, func, buffer);
+                        if (k < 0) {
+                                log_close_kmsg();
+                                log_open_console();
+                        } else if (k > 0)
+                                r++;
+                }
+
+                if (k <= 0) {
+                        k = write_to_console(level, file, line, func, buffer);
+                        if (k < 0)
+                                return k;
+                }
+
+                buffer = e;
+        } while (buffer);
+
+        return r;
+}
+
+int log_dump_internal(
+        int level,
+        const char*file,
+        int line,
+        const char *func,
+        char *buffer) {
 
-        char buffer[LOG_BUFFER_MAX];
         int saved_errno, r;
-        va_list ap;
 
-        if (_likely(LOG_PRI(level) > log_max_level))
+        /* This modifies the buffer... */
+
+        if (_likely_(LOG_PRI(level) > log_max_level))
                 return 0;
 
         saved_errno = errno;
+        r = log_dispatch(level, file, line, func, buffer);
+        errno = saved_errno;
 
-        va_start(ap, format);
-        vsnprintf(buffer, sizeof(buffer), format, ap);
-        va_end(ap);
+        return r;
+}
+
+int log_metav(
+        int level,
+        const char*file,
+        int line,
+        const char *func,
+        const char *format,
+        va_list ap) {
 
+        char buffer[LINE_MAX];
+        int saved_errno, r;
+
+        if (_likely_(LOG_PRI(level) > log_max_level))
+                return 0;
+
+        saved_errno = errno;
+        vsnprintf(buffer, sizeof(buffer), format, ap);
         char_array_0(buffer);
 
         r = log_dispatch(level, file, line, func, buffer);
@@ -367,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);
@@ -404,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;
@@ -421,6 +685,14 @@ void log_parse_environment(void) {
         if ((e = getenv("SYSTEMD_LOG_LEVEL")))
                 if (log_set_max_level_from_string(e) < 0)
                         log_warning("Failed to parse log level %s. Ignoring.", e);
+
+        if ((e = getenv("SYSTEMD_LOG_COLOR")))
+                if (log_show_color_from_string(e) < 0)
+                        log_warning("Failed to parse bool %s. Ignoring.", e);
+
+        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) {
@@ -431,11 +703,45 @@ int log_get_max_level(void) {
         return log_max_level;
 }
 
+void log_show_color(bool b) {
+        show_color = b;
+}
+
+void log_show_location(bool b) {
+        show_location = b;
+}
+
+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;
+}
+
 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"
 };
 
 DEFINE_STRING_TABLE_LOOKUP(log_target, LogTarget);