morgan/systemd
1
0
Fork 0
mirror of https://github.com/morgan9e/systemd synced 2026-04-16 01:16:10 +09:00
Code Issues Packages Projects Releases Wiki Activity
Files
91ee7c5ebda88efe112d432d63cb5216806c828a
systemd/src/basic/log.c
Daan De Meyer 9c41618008 journal: Don't discard kmsg messages coming from journald itself 
Previously, we discarded any kmsg messages coming from journald
itself to avoid infinite loops where potentially the processing
of a kmsg message causes journald to log one or more messages to
kmsg which then get read again by the kmsg handler, ...

However, if we completely disable logging whenever we're processing
a kmsg message coming from journald itself, we also prevent any
infinite loops as we can be sure that journald won't accidentally
generate logging messages while processing a kmsg log message.

This change allows us to store all journald logs generated during
the processing of log messages from other services in the system
journal. Previously these could only be found in kmsg which has
low retention, can't be queried using journalctl and whose logs
don't survive reboots.
2021-11-18 19:37:17 +00:00

1505 lines
46 KiB
C
Raw Blame History

/* SPDX-License-Identifier: LGPL-2.1-or-later */
#include <errno.h>
#include <fcntl.h>
#include <inttypes.h>
#include <limits.h>
#include <stdarg.h>
#include <stddef.h>
#include <sys/signalfd.h>
#include <sys/stat.h>
#include <sys/time.h>
#include <sys/uio.h>
#include <sys/un.h>
#include <unistd.h>
#include "sd-messages.h"
#include "alloc-util.h"
#include "errno-util.h"
#include "fd-util.h"
#include "format-util.h"
#include "io-util.h"
#include "log.h"
#include "macro.h"
#include "missing_syscall.h"
#include "parse-util.h"
#include "proc-cmdline.h"
#include "process-util.h"
#include "ratelimit.h"
#include "signal-util.h"
#include "socket-util.h"
#include "stdio-util.h"
#include "string-table.h"
#include "string-util.h"
#include "syslog-util.h"
#include "terminal-util.h"
#include "time-util.h"
#include "utf8.h"
#define SNDBUF_SIZE (8*1024*1024)
static log_syntax_callback_t log_syntax_callback = NULL;
static void *log_syntax_callback_userdata = NULL;
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 int show_color = -1; /* tristate */
static bool show_location = false;
static bool show_time = false;
static bool show_tid = false;
static bool upgrade_syslog_to_journal = false;
static bool always_reopen_console = false;
static bool open_when_needed = false;
static bool prohibit_ipc = false;
/* Akin to glibc's __abort_msg; which is private and we hence cannot
* use here. */
static char *log_abort_msg = NULL;
/* An assert to use in logging functions that does not call recursively
* into our logging functions (since that might lead to a loop). */
#define assert_raw(expr) \
do { \
if (_unlikely_(!(expr))) { \
fputs(#expr "\n", stderr); \
abort(); \
} \
} while (false)
static void log_close_console(void) {
console_fd = safe_close_above_stdio(console_fd);
}
static int log_open_console(void) {
if (!always_reopen_console) {
console_fd = STDERR_FILENO;
return 0;
}
if (console_fd < 3) {
int fd;
fd = open_terminal("/dev/console", O_WRONLY|O_NOCTTY|O_CLOEXEC);
if (fd < 0)
return fd;
console_fd = fd_move_above_stdio(fd);
}
return 0;
}
static void log_close_kmsg(void) {
kmsg_fd = safe_close(kmsg_fd);
}
static int log_open_kmsg(void) {
if (kmsg_fd >= 0)
return 0;
kmsg_fd = open("/dev/kmsg", O_WRONLY|O_NOCTTY|O_CLOEXEC);
if (kmsg_fd < 0)
return -errno;
kmsg_fd = fd_move_above_stdio(kmsg_fd);
return 0;
}
static void log_close_syslog(void) {
syslog_fd = safe_close(syslog_fd);
}
static int create_log_socket(int type) {
struct timeval tv;
int fd;
fd = socket(AF_UNIX, type|SOCK_CLOEXEC, 0);
if (fd < 0)
return -errno;
fd = fd_move_above_stdio(fd);
(void) 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_cached() == 1)
timeval_store(&tv, 10 * USEC_PER_MSEC);
else
timeval_store(&tv, 10 * USEC_PER_SEC);
(void) setsockopt(fd, SOL_SOCKET, SO_SNDTIMEO, &tv, sizeof(tv));
return fd;
}
static int log_open_syslog(void) {
static const union sockaddr_union sa = {
.un.sun_family = AF_UNIX,
.un.sun_path = "/dev/log",
};
int r;
if (syslog_fd >= 0)
return 0;
syslog_fd = create_log_socket(SOCK_DGRAM);
if (syslog_fd < 0) {
r = syslog_fd;
goto fail;
}
if (connect(syslog_fd, &sa.sa, SOCKADDR_UN_LEN(sa.un)) < 0) {
safe_close(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, SOCKADDR_UN_LEN(sa.un)) < 0) {
r = -errno;
goto fail;
}
syslog_is_stream = true;
} else
syslog_is_stream = false;
return 0;
fail:
log_close_syslog();
return r;
}
static void log_close_journal(void) {
journal_fd = safe_close(journal_fd);
}
static int log_open_journal(void) {
static const union sockaddr_union sa = {
.un.sun_family = AF_UNIX,
.un.sun_path = "/run/systemd/journal/socket",
};
int r;
if (journal_fd >= 0)
return 0;
journal_fd = create_log_socket(SOCK_DGRAM);
if (journal_fd < 0) {
r = journal_fd;
goto fail;
}
if (connect(journal_fd, &sa.sa, SOCKADDR_UN_LEN(sa.un)) < 0) {
r = -errno;
goto fail;
}
return 0;
fail:
log_close_journal();
return r;
}
static bool stderr_is_journal(void) {
_cleanup_free_ char *w = NULL;
const char *e;
uint64_t dev, ino;
struct stat st;
e = getenv("JOURNAL_STREAM");
if (!e)
return false;
if (extract_first_word(&e, &w, ":", EXTRACT_DONT_COALESCE_SEPARATORS) <= 0)
return false;
if (!e)
return false;
if (safe_atou64(w, &dev) < 0)
return false;
if (safe_atou64(e, &ino) < 0)
return false;
if (fstat(STDERR_FILENO, &st) < 0)
return false;
return st.st_dev == dev && st.st_ino == ino;
}
int log_open(void) {
int r;
/* Do not call from library code. */
/* This function is often called in preparation for logging. Let's make sure we don't clobber errno,
* so that a call to a logging function immediately following a log_open() call can still easily
* reference an error that happened immediately before the log_open() call. */
PROTECT_ERRNO;
/* If we don't use the console, we close it here to not get killed by SAK. If we don't use syslog, we
* close it here too, so that we are not confused by somebody deleting the socket in the fs, and to
* make sure we don't use it if prohibit_ipc is set. 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_NULL) {
log_close_journal();
log_close_syslog();
log_close_console();
return 0;
}
if (getpid_cached() == 1 ||
stderr_is_journal() ||
IN_SET(log_target,
LOG_TARGET_KMSG,
LOG_TARGET_JOURNAL,
LOG_TARGET_JOURNAL_OR_KMSG,
LOG_TARGET_SYSLOG,
LOG_TARGET_SYSLOG_OR_KMSG)) {
if (!prohibit_ipc) {
if (IN_SET(log_target,
LOG_TARGET_AUTO,
LOG_TARGET_JOURNAL_OR_KMSG,
LOG_TARGET_JOURNAL)) {
r = log_open_journal();
if (r >= 0) {
log_close_syslog();
log_close_console();
return r;
}
}
if (IN_SET(log_target,
LOG_TARGET_SYSLOG_OR_KMSG,
LOG_TARGET_SYSLOG)) {
r = log_open_syslog();
if (r >= 0) {
log_close_journal();
log_close_console();
return r;
}
}
}
if (IN_SET(log_target, LOG_TARGET_AUTO,
LOG_TARGET_JOURNAL_OR_KMSG,
LOG_TARGET_SYSLOG_OR_KMSG,
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();
return log_open_console();
}
void log_set_target(LogTarget target) {
assert(target >= 0);
assert(target < _LOG_TARGET_MAX);
if (upgrade_syslog_to_journal) {
if (target == LOG_TARGET_SYSLOG)
target = LOG_TARGET_JOURNAL;
else if (target == LOG_TARGET_SYSLOG_OR_KMSG)
target = LOG_TARGET_JOURNAL_OR_KMSG;
}
log_target = target;
}
void log_close(void) {
/* Do not call from library code. */
log_close_journal();
log_close_syslog();
log_close_kmsg();
log_close_console();
}
void log_forget_fds(void) {
/* Do not call from library code. */
console_fd = kmsg_fd = syslog_fd = journal_fd = -1;
}
void log_set_max_level(int level) {
assert(level == LOG_NULL || (level & LOG_PRIMASK) == level);
log_max_level = level;
}
void log_set_facility(int facility) {
log_facility = facility;
}
static int write_to_console(
int level,
int error,
const char *file,
int line,
const char *func,
const char *buffer) {
char location[256],
header_time[FORMAT_TIMESTAMP_MAX],
prefix[1 + DECIMAL_STR_MAX(int) + 2],
tid_string[3 + DECIMAL_STR_MAX(pid_t) + 1];
struct iovec iovec[9];
const char *on = NULL, *off = NULL;
size_t n = 0;
if (console_fd < 0)
return 0;
if (log_target == LOG_TARGET_CONSOLE_PREFIXED) {
xsprintf(prefix, "<%i>", level);
iovec[n++] = IOVEC_MAKE_STRING(prefix);
}
if (show_time &&
format_timestamp(header_time, sizeof(header_time), now(CLOCK_REALTIME))) {
iovec[n++] = IOVEC_MAKE_STRING(header_time);
iovec[n++] = IOVEC_MAKE_STRING(" ");
}
if (show_tid) {
xsprintf(tid_string, "(" PID_FMT ") ", gettid());
iovec[n++] = IOVEC_MAKE_STRING(tid_string);
}
if (log_get_show_color())
get_log_colors(LOG_PRI(level), &on, &off, NULL);
if (show_location) {
const char *lon = "", *loff = "";
if (log_get_show_color()) {
lon = ansi_highlight_yellow4();
loff = ansi_normal();
}
(void) snprintf(location, sizeof location, "%s%s:%i%s: ", lon, file, line, loff);
iovec[n++] = IOVEC_MAKE_STRING(location);
}
if (on)
iovec[n++] = IOVEC_MAKE_STRING(on);
iovec[n++] = IOVEC_MAKE_STRING(buffer);
if (off)
iovec[n++] = IOVEC_MAKE_STRING(off);
iovec[n++] = IOVEC_MAKE_STRING("\n");
if (writev(console_fd, iovec, n) < 0) {
if (errno == EIO && getpid_cached() == 1) {
/* If somebody tried to kick us from our console tty (via vhangup() or suchlike), try
* to reconnect. */
log_close_console();
(void) log_open_console();
if (console_fd < 0)
return 0;
if (writev(console_fd, iovec, n) < 0)
return -errno;
} else
return -errno;
}
return 1;
}
static int write_to_syslog(
int level,
int error,
const char *file,
int line,
const char *func,
const char *buffer) {
char header_priority[2 + DECIMAL_STR_MAX(int) + 1],
header_time[64],
header_pid[4 + DECIMAL_STR_MAX(pid_t) + 1];
time_t t;
struct tm tm;
if (syslog_fd < 0)
return 0;
xsprintf(header_priority, "<%i>", level);
t = (time_t) (now(CLOCK_REALTIME) / USEC_PER_SEC);
if (!localtime_r(&t, &tm))
return -EINVAL;
if (strftime(header_time, sizeof(header_time), "%h %e %T ", &tm) <= 0)
return -EINVAL;
xsprintf(header_pid, "["PID_FMT"]: ", getpid_cached());
struct iovec iovec[] = {
IOVEC_MAKE_STRING(header_priority),
IOVEC_MAKE_STRING(header_time),
IOVEC_MAKE_STRING(program_invocation_short_name),
IOVEC_MAKE_STRING(header_pid),
IOVEC_MAKE_STRING(buffer),
};
const struct msghdr msghdr = {
.msg_iov = iovec,
.msg_iovlen = ELEMENTSOF(iovec),
};
/* When using syslog via SOCK_STREAM separate the messages by NUL chars */
if (syslog_is_stream)
iovec[ELEMENTSOF(iovec) - 1].iov_len++;
for (;;) {
ssize_t n;
n = sendmsg(syslog_fd, &msghdr, MSG_NOSIGNAL);
if (n < 0)
return -errno;
if (!syslog_is_stream)
break;
if (IOVEC_INCREMENT(iovec, ELEMENTSOF(iovec), n))
break;
}
return 1;
}
static int write_to_kmsg(
int level,
int error,
const char *file,
int line,
const char *func,
const char *buffer) {
/* Set a ratelimit on the amount of messages logged to /dev/kmsg. This is mostly supposed to be a
* safety catch for the case where start indiscriminately logging in a loop. It will not catch cases
* where we log excessively, but not in a tight loop.
*
* Note that this ratelimit is per-emitter, so we might still overwhelm /dev/kmsg with multiple
* loggers.
*/
static thread_local RateLimit ratelimit = { 5 * USEC_PER_SEC, 200 };
char header_priority[2 + DECIMAL_STR_MAX(int) + 1],
header_pid[4 + DECIMAL_STR_MAX(pid_t) + 1];
if (kmsg_fd < 0)
return 0;
if (!ratelimit_below(&ratelimit))
return 0;
xsprintf(header_priority, "<%i>", level);
xsprintf(header_pid, "["PID_FMT"]: ", getpid_cached());
const struct iovec iovec[] = {
IOVEC_MAKE_STRING(header_priority),
IOVEC_MAKE_STRING(program_invocation_short_name),
IOVEC_MAKE_STRING(header_pid),
IOVEC_MAKE_STRING(buffer),
IOVEC_MAKE_STRING("\n"),
};
if (writev(kmsg_fd, iovec, ELEMENTSOF(iovec)) < 0)
return -errno;
return 1;
}
static int log_do_header(
char *header,
size_t size,
int level,
int error,
const char *file, int line, const char *func,
const char *object_field, const char *object,
const char *extra_field, const char *extra) {
int r;
error = IS_SYNTHETIC_ERRNO(error) ? 0 : ERRNO_VALUE(error);
r = snprintf(header, size,
"PRIORITY=%i\n"
"SYSLOG_FACILITY=%i\n"
"TID=" PID_FMT "\n"
"%s%.256s%s" /* CODE_FILE */
"%s%.*i%s" /* CODE_LINE */
"%s%.256s%s" /* CODE_FUNC */
"%s%.*i%s" /* ERRNO */
"%s%.256s%s" /* object */
"%s%.256s%s" /* extra */
"SYSLOG_IDENTIFIER=%.256s\n",
LOG_PRI(level),
LOG_FAC(level),
gettid(),
isempty(file) ? "" : "CODE_FILE=",
isempty(file) ? "" : file,
isempty(file) ? "" : "\n",
line ? "CODE_LINE=" : "",
line ? 1 : 0, line, /* %.0d means no output too, special case for 0 */
line ? "\n" : "",
isempty(func) ? "" : "CODE_FUNC=",
isempty(func) ? "" : func,
isempty(func) ? "" : "\n",
error ? "ERRNO=" : "",
error ? 1 : 0, error,
error ? "\n" : "",
isempty(object) ? "" : object_field,
isempty(object) ? "" : object,
isempty(object) ? "" : "\n",
isempty(extra) ? "" : extra_field,
isempty(extra) ? "" : extra,
isempty(extra) ? "" : "\n",
program_invocation_short_name);
assert_raw((size_t) r < size);
return 0;
}
static int write_to_journal(
int level,
int error,
const char *file,
int line,
const char *func,
const char *object_field,
const char *object,
const char *extra_field,
const char *extra,
const char *buffer) {
char header[LINE_MAX];
if (journal_fd < 0)
return 0;
log_do_header(header, sizeof(header), level, error, file, line, func, object_field, object, extra_field, extra);
struct iovec iovec[4] = {
IOVEC_MAKE_STRING(header),
IOVEC_MAKE_STRING("MESSAGE="),
IOVEC_MAKE_STRING(buffer),
IOVEC_MAKE_STRING("\n"),
};
const struct msghdr msghdr = {
.msg_iov = iovec,
.msg_iovlen = ELEMENTSOF(iovec),
};
if (sendmsg(journal_fd, &msghdr, MSG_NOSIGNAL) < 0)
return -errno;
return 1;
}
int log_dispatch_internal(
int level,
int error,
const char *file,
int line,
const char *func,
const char *object_field,
const char *object,
const char *extra_field,
const char *extra,
char *buffer) {
assert_raw(buffer);
if (log_target == LOG_TARGET_NULL)
return -ERRNO_VALUE(error);
/* Patch in LOG_DAEMON facility if necessary */
if ((level & LOG_FACMASK) == 0)
level |= log_facility;
if (open_when_needed)
(void) log_open();
do {
char *e;
int k = 0;
buffer += strspn(buffer, NEWLINE);
if (buffer[0] == 0)
break;
if ((e = strpbrk(buffer, NEWLINE)))
*(e++) = 0;
if (IN_SET(log_target, LOG_TARGET_AUTO,
LOG_TARGET_JOURNAL_OR_KMSG,
LOG_TARGET_JOURNAL)) {
k = write_to_journal(level, error, file, line, func, object_field, object, extra_field, extra, buffer);
if (k < 0 && k != -EAGAIN)
log_close_journal();
}
if (IN_SET(log_target, LOG_TARGET_SYSLOG_OR_KMSG,
LOG_TARGET_SYSLOG)) {
k = write_to_syslog(level, error, file, line, func, buffer);
if (k < 0 && k != -EAGAIN)
log_close_syslog();
}
if (k <= 0 &&
IN_SET(log_target, LOG_TARGET_AUTO,
LOG_TARGET_SYSLOG_OR_KMSG,
LOG_TARGET_JOURNAL_OR_KMSG,
LOG_TARGET_KMSG)) {
if (k < 0)
log_open_kmsg();
k = write_to_kmsg(level, error, file, line, func, buffer);
if (k < 0) {
log_close_kmsg();
(void) log_open_console();
}
}
if (k <= 0)
(void) write_to_console(level, error, file, line, func, buffer);
buffer = e;
} while (buffer);
if (open_when_needed)
log_close();
return -ERRNO_VALUE(error);
}
int log_dump_internal(
int level,
int error,
const char *file,
int line,
const char *func,
char *buffer) {
PROTECT_ERRNO;
/* This modifies the buffer... */
if (_likely_(LOG_PRI(level) > log_max_level))
return -ERRNO_VALUE(error);
return log_dispatch_internal(level, error, file, line, func, NULL, NULL, NULL, NULL, buffer);
}
int log_internalv(
int level,
int error,
const char *file,
int line,
const char *func,
const char *format,
va_list ap) {
char buffer[LINE_MAX];
PROTECT_ERRNO;
if (_likely_(LOG_PRI(level) > log_max_level))
return -ERRNO_VALUE(error);
/* Make sure that %m maps to the specified error (or "Success"). */
errno = ERRNO_VALUE(error);
(void) vsnprintf(buffer, sizeof buffer, format, ap);
return log_dispatch_internal(level, error, file, line, func, NULL, NULL, NULL, NULL, buffer);
}
int log_internal(
int level,
int error,
const char *file,
int line,
const char *func,
const char *format, ...) {
va_list ap;
int r;
va_start(ap, format);
r = log_internalv(level, error, file, line, func, format, ap);
va_end(ap);
return r;
}
int log_object_internalv(
int level,
int error,
const char *file,
int line,
const char *func,
const char *object_field,
const char *object,
const char *extra_field,
const char *extra,
const char *format,
va_list ap) {
PROTECT_ERRNO;
char *buffer, *b;
if (_likely_(LOG_PRI(level) > log_max_level))
return -ERRNO_VALUE(error);
/* Make sure that %m maps to the specified error (or "Success"). */
errno = ERRNO_VALUE(error);
/* Prepend the object name before the message */
if (object) {
size_t n;
n = strlen(object);
buffer = newa(char, n + 2 + LINE_MAX);
b = stpcpy(stpcpy(buffer, object), ": ");
} else
b = buffer = newa(char, LINE_MAX);
(void) vsnprintf(b, LINE_MAX, format, ap);
return log_dispatch_internal(level, error, file, line, func,
object_field, object, extra_field, extra, buffer);
}
int log_object_internal(
int level,
int error,
const char *file,
int line,
const char *func,
const char *object_field,
const char *object,
const char *extra_field,
const char *extra,
const char *format, ...) {
va_list ap;
int r;
va_start(ap, format);
r = log_object_internalv(level, error, file, line, func, object_field, object, extra_field, extra, 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;
(void) snprintf(buffer, sizeof buffer, format, text, file, line, func);
REENABLE_WARNING;
log_abort_msg = buffer;
log_dispatch_internal(level, 0, file, line, func, NULL, NULL, 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();
}
_noreturn_ void log_assert_failed_unreachable(
const char *file,
int line,
const char *func) {
log_assert(LOG_CRIT, "Code should not be reached", file, line, func,
"%s at %s:%u, function %s(). Aborting. 💥");
abort();
}
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(int level, const char *file, int line, const char *func) {
return log_internal(level, ENOMEM, file, line, func, "Out of memory.");
}
int log_format_iovec(
struct iovec *iovec,
size_t iovec_len,
size_t *n,
bool newline_separator,
int error,
const char *format,
va_list ap) {
static const char nl = '\n';
while (format && *n + 1 < iovec_len) {
va_list aq;
char *m;
int r;
/* We need to copy the va_list structure,
* since vasprintf() leaves it afterwards at
* an undefined location */
errno = ERRNO_VALUE(error);
va_copy(aq, ap);
r = vasprintf(&m, format, aq);
va_end(aq);
if (r < 0)
return -EINVAL;
/* Now, jump enough ahead, so that we point to
* the next format string */
VA_FORMAT_ADVANCE(format, ap);
iovec[(*n)++] = IOVEC_MAKE_STRING(m);
if (newline_separator)
iovec[(*n)++] = IOVEC_MAKE((char *)&nl, 1);
format = va_arg(ap, char *);
}
return 0;
}
int log_struct_internal(
int level,
int error,
const char *file,
int line,
const char *func,
const char *format, ...) {
char buf[LINE_MAX];
bool found = false;
PROTECT_ERRNO;
va_list ap;
if (_likely_(LOG_PRI(level) > log_max_level) ||
log_target == LOG_TARGET_NULL)
return -ERRNO_VALUE(error);
if ((level & LOG_FACMASK) == 0)
level |= log_facility;
if (IN_SET(log_target,
LOG_TARGET_AUTO,
LOG_TARGET_JOURNAL_OR_KMSG,
LOG_TARGET_JOURNAL)) {
if (open_when_needed)
log_open_journal();
if (journal_fd >= 0) {
char header[LINE_MAX];
struct iovec iovec[17];
size_t n = 0;
int r;
bool fallback = false;
/* If the journal is available do structured logging.
* Do not report the errno if it is synthetic. */
log_do_header(header, sizeof(header), level, error, file, line, func, NULL, NULL, NULL, NULL);
iovec[n++] = IOVEC_MAKE_STRING(header);
va_start(ap, format);
r = log_format_iovec(iovec, ELEMENTSOF(iovec), &n, true, error, format, ap);
if (r < 0)
fallback = true;
else {
const struct msghdr msghdr = {
.msg_iov = iovec,
.msg_iovlen = n,
};
(void) sendmsg(journal_fd, &msghdr, MSG_NOSIGNAL);
}
va_end(ap);
for (size_t i = 1; i < n; i += 2)
free(iovec[i].iov_base);
if (!fallback) {
if (open_when_needed)
log_close();
return -ERRNO_VALUE(error);
}
}
}
/* Fallback if journal logging is not available or didn't work. */
va_start(ap, format);
while (format) {
va_list aq;
errno = ERRNO_VALUE(error);
va_copy(aq, ap);
(void) vsnprintf(buf, sizeof buf, format, aq);
va_end(aq);
if (startswith(buf, "MESSAGE=")) {
found = true;
break;
}
VA_FORMAT_ADVANCE(format, ap);
format = va_arg(ap, char *);
}
va_end(ap);
if (!found) {
if (open_when_needed)
log_close();
return -ERRNO_VALUE(error);
}
return log_dispatch_internal(level, error, file, line, func, NULL, NULL, NULL, NULL, buf + 8);
}
int log_struct_iovec_internal(
int level,
int error,
const char *file,
int line,
const char *func,
const struct iovec input_iovec[],
size_t n_input_iovec) {
PROTECT_ERRNO;
if (_likely_(LOG_PRI(level) > log_max_level) ||
log_target == LOG_TARGET_NULL)
return -ERRNO_VALUE(error);
if ((level & LOG_FACMASK) == 0)
level |= log_facility;
if (IN_SET(log_target, LOG_TARGET_AUTO,
LOG_TARGET_JOURNAL_OR_KMSG,
LOG_TARGET_JOURNAL) &&
journal_fd >= 0) {
char header[LINE_MAX];
log_do_header(header, sizeof(header), level, error, file, line, func, NULL, NULL, NULL, NULL);
struct iovec iovec[1 + n_input_iovec*2];
iovec[0] = IOVEC_MAKE_STRING(header);
for (size_t i = 0; i < n_input_iovec; i++) {
iovec[1+i*2] = input_iovec[i];
iovec[1+i*2+1] = IOVEC_MAKE_STRING("\n");
}
const struct msghdr msghdr = {
.msg_iov = iovec,
.msg_iovlen = 1 + n_input_iovec*2,
};
if (sendmsg(journal_fd, &msghdr, MSG_NOSIGNAL) >= 0)
return -ERRNO_VALUE(error);
}
for (size_t i = 0; i < n_input_iovec; i++)
if (memory_startswith(input_iovec[i].iov_base, input_iovec[i].iov_len, "MESSAGE=")) {
char *m;
m = strndupa_safe((char*) input_iovec[i].iov_base + STRLEN("MESSAGE="),
input_iovec[i].iov_len - STRLEN("MESSAGE="));
return log_dispatch_internal(level, error, file, line, func, NULL, NULL, NULL, NULL, m);
}
/* Couldn't find MESSAGE=. */
return -ERRNO_VALUE(error);
}
int log_set_target_from_string(const char *e) {
LogTarget t;
t = log_target_from_string(e);
if (t < 0)
return t;
log_set_target(t);
return 0;
}
int log_set_max_level_from_string(const char *e) {
int t;
t = log_level_from_string(e);
if (t < 0)
return t;
log_set_max_level(t);
return 0;
}
static int parse_proc_cmdline_item(const char *key, const char *value, void *data) {
/*
* The systemd.log_xyz= settings are parsed by all tools, and
* so is "debug".
*
* However, "quiet" is only parsed by PID 1, and only turns of
* status output to /dev/console, but does not alter the log
* level.
*/
if (streq(key, "debug") && !value)
log_set_max_level(LOG_DEBUG);
else if (proc_cmdline_key_streq(key, "systemd.log_target")) {
if (proc_cmdline_value_missing(key, value))
return 0;
if (log_set_target_from_string(value) < 0)
log_warning("Failed to parse log target '%s'. Ignoring.", value);
} else if (proc_cmdline_key_streq(key, "systemd.log_level")) {
if (proc_cmdline_value_missing(key, value))
return 0;
if (log_set_max_level_from_string(value) < 0)
log_warning("Failed to parse log level '%s'. Ignoring.", value);
} else if (proc_cmdline_key_streq(key, "systemd.log_color")) {
if (log_show_color_from_string(value ?: "1") < 0)
log_warning("Failed to parse log color setting '%s'. Ignoring.", value);
} else if (proc_cmdline_key_streq(key, "systemd.log_location")) {
if (log_show_location_from_string(value ?: "1") < 0)
log_warning("Failed to parse log location setting '%s'. Ignoring.", value);
} else if (proc_cmdline_key_streq(key, "systemd.log_tid")) {
if (log_show_tid_from_string(value ?: "1") < 0)
log_warning("Failed to parse log tid setting '%s'. Ignoring.", value);
} else if (proc_cmdline_key_streq(key, "systemd.log_time")) {
if (log_show_time_from_string(value ?: "1") < 0)
log_warning("Failed to parse log time setting '%s'. Ignoring.", value);
}
return 0;
}
static bool should_parse_proc_cmdline(void) {
const char *e;
pid_t p;
/* PID1 always reads the kernel command line. */
if (getpid_cached() == 1)
return true;
/* If the process is directly executed by PID1 (e.g. ExecStart= or generator), systemd-importd,
* or systemd-homed, then $SYSTEMD_EXEC_PID= is set, and read the command line. */
e = getenv("SYSTEMD_EXEC_PID");
if (!e)
return false;
if (streq(e, "*"))
/* For testing. */
return true;
if (parse_pid(e, &p) < 0) {
/* We know that systemd sets the variable correctly. Something else must have set it. */
log_debug("Failed to parse \"$SYSTEMD_EXEC_PID=%s\". Ignoring.", e);
return false;
}
return getpid_cached() == p;
}
void log_parse_environment(void) {
const char *e;
/* Do not call from library code. */
if (should_parse_proc_cmdline())
(void) proc_cmdline_parse(parse_proc_cmdline_item, NULL, PROC_CMDLINE_STRIP_RD_PREFIX);
e = getenv("SYSTEMD_LOG_TARGET");
if (e && log_set_target_from_string(e) < 0)
log_warning("Failed to parse log target '%s'. Ignoring.", e);
e = 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 = getenv("SYSTEMD_LOG_COLOR");
if (e && log_show_color_from_string(e) < 0)
log_warning("Failed to parse log color '%s'. Ignoring.", e);
e = getenv("SYSTEMD_LOG_LOCATION");
if (e && log_show_location_from_string(e) < 0)
log_warning("Failed to parse log location '%s'. Ignoring.", e);
e = getenv("SYSTEMD_LOG_TIME");
if (e && log_show_time_from_string(e) < 0)
log_warning("Failed to parse log time '%s'. Ignoring.", e);
e = getenv("SYSTEMD_LOG_TID");
if (e && log_show_tid_from_string(e) < 0)
log_warning("Failed to parse log tid '%s'. Ignoring.", e);
}
LogTarget log_get_target(void) {
return log_target;
}
int log_get_max_level(void) {
return log_max_level;
}
void log_show_color(bool b) {
show_color = b;
}
bool log_get_show_color(void) {
return show_color > 0; /* Defaults to false. */
}
void log_show_location(bool b) {
show_location = b;
}
bool log_get_show_location(void) {
return show_location;
}
void log_show_time(bool b) {
show_time = b;
}
bool log_get_show_time(void) {
return show_time;
}
void log_show_tid(bool b) {
show_tid = b;
}
bool log_get_show_tid(void) {
return show_tid;
}
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;
}
int log_show_time_from_string(const char *e) {
int t;
t = parse_boolean(e);
if (t < 0)
return t;
log_show_time(t);
return 0;
}
int log_show_tid_from_string(const char *e) {
int t;
t = parse_boolean(e);
if (t < 0)
return t;
log_show_tid(t);
return 0;
}
bool log_on_console(void) {
if (IN_SET(log_target, LOG_TARGET_CONSOLE,
LOG_TARGET_CONSOLE_PREFIXED))
return true;
return syslog_fd < 0 && kmsg_fd < 0 && journal_fd < 0;
}
static const char *const log_target_table[_LOG_TARGET_MAX] = {
[LOG_TARGET_CONSOLE] = "console",
[LOG_TARGET_CONSOLE_PREFIXED] = "console-prefixed",
[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);
void log_received_signal(int level, const struct signalfd_siginfo *si) {
assert(si);
if (pid_is_valid(si->ssi_pid)) {
_cleanup_free_ char *p = NULL;
(void) get_process_comm(si->ssi_pid, &p);
log_full(level,
"Received SIG%s from PID %"PRIu32" (%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));
}
void set_log_syntax_callback(log_syntax_callback_t cb, void *userdata) {
assert(!log_syntax_callback || !cb);
assert(!log_syntax_callback_userdata || !userdata);
log_syntax_callback = cb;
log_syntax_callback_userdata = userdata;
}
int log_syntax_internal(
const char *unit,
int level,
const char *config_file,
unsigned config_line,
int error,
const char *file,
int line,
const char *func,
const char *format, ...) {
if (log_syntax_callback)
log_syntax_callback(unit, level, log_syntax_callback_userdata);
PROTECT_ERRNO;
char buffer[LINE_MAX];
va_list ap;
const char *unit_fmt = NULL;
if (_likely_(LOG_PRI(level) > log_max_level) ||
log_target == LOG_TARGET_NULL)
return -ERRNO_VALUE(error);
errno = ERRNO_VALUE(error);
va_start(ap, format);
(void) vsnprintf(buffer, sizeof buffer, format, ap);
va_end(ap);
if (unit)
unit_fmt = getpid_cached() == 1 ? "UNIT=%s" : "USER_UNIT=%s";
if (config_file) {
if (config_line > 0)
return log_struct_internal(
level,
error,
file, line, func,
"MESSAGE_ID=" SD_MESSAGE_INVALID_CONFIGURATION_STR,
"CONFIG_FILE=%s", config_file,
"CONFIG_LINE=%u", config_line,
LOG_MESSAGE("%s:%u: %s", config_file, config_line, buffer),
unit_fmt, unit,
NULL);
else
return log_struct_internal(
level,
error,
file, line, func,
"MESSAGE_ID=" SD_MESSAGE_INVALID_CONFIGURATION_STR,
"CONFIG_FILE=%s", config_file,
LOG_MESSAGE("%s: %s", config_file, buffer),
unit_fmt, unit,
NULL);
} else if (unit)
return log_struct_internal(
level,
error,
file, line, func,
"MESSAGE_ID=" SD_MESSAGE_INVALID_CONFIGURATION_STR,
LOG_MESSAGE("%s: %s", unit, buffer),
unit_fmt, unit,
NULL);
else
return log_struct_internal(
level,
error,
file, line, func,
"MESSAGE_ID=" SD_MESSAGE_INVALID_CONFIGURATION_STR,
LOG_MESSAGE("%s", buffer),
NULL);
}
int log_syntax_invalid_utf8_internal(
const char *unit,
int level,
const char *config_file,
unsigned config_line,
const char *file,
int line,
const char *func,
const char *rvalue) {
_cleanup_free_ char *p = NULL;
if (rvalue)
p = utf8_escape_invalid(rvalue);
return log_syntax_internal(unit, level, config_file, config_line,
SYNTHETIC_ERRNO(EINVAL), file, line, func,
"String is not UTF-8 clean, ignoring assignment: %s", strna(p));
}
void log_set_upgrade_syslog_to_journal(bool b) {
upgrade_syslog_to_journal = b;
/* Make the change effective immediately */
if (b) {
if (log_target == LOG_TARGET_SYSLOG)
log_target = LOG_TARGET_JOURNAL;
else if (log_target == LOG_TARGET_SYSLOG_OR_KMSG)
log_target = LOG_TARGET_JOURNAL_OR_KMSG;
}
}
void log_set_always_reopen_console(bool b) {
always_reopen_console = b;
}
void log_set_open_when_needed(bool b) {
open_when_needed = b;
}
void log_set_prohibit_ipc(bool b) {
prohibit_ipc = b;
}
int log_emergency_level(void) {
/* Returns the log level to use for log_emergency() logging. We use LOG_EMERG only when we are PID 1, as only
* then the system of the whole system is obviously affected. */
return getpid_cached() == 1 ? LOG_EMERG : LOG_ERR;
}
int log_dup_console(void) {
int copy;
/* Duplicate the fd we use for fd logging if it's < 3 and use the copy from now on. This call is useful
* whenever we want to continue logging through the original fd, but want to rearrange stderr. */
if (console_fd >= 3)
return 0;
copy = fcntl(console_fd, F_DUPFD_CLOEXEC, 3);
if (copy < 0)
return -errno;
console_fd = copy;
return 0;
}
void log_setup(void) {
log_set_target(LOG_TARGET_AUTO);
log_parse_environment();
(void) log_open();
if (log_on_console() && show_color < 0)
log_show_color(true);
}
Reference in New Issue View Git Blame Copy Permalink