X-Git-Url: http://www.chiark.greenend.org.uk/ucgi/~ianmdlvl/git?p=elogind.git;a=blobdiff_plain;f=src%2Fshared%2Flog.c;h=3e48b3ccc24f303e41229a3f198942bcd09aa05a;hp=847202d7d38eb64592725944c69698112d293b94;hb=b1e90ec515408aec2702522f6f68c4920b56375b;hpb=81270860a5b8c6794f0c7bac8becfdd0c41a9385 diff --git a/src/shared/log.c b/src/shared/log.c index 847202d7d..3e48b3ccc 100644 --- a/src/shared/log.c +++ b/src/shared/log.c @@ -27,9 +27,11 @@ #include #include #include +#include #include "log.h" #include "util.h" +#include "missing.h" #include "macro.h" #include "socket-util.h" @@ -72,14 +74,9 @@ static int log_open_console(void) { return 0; if (getpid() == 1) { - 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)); + if (console_fd < 0) return console_fd; - } - - log_debug("Successfully opened /dev/console for logging."); } else console_fd = STDERR_FILENO; @@ -101,12 +98,8 @@ static int log_open_kmsg(void) { return 0; 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)); + if (kmsg_fd < 0) return -errno; - } - - log_debug("Successfully opened /dev/kmsg for logging."); return 0; } @@ -122,30 +115,36 @@ void log_close_syslog(void) { 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; @@ -173,13 +172,10 @@ static int log_open_syslog(void) { } 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; } @@ -193,7 +189,10 @@ void log_close_journal(void) { } 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) @@ -205,22 +204,15 @@ 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; } - log_debug("Successfully opened journal for logging."); - return 0; fail: log_close_journal(); - log_debug("Failed to open journal for logging: %s", strerror(-r)); return r; } @@ -283,8 +275,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(); } @@ -321,10 +311,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; @@ -333,8 +325,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); @@ -348,8 +338,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; } @@ -359,11 +366,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; @@ -374,7 +386,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) @@ -383,7 +396,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); @@ -394,10 +406,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; @@ -420,10 +428,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; @@ -434,7 +444,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); @@ -447,43 +456,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); @@ -498,6 +525,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; @@ -525,7 +554,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(); @@ -537,7 +567,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(); @@ -553,7 +584,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(); @@ -562,7 +594,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; } @@ -580,18 +613,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( @@ -602,20 +631,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( @@ -635,27 +660,79 @@ int log_meta( return r; } +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; +} + #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 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; + 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(); + log_dispatch(level, file, line, func, NULL, NULL, buffer); } #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(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 *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) { @@ -670,7 +747,7 @@ int log_struct_internal( const char *func, const char *format, ...) { - int saved_errno; + PROTECT_ERRNO; va_list ap; int r; @@ -683,47 +760,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; - if (vasprintf(&buf, format, ap) < 0) { + /* We need to copy the va_list structure, + * since vasprintf() leaves it afterwards at + * an undefined location */ + + 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); @@ -733,10 +807,7 @@ int log_struct_internal( format = va_arg(ap, char *); } - va_end(ap); - zero(mh); - mh.msg_iov = iovec; mh.msg_iovlen = n; if (sendmsg(journal_fd, &mh, MSG_NOSIGNAL) < 0) @@ -745,6 +816,7 @@ int log_struct_internal( r = 1; finish: + va_end(ap); for (i = 1; i < n; i += 2) free(iovec[i].iov_base); @@ -756,8 +828,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=")) { @@ -765,17 +840,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; } @@ -802,21 +879,38 @@ 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"); + e = secure_getenv("SYSTEMD_LOG_TARGET"); if (e && log_set_target_from_string(e) < 0) log_warning("Failed to parse log target %s. Ignoring.", e); - e = __secure_getenv("SYSTEMD_LOG_LEVEL"); + e = secure_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 = __secure_getenv("SYSTEMD_LOG_COLOR"); + e = secure_getenv("SYSTEMD_LOG_COLOR"); if (e && log_show_color_from_string(e) < 0) log_warning("Failed to parse bool %s. Ignoring.", e); - e = __secure_getenv("SYSTEMD_LOG_LOCATION"); + e = secure_getenv("SYSTEMD_LOG_LOCATION"); if (e && log_show_location_from_string(e) < 0) log_warning("Failed to parse bool %s. Ignoring.", e); } @@ -833,10 +927,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; @@ -879,3 +981,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)); + +}