chiark / gitweb /
log: make internal log api log directly to the journal
[elogind.git] / src / log.c
index a47285cb2129130e463ed822767ac1fa501d3088..6caa5fad0b8c37bb6809948f9c0aab343164d287 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 SOCKET_TIMEOUT_USEC (5*USEC_PER_SEC)
 
 static LogTarget log_target = LOG_TARGET_CONSOLE;
 static int log_max_level = LOG_INFO;
@@ -40,11 +41,14 @@ static int log_max_level = LOG_INFO;
 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 +72,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 +99,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 +119,115 @@ void log_close_syslog(void) {
         syslog_fd = -1;
 }
 
-static int log_open_syslog(void) {
-        union {
-                struct sockaddr sa;
-                struct sockaddr_un un;
-        } sa;
+static int create_log_socket(int type) {
         struct timeval tv;
+        int fd;
+
+        if (getpid() == 1)
+                /* systemd should not block on syslog */
+                type |= SOCK_NONBLOCK;
+
+        fd = socket(AF_UNIX, type|SOCK_CLOEXEC, 0);
+        if (fd < 0)
+                return -errno;
+
+        /* Make sure we don't block for more than 5s when talking to
+         * syslog */
+        timeval_store(&tv, SOCKET_TIMEOUT_USEC);
+        if (setsockopt(fd, SOL_SOCKET, SO_SNDTIMEO, &tv, sizeof(tv)) < 0) {
+                close_nointr_nofail(fd);
+                return -errno;
+        }
+
+        return fd;
+}
+
+static int log_open_syslog(void) {
+        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, sizeof(sa)) < 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, sizeof(sa)) < 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 +241,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,6 +301,17 @@ 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);
 
@@ -204,11 +319,11 @@ void log_set_max_level(int level) {
 }
 
 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 +333,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_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 +372,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 +392,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 +430,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 +449,48 @@ 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"
+                 "CODE_FILE=%s\n"
+                 "CODE_LINE=%i\n"
+                 "CODE_FUNCTION=%s\n"
+                 "MESSAGE=",
+                 LOG_PRI(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 +503,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_DAEMON | LOG_PRI(level);
+
         do {
                 char *e;
-                int k;
+                int k = 0;
 
                 buffer += strspn(buffer, NEWLINE);
 
@@ -341,28 +519,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);
@@ -398,7 +597,7 @@ int log_meta(
         const char *func,
         const char *format, ...) {
 
-        char buffer[LOG_BUFFER_MAX];
+        char buffer[LINE_MAX];
         int saved_errno, r;
         va_list ap;
 
@@ -425,7 +624,7 @@ void log_assert(
         const char *func,
         const char *format, ...) {
 
-        static char buffer[LOG_BUFFER_MAX];
+        static char buffer[LINE_MAX];
         int saved_errno = errno;
         va_list ap;
 
@@ -446,7 +645,8 @@ void log_assert(
 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 +656,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 +679,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 +703,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 +714,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 +724,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"
 };