chiark / gitweb /
util: replace close_nointr_nofail() by a more useful safe_close()
[elogind.git] / src / shared / log.c
index b61845859f3cca5300b7750fa812a564cd2c3913..a4b3b68ef181e316f74da46f18dbd9399c595784 100644 (file)
@@ -27,6 +27,7 @@
 #include <sys/socket.h>
 #include <sys/un.h>
 #include <stddef.h>
+#include <printf.h>
 
 #include "log.h"
 #include "util.h"
@@ -61,7 +62,7 @@ void log_close_console(void) {
 
         if (getpid() == 1) {
                 if (console_fd >= 3)
-                        close_nointr_nofail(console_fd);
+                        safe_close(console_fd);
 
                 console_fd = -1;
         }
@@ -83,12 +84,7 @@ static int log_open_console(void) {
 }
 
 void log_close_kmsg(void) {
-
-        if (kmsg_fd < 0)
-                return;
-
-        close_nointr_nofail(kmsg_fd);
-        kmsg_fd = -1;
+        kmsg_fd = safe_close(kmsg_fd);
 }
 
 static int log_open_kmsg(void) {
@@ -104,40 +100,41 @@ static int log_open_kmsg(void) {
 }
 
 void log_close_syslog(void) {
-
-        if (syslog_fd < 0)
-                return;
-
-        close_nointr_nofail(syslog_fd);
-        syslog_fd = -1;
+        syslog_fd = safe_close(syslog_fd);
 }
 
 static int create_log_socket(int type) {
         int fd;
+        struct timeval tv;
 
-        /* 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);
+        fd = socket(AF_UNIX, type|SOCK_CLOEXEC, 0);
         if (fd < 0)
                 return -errno;
 
         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() == 1)
+                timeval_store(&tv, 10 * USEC_PER_MSEC);
+        else
+                timeval_store(&tv, 10 * USEC_PER_SEC);
+        setsockopt(fd, SOL_SOCKET, SO_SNDTIMEO, &tv, sizeof(tv));
+
         return fd;
 }
 
 static int log_open_syslog(void) {
-        union sockaddr_union sa;
         int r;
+        union sockaddr_union sa = {
+                .un.sun_family = AF_UNIX,
+                .un.sun_path = "/dev/log",
+        };
 
         if (syslog_fd >= 0)
                 return 0;
 
-        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;
@@ -145,7 +142,7 @@ static int log_open_syslog(void) {
         }
 
         if (connect(syslog_fd, &sa.sa, offsetof(struct sockaddr_un, sun_path) + strlen(sa.un.sun_path)) < 0) {
-                close_nointr_nofail(syslog_fd);
+                safe_close(syslog_fd);
 
                 /* Some legacy syslog systems still use stream
                  * sockets. They really shouldn't. But what can we
@@ -173,16 +170,14 @@ fail:
 }
 
 void log_close_journal(void) {
-
-        if (journal_fd < 0)
-                return;
-
-        close_nointr_nofail(journal_fd);
-        journal_fd = -1;
+        journal_fd = safe_close(journal_fd);
 }
 
 static int log_open_journal(void) {
-        union sockaddr_union sa;
+        union sockaddr_union sa = {
+                .un.sun_family = AF_UNIX,
+                .un.sun_path = "/run/systemd/journal/socket",
+        };
         int r;
 
         if (journal_fd >= 0)
@@ -194,10 +189,6 @@ static int log_open_journal(void) {
                 goto fail;
         }
 
-        zero(sa);
-        sa.un.sun_family = AF_UNIX;
-        strncpy(sa.un.sun_path, "/run/systemd/journal/socket", sizeof(sa.un.sun_path));
-
         if (connect(journal_fd, &sa.sa, offsetof(struct sockaddr_un, sun_path) + strlen(sa.un.sun_path)) < 0) {
                 r = -errno;
                 goto fail;
@@ -269,8 +260,6 @@ int log_open(void) {
         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();
 }
 
@@ -307,10 +296,12 @@ static int write_to_console(
                 const char*file,
                 int line,
                 const char *func,
+                const char *object_name,
+                const char *object,
                 const char *buffer) {
 
         char location[64];
-        struct iovec iovec[5];
+        struct iovec iovec[5] = {};
         unsigned n = 0;
         bool highlight;
 
@@ -319,8 +310,6 @@ static int write_to_console(
 
         highlight = LOG_PRI(level) <= LOG_ERR && show_color;
 
-        zero(iovec);
-
         if (show_location) {
                 snprintf(location, sizeof(location), "(%s:%u) ", file, line);
                 char_array_0(location);
@@ -334,8 +323,25 @@ static int write_to_console(
                 IOVEC_SET_STRING(iovec[n++], ANSI_HIGHLIGHT_OFF);
         IOVEC_SET_STRING(iovec[n++], "\n");
 
-        if (writev(console_fd, iovec, n) < 0)
-                return -errno;
+        if (writev(console_fd, iovec, n) < 0) {
+
+                if (errno == EIO && getpid() == 1) {
+
+                        /* If somebody tried to kick us from our
+                         * console tty (via vhangup() or suchlike),
+                         * try to reconnect */
+
+                        log_close_console();
+                        log_open_console();
+
+                        if (console_fd < 0)
+                                return 0;
+
+                        if (writev(console_fd, iovec, n) < 0)
+                                return -errno;
+                } else
+                        return -errno;
+        }
 
         return 1;
 }
@@ -345,11 +351,16 @@ static int write_to_syslog(
         const char*file,
         int line,
         const char *func,
+        const char *object_name,
+        const char *object,
         const char *buffer) {
 
         char header_priority[16], header_time[64], header_pid[16];
-        struct iovec iovec[5];
-        struct msghdr msghdr;
+        struct iovec iovec[5] = {};
+        struct msghdr msghdr = {
+                .msg_iov = iovec,
+                .msg_iovlen = ELEMENTSOF(iovec),
+        };
         time_t t;
         struct tm *tm;
 
@@ -360,7 +371,8 @@ static int write_to_syslog(
         char_array_0(header_priority);
 
         t = (time_t) (now(CLOCK_REALTIME) / USEC_PER_SEC);
-        if (!(tm = localtime(&t)))
+        tm = localtime(&t);
+        if (!tm)
                 return -EINVAL;
 
         if (strftime(header_time, sizeof(header_time), "%h %e %T ", tm) <= 0)
@@ -369,7 +381,6 @@ static int write_to_syslog(
         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], program_invocation_short_name);
@@ -380,10 +391,6 @@ static int write_to_syslog(
         if (syslog_is_stream)
                 iovec[4].iov_len++;
 
-        zero(msghdr);
-        msghdr.msg_iov = iovec;
-        msghdr.msg_iovlen = ELEMENTSOF(iovec);
-
         for (;;) {
                 ssize_t n;
 
@@ -406,10 +413,12 @@ static int write_to_kmsg(
         const char*file,
         int line,
         const char *func,
+        const char *object_name,
+        const char *object,
         const char *buffer) {
 
         char header_priority[16], header_pid[16];
-        struct iovec iovec[5];
+        struct iovec iovec[5] = {};
 
         if (kmsg_fd < 0)
                 return 0;
@@ -420,7 +429,6 @@ static int write_to_kmsg(
         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], program_invocation_short_name);
         IOVEC_SET_STRING(iovec[2], header_pid);
@@ -433,43 +441,61 @@ static int write_to_kmsg(
         return 1;
 }
 
+static int log_do_header(char *header, size_t size,
+                         int level,
+                         const char *file, int line, const char *func,
+                         const char *object_name, const char *object) {
+        snprintf(header, size,
+                 "PRIORITY=%i\n"
+                 "SYSLOG_FACILITY=%i\n"
+                 "%s%.*s%s"
+                 "%s%.*i%s"
+                 "%s%.*s%s"
+                 "%s%.*s%s"
+                 "SYSLOG_IDENTIFIER=%s\n",
+                 LOG_PRI(level),
+                 LOG_FAC(level),
+                 file ? "CODE_FILE=" : "",
+                 file ? LINE_MAX : 0, file, /* %.0s means no output */
+                 file ? "\n" : "",
+                 line ? "CODE_LINE=" : "",
+                 line ? 1 : 0, line, /* %.0d means no output too, special case for 0 */
+                 line ? "\n" : "",
+                 func ? "CODE_FUNCTION=" : "",
+                 func ? LINE_MAX : 0, func,
+                 func ? "\n" : "",
+                 object ? object_name : "",
+                 object ? LINE_MAX : 0, object, /* %.0s means no output */
+                 object ? "\n" : "",
+                 program_invocation_short_name);
+        header[size - 1] = '\0';
+        return 0;
+}
+
 static int write_to_journal(
         int level,
         const char*file,
         int line,
         const char *func,
+        const char *object_name,
+        const char *object,
         const char *buffer) {
 
         char header[LINE_MAX];
-        struct iovec iovec[3];
-        struct msghdr mh;
+        struct iovec iovec[4] = {};
+        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"
-                 "SYSLOG_IDENTIFIER=%s\n"
-                 "MESSAGE=",
-                 LOG_PRI(level),
-                 LOG_FAC(level),
-                 file,
-                 line,
-                 func,
-                 program_invocation_short_name);
-
-        char_array_0(header);
+        log_do_header(header, sizeof(header), level,
+                      file, line, func, object_name, object);
 
-        zero(iovec);
         IOVEC_SET_STRING(iovec[0], header);
-        IOVEC_SET_STRING(iovec[1], buffer);
-        IOVEC_SET_STRING(iovec[2], "\n");
+        IOVEC_SET_STRING(iovec[1], "MESSAGE=");
+        IOVEC_SET_STRING(iovec[2], buffer);
+        IOVEC_SET_STRING(iovec[3], "\n");
 
-        zero(mh);
         mh.msg_iov = iovec;
         mh.msg_iovlen = ELEMENTSOF(iovec);
 
@@ -484,6 +510,8 @@ static int log_dispatch(
         const char*file,
         int line,
         const char *func,
+        const char *object_name,
+        const char *object,
         char *buffer) {
 
         int r = 0;
@@ -511,7 +539,8 @@ static int log_dispatch(
                     log_target == LOG_TARGET_JOURNAL_OR_KMSG ||
                     log_target == LOG_TARGET_JOURNAL) {
 
-                        k = write_to_journal(level, file, line, func, buffer);
+                        k = write_to_journal(level, file, line, func,
+                                             object_name, object, buffer);
                         if (k < 0) {
                                 if (k != -EAGAIN)
                                         log_close_journal();
@@ -523,7 +552,8 @@ static int log_dispatch(
                 if (log_target == LOG_TARGET_SYSLOG_OR_KMSG ||
                     log_target == LOG_TARGET_SYSLOG) {
 
-                        k = write_to_syslog(level, file, line, func, buffer);
+                        k = write_to_syslog(level, file, line, func,
+                                            object_name, object, buffer);
                         if (k < 0) {
                                 if (k != -EAGAIN)
                                         log_close_syslog();
@@ -539,7 +569,8 @@ static int log_dispatch(
                      log_target == LOG_TARGET_JOURNAL_OR_KMSG ||
                      log_target == LOG_TARGET_KMSG)) {
 
-                        k = write_to_kmsg(level, file, line, func, buffer);
+                        k = write_to_kmsg(level, file, line, func,
+                                          object_name, object, buffer);
                         if (k < 0) {
                                 log_close_kmsg();
                                 log_open_console();
@@ -548,7 +579,8 @@ static int log_dispatch(
                 }
 
                 if (k <= 0) {
-                        k = write_to_console(level, file, line, func, buffer);
+                        k = write_to_console(level, file, line, func,
+                                             object_name, object, buffer);
                         if (k < 0)
                                 return k;
                 }
@@ -566,18 +598,14 @@ int log_dump_internal(
         const char *func,
         char *buffer) {
 
-        int saved_errno, r;
+        PROTECT_ERRNO;
 
         /* 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;
-
-        return r;
+        return log_dispatch(level, file, line, func, NULL, NULL, buffer);
 }
 
 int log_metav(
@@ -588,20 +616,16 @@ int log_metav(
         const char *format,
         va_list ap) {
 
+        PROTECT_ERRNO;
         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);
-        errno = saved_errno;
-
-        return r;
+        return log_dispatch(level, file, line, func, NULL, NULL, buffer);
 }
 
 int log_meta(
@@ -621,27 +645,78 @@ int log_meta(
         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) {
+int log_metav_object(
+        int level,
+        const char*file,
+        int line,
+        const char *func,
+        const char *object_name,
+        const char *object,
+        const char *format,
+        va_list ap) {
+
+        PROTECT_ERRNO;
+        char buffer[LINE_MAX];
+
+        if (_likely_(LOG_PRI(level) > log_max_level))
+                return 0;
+
+        vsnprintf(buffer, sizeof(buffer), format, ap);
+        char_array_0(buffer);
+
+        return log_dispatch(level, file, line, func,
+                            object_name, object, buffer);
+}
+
+int log_meta_object(
+        int level,
+        const char*file,
+        int line,
+        const char *func,
+        const char *object_name,
+        const char *object,
+        const char *format, ...) {
+
+        int r;
+        va_list ap;
+
+        va_start(ap, format);
+        r = log_metav_object(level, file, line, func,
+                             object_name, object, 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;
         snprintf(buffer, sizeof(buffer), format, text, file, line, func);
+        REENABLE_WARNING;
 
         char_array_0(buffer);
         log_abort_msg = buffer;
 
-        log_dispatch(LOG_CRIT, file, line, func, buffer);
+        log_dispatch(level, file, line, func, 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();
 }
-#pragma GCC diagnostic pop
 
-_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(LOG_CRIT, text, file, line, func, "Code should not be reached '%s' at %s:%u, function %s(). Aborting.");
+        abort();
 }
 
-_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.");
+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(const char *file, int line, const char *func) {
@@ -656,7 +731,7 @@ int log_struct_internal(
                 const char *func,
                 const char *format, ...) {
 
-        int saved_errno;
+        PROTECT_ERRNO;
         va_list ap;
         int r;
 
@@ -669,47 +744,44 @@ int log_struct_internal(
         if ((level & LOG_FACMASK) == 0)
                 level = log_facility | LOG_PRI(level);
 
-        saved_errno = errno;
-
         if ((log_target == LOG_TARGET_AUTO ||
              log_target == LOG_TARGET_JOURNAL_OR_KMSG ||
              log_target == LOG_TARGET_JOURNAL) &&
             journal_fd >= 0) {
 
                 char header[LINE_MAX];
-                struct iovec iovec[17];
+                struct iovec iovec[17] = {};
                 unsigned n = 0, i;
-                struct msghdr mh;
-                const char nl = '\n';
+                struct msghdr mh = {
+                        .msg_iov = iovec,
+                };
+                static const char nl = '\n';
 
                 /* If the journal is available do structured logging */
-
-                snprintf(header, sizeof(header),
-                        "PRIORITY=%i\n"
-                        "SYSLOG_FACILITY=%i\n"
-                        "CODE_FILE=%s\n"
-                        "CODE_LINE=%i\n"
-                        "CODE_FUNCTION=%s\n"
-                        "SYSLOG_IDENTIFIER=%s\n",
-                        LOG_PRI(level),
-                        LOG_FAC(level),
-                        file,
-                        line,
-                        func,
-                        program_invocation_short_name);
-                char_array_0(header);
-
-                zero(iovec);
+                log_do_header(header, sizeof(header), level,
+                              file, line, func, NULL, NULL);
                 IOVEC_SET_STRING(iovec[n++], header);
 
                 va_start(ap, format);
                 while (format && n + 1 < ELEMENTSOF(iovec)) {
                         char *buf;
+                        va_list aq;
+
+                        /* We need to copy the va_list structure,
+                         * since vasprintf() leaves it afterwards at
+                         * an undefined location */
 
-                        if (vasprintf(&buf, format, ap) < 0) {
+                        va_copy(aq, ap);
+                        if (vasprintf(&buf, format, aq) < 0) {
+                                va_end(aq);
                                 r = -ENOMEM;
                                 goto finish;
                         }
+                        va_end(aq);
+
+                        /* Now, jump enough ahead, so that we point to
+                         * the next format string */
+                        VA_FORMAT_ADVANCE(format, ap);
 
                         IOVEC_SET_STRING(iovec[n++], buf);
 
@@ -720,8 +792,6 @@ int log_struct_internal(
                         format = va_arg(ap, char *);
                 }
 
-                zero(mh);
-                mh.msg_iov = iovec;
                 mh.msg_iovlen = n;
 
                 if (sendmsg(journal_fd, &mh, MSG_NOSIGNAL) < 0)
@@ -742,8 +812,11 @@ int log_struct_internal(
 
                 va_start(ap, format);
                 while (format) {
+                        va_list aq;
 
-                        vsnprintf(buf, sizeof(buf), format, ap);
+                        va_copy(aq, ap);
+                        vsnprintf(buf, sizeof(buf), format, aq);
+                        va_end(aq);
                         char_array_0(buf);
 
                         if (startswith(buf, "MESSAGE=")) {
@@ -751,17 +824,19 @@ int log_struct_internal(
                                 break;
                         }
 
+                        VA_FORMAT_ADVANCE(format, ap);
+
                         format = va_arg(ap, char *);
                 }
                 va_end(ap);
 
                 if (found)
-                        r = log_dispatch(level, file, line, func, buf + 8);
+                        r = log_dispatch(level, file, line, func,
+                                         NULL, NULL, buf + 8);
                 else
                         r = -EINVAL;
         }
 
-        errno = saved_errno;
         return r;
 }
 
@@ -788,7 +863,24 @@ int log_set_max_level_from_string(const char *e) {
 }
 
 void log_parse_environment(void) {
+        _cleanup_free_ char *line = NULL;
         const char *e;
+        int r;
+
+        r = proc_cmdline(&line);
+        if (r < 0)
+                log_warning("Failed to read /proc/cmdline. Ignoring: %s", strerror(-r));
+        else if (r > 0) {
+                char *w, *state;
+                size_t l;
+
+                FOREACH_WORD_QUOTED(w, l, line, state) {
+                        if (l == 5 && startswith(w, "debug")) {
+                                log_set_max_level(LOG_DEBUG);
+                                break;
+                        }
+                }
+        }
 
         e = secure_getenv("SYSTEMD_LOG_TARGET");
         if (e && log_set_target_from_string(e) < 0)
@@ -819,10 +911,18 @@ void log_show_color(bool b) {
         show_color = b;
 }
 
+bool log_get_show_color(void) {
+        return show_color;
+}
+
 void log_show_location(bool b) {
         show_location = b;
 }
 
+bool log_get_show_location(void) {
+        return show_location;
+}
+
 int log_show_color_from_string(const char *e) {
         int t;
 
@@ -852,7 +952,7 @@ bool log_on_console(void) {
         return syslog_fd < 0 && kmsg_fd < 0 && journal_fd < 0;
 }
 
-static const char *const log_target_table[] = {
+static const char *const log_target_table[_LOG_TARGET_MAX] = {
         [LOG_TARGET_CONSOLE] = "console",
         [LOG_TARGET_KMSG] = "kmsg",
         [LOG_TARGET_JOURNAL] = "journal",
@@ -865,3 +965,20 @@ static const char *const log_target_table[] = {
 };
 
 DEFINE_STRING_TABLE_LOOKUP(log_target, LogTarget);
+
+void log_received_signal(int level, const struct signalfd_siginfo *si) {
+        if (si->ssi_pid > 0) {
+                _cleanup_free_ char *p = NULL;
+
+                get_process_comm(si->ssi_pid, &p);
+
+                log_full(level,
+                         "Received SIG%s from PID "PID_FMT" (%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));
+
+}