SymbX/systemd
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity
Files
a3b00f91bb985fa10bc33db5c7883e33dbdf83d0
systemd/src/basic/log.c
T
Daan De Meyer a3b00f91bb core: Settle log target if we're going to be closing all fds 
Whenever we're going to close all file descriptors, we tend to close
the log and set it into open when needed mode. When this is done with
the logging target set to LOG_TARGET_AUTO, we run into issues because
for every logging call, we'll check if stderr is connected to the
journal to determine where to send the logging message. This check
obviously stops working when we close stderr, so we settle the log
target before we do that so that we keep using the same logging
target even after stderr is closed.
2023-03-22 13:20:08 +01:00

1676 lines
51 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 "argv-util.h"
#include "env-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 "missing_threads.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 "strv.h"
#include "syslog-util.h"
#include "terminal-util.h"
#include "time-util.h"
#include "utf8.h"
#define SNDBUF_SIZE (8*1024*1024)
#define IOVEC_MAX 128U
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 = -EBADF;
static int kmsg_fd = -EBADF;
static int journal_fd = -EBADF;
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;
typedef struct LogContext {
/* Depending on which destructor is used (log_context_free() or log_context_detach()) the memory
* referenced by this is freed or not */
char **fields;
struct iovec *input_iovec;
size_t n_input_iovec;
bool owned;
LIST_FIELDS(struct LogContext, ll);
} LogContext;
static thread_local LIST_HEAD(LogContext, _log_context) = NULL;
static thread_local size_t _log_context_num_fields = 0;
#if LOG_MESSAGE_VERIFICATION || defined(__COVERITY__)
bool _log_message_dummy = false; /* Always false */
#endif
/* 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) {
int r;
if (syslog_fd >= 0)
return 0;
syslog_fd = create_log_socket(SOCK_DGRAM);
if (syslog_fd < 0) {
r = syslog_fd;
goto fail;
}
r = connect_unix_path(syslog_fd, AT_FDCWD, "/dev/log");
if (r < 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;
}
r = connect_unix_path(syslog_fd, AT_FDCWD, "/dev/log");
if (r < 0)
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) {
int r;
if (journal_fd >= 0)
return 0;
journal_fd = create_log_socket(SOCK_DGRAM);
if (journal_fd < 0) {
r = journal_fd;
goto fail;
}
r = connect_unix_path(journal_fd, AT_FDCWD, "/run/systemd/journal/socket");
if (r < 0)
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_set_target_and_open(LogTarget target) {
log_set_target(target);
log_open();
}
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 = -EBADF;
}
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 void log_do_context(struct iovec *iovec, size_t iovec_len, size_t *n) {
assert(iovec);
assert(n);
LIST_FOREACH(ll, c, _log_context) {
STRV_FOREACH(s, c->fields) {
if (*n + 2 >= iovec_len)
return;
iovec[(*n)++] = IOVEC_MAKE_STRING(*s);
iovec[(*n)++] = IOVEC_MAKE_STRING("\n");
}
for (size_t i = 0; i < c->n_input_iovec; i++) {
if (*n + 2 >= iovec_len)
return;
iovec[(*n)++] = c->input_iovec[i];
iovec[(*n)++] = IOVEC_MAKE_STRING("\n");
}
}
}
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];
size_t n = 0, iovec_len;
struct iovec *iovec;
if (journal_fd < 0)
return 0;
iovec_len = MIN(4 + _log_context_num_fields * 2, IOVEC_MAX);
iovec = newa(struct iovec, iovec_len);
log_do_header(header, sizeof(header), level, error, file, line, func, object_field, object, extra_field, extra);
iovec[n++] = IOVEC_MAKE_STRING(header);
iovec[n++] = IOVEC_MAKE_STRING("MESSAGE=");
iovec[n++] = IOVEC_MAKE_STRING(buffer);
iovec[n++] = IOVEC_MAKE_STRING("\n");
log_do_context(iovec, iovec_len, &n);
const struct msghdr msghdr = {
.msg_iov = iovec,
.msg_iovlen = n,
};
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) {
if (_likely_(LOG_PRI(level) > log_max_level))
return -ERRNO_VALUE(error);
/* Make sure that %m maps to the specified error (or "Success"). */
char buffer[LINE_MAX];
LOCAL_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) {
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"). */
LOCAL_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;
size_t n = 0, m, iovec_len;
int r;
bool fallback = false;
iovec_len = MIN(17 + _log_context_num_fields * 2, IOVEC_MAX);
iovec = newa(struct iovec, iovec_len);
/* 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, iovec_len, &n, true, error, format, ap);
m = n;
if (r < 0)
fallback = true;
else {
log_do_context(iovec, iovec_len, &n);
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 < m; 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];
struct iovec *iovec;
size_t n = 0, iovec_len;
iovec_len = MIN(1 + n_input_iovec * 2 + _log_context_num_fields * 2, IOVEC_MAX);
iovec = newa(struct iovec, iovec_len);
log_do_header(header, sizeof(header), level, error, file, line, func, NULL, NULL, NULL, NULL);
iovec[n++] = IOVEC_MAKE_STRING(header);
for (size_t i = 0; i < n_input_iovec; i++) {
iovec[n++] = input_iovec[i];
iovec[n++] = IOVEC_MAKE_STRING("\n");
}
log_do_context(iovec, iovec_len, &n);
const struct msghdr msghdr = {
.msg_iov = iovec,
.msg_iovlen = n,
};
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) {
/* PID1 always reads the kernel command line. */
if (getpid_cached() == 1)
return true;
/* Otherwise, parse the commandline if invoked directly by systemd. */
return invoked_by_systemd();
}
void log_parse_environment_variables(void) {
const char *e;
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);
}
void log_parse_environment(void) {
/* 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);
log_parse_environment_variables();
}
LogTarget log_get_target(void) {
return log_target;
}
void log_settle_target(void) {
/* If we're using LOG_TARGET_AUTO and opening the log again on every single log call, we'll check if
* stderr is attached to the journal every single log call. However, if we then close all file
* descriptors later, that will stop working because stderr will be closed as well. To avoid that
* problem, this function is used to permanently change the log target depending on whether stderr is
* connected to the journal or not. */
LogTarget t = log_get_target();
if (t != LOG_TARGET_AUTO)
return;
t = getpid_cached() == 1 || stderr_is_journal() ? (prohibit_ipc ? LOG_TARGET_KMSG : LOG_TARGET_JOURNAL_OR_KMSG)
: LOG_TARGET_CONSOLE;
log_set_target(t);
}
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, ...) {
PROTECT_ERRNO;
if (log_syntax_callback)
log_syntax_callback(unit, level, log_syntax_callback_userdata);
if (_likely_(LOG_PRI(level) > log_max_level) ||
log_target == LOG_TARGET_NULL)
return -ERRNO_VALUE(error);
char buffer[LINE_MAX];
va_list ap;
const char *unit_fmt = NULL;
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 < 0 || 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);
}
static int saved_log_context_enabled = -1;
bool log_context_enabled(void) {
int r;
if (log_get_max_level() == LOG_DEBUG)
return true;
if (saved_log_context_enabled >= 0)
return saved_log_context_enabled;
r = getenv_bool_secure("SYSTEMD_ENABLE_LOG_CONTEXT");
if (r < 0 && r != -ENXIO)
log_debug_errno(r, "Failed to parse $SYSTEMD_ENABLE_LOG_CONTEXT, ignoring: %m");
saved_log_context_enabled = r > 0;
return saved_log_context_enabled;
}
LogContext* log_context_attach(LogContext *c) {
assert(c);
_log_context_num_fields += strv_length(c->fields);
_log_context_num_fields += c->n_input_iovec;
return LIST_PREPEND(ll, _log_context, c);
}
LogContext* log_context_detach(LogContext *c) {
if (!c)
return NULL;
assert(_log_context_num_fields >= strv_length(c->fields) + c->n_input_iovec);
_log_context_num_fields -= strv_length(c->fields);
_log_context_num_fields -= c->n_input_iovec;
LIST_REMOVE(ll, _log_context, c);
return NULL;
}
LogContext* log_context_new(char **fields, bool owned) {
LogContext *c = new(LogContext, 1);
if (!c)
return NULL;
*c = (LogContext) {
.fields = fields,
.owned = owned,
};
return log_context_attach(c);
}
LogContext* log_context_newv(struct iovec *input_iovec, size_t n_input_iovec, bool owned) {
if (!input_iovec || n_input_iovec == 0)
return NULL; /* Nothing to do */
LogContext *c = new(LogContext, 1);
if (!c)
return NULL;
*c = (LogContext) {
.input_iovec = input_iovec,
.n_input_iovec = n_input_iovec,
.owned = owned,
};
return log_context_attach(c);
}
LogContext* log_context_free(LogContext *c) {
if (!c)
return NULL;
log_context_detach(c);
if (c->owned) {
strv_free(c->fields);
iovec_array_free(c->input_iovec, c->n_input_iovec);
}
return mfree(c);
}
LogContext* log_context_new_consume(char **fields) {
LogContext *c = log_context_new(fields, /*owned=*/ true);
if (!c)
strv_free(fields);
return c;
}
LogContext* log_context_new_consumev(struct iovec *input_iovec, size_t n_input_iovec) {
LogContext *c = log_context_newv(input_iovec, n_input_iovec, /*owned=*/ true);
if (!c)
iovec_array_free(input_iovec, n_input_iovec);
return c;
}
size_t log_context_num_contexts(void) {
size_t n = 0;
LIST_FOREACH(ll, c, _log_context)
n++;
return n;
}
size_t log_context_num_fields(void) {
return _log_context_num_fields;
}
Reference in New Issue View Git Blame Copy Permalink