Merge pull request #23309 from DaanDeMeyer/log-context

basic: Add log context
This commit is contained in:
Luca Boccassi
2023-01-20 15:01:03 +00:00
committed by GitHub
22 changed files with 528 additions and 96 deletions
+35 -36
View File
@@ -1,8 +1,6 @@
/* SPDX-License-Identifier: LGPL-2.1-or-later */
#pragma once
#include "macro.h"
/* The head of the linked list. Use this in the structure that shall
* contain the head of the linked list */
#define LIST_HEAD(t,name) \
@@ -28,26 +26,27 @@
/* Prepend an item to the list */
#define LIST_PREPEND(name,head,item) \
do { \
({ \
typeof(*(head)) **_head = &(head), *_item = (item); \
assert(_item); \
if ((_item->name##_next = *_head)) \
_item->name##_next->name##_prev = _item; \
_item->name##_prev = NULL; \
*_head = _item; \
} while (false)
_item; \
})
/* Append an item to the list */
#define LIST_APPEND(name,head,item) \
do { \
({ \
typeof(*(head)) **_hhead = &(head), *_tail; \
LIST_FIND_TAIL(name, *_hhead, _tail); \
_tail = LIST_FIND_TAIL(name, *_hhead); \
LIST_INSERT_AFTER(name, *_hhead, _tail, item); \
} while (false)
})
/* Remove an item from the list */
#define LIST_REMOVE(name,head,item) \
do { \
({ \
typeof(*(head)) **_head = &(head), *_item = (item); \
assert(_item); \
if (_item->name##_next) \
@@ -59,37 +58,30 @@
*_head = _item->name##_next; \
} \
_item->name##_next = _item->name##_prev = NULL; \
} while (false)
_item; \
})
/* Find the head of the list */
#define LIST_FIND_HEAD(name,item,head) \
do { \
#define LIST_FIND_HEAD(name,item) \
({ \
typeof(*(item)) *_item = (item); \
if (!_item) \
(head) = NULL; \
else { \
while (_item->name##_prev) \
_item = _item->name##_prev; \
(head) = _item; \
} \
} while (false)
while (_item && _item->name##_prev) \
_item = _item->name##_prev; \
_item; \
})
/* Find the tail of the list */
#define LIST_FIND_TAIL(name,item,tail) \
do { \
#define LIST_FIND_TAIL(name,item) \
({ \
typeof(*(item)) *_item = (item); \
if (!_item) \
(tail) = NULL; \
else { \
while (_item->name##_next) \
_item = _item->name##_next; \
(tail) = _item; \
} \
} while (false)
while (_item && _item->name##_next) \
_item = _item->name##_next; \
_item; \
})
/* Insert an item after another one (a = where, b = what) */
#define LIST_INSERT_AFTER(name,head,a,b) \
do { \
({ \
typeof(*(head)) **_head = &(head), *_a = (a), *_b = (b); \
assert(_b); \
if (!_a) { \
@@ -103,11 +95,12 @@
_b->name##_prev = _a; \
_a->name##_next = _b; \
} \
} while (false)
_b; \
})
/* Insert an item before another one (a = where, b = what) */
#define LIST_INSERT_BEFORE(name,head,a,b) \
do { \
({ \
typeof(*(head)) **_head = &(head), *_a = (a), *_b = (b); \
assert(_b); \
if (!_a) { \
@@ -131,7 +124,8 @@
_b->name##_next = _a; \
_a->name##_prev = _b; \
} \
} while (false)
_b; \
})
#define LIST_JUST_US(name,item) \
(!(item)->name##_prev && !(item)->name##_next)
@@ -172,18 +166,19 @@
/* Join two lists tail to head: a->b, c->d to a->b->c->d and de-initialise second list */
#define LIST_JOIN(name,a,b) \
do { \
({ \
assert(b); \
if (!(a)) \
(a) = (b); \
else { \
typeof(*(a)) *_head = (b), *_tail; \
LIST_FIND_TAIL(name, (a), _tail); \
_tail = LIST_FIND_TAIL(name, (a)); \
_tail->name##_next = _head; \
_head->name##_prev = _tail; \
} \
(b) = NULL; \
} while (false)
a; \
})
#define LIST_POP(name, a) \
({ \
@@ -193,3 +188,7 @@
LIST_REMOVE(name, *_a, _p); \
_p; \
})
/* Now include "macro.h", because we want our definition of assert() which the macros above use. We include
* it down here instead of up top, since macro.h pulls in log.h which in turn needs our own definitions. */
#include "macro.h"
+148 -16
View File
@@ -17,6 +17,7 @@
#include "alloc-util.h"
#include "argv-util.h"
#include "env-util.h"
#include "errno-util.h"
#include "fd-util.h"
#include "format-util.h"
@@ -33,12 +34,14 @@
#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;
@@ -68,6 +71,17 @@ static bool prohibit_ipc = false;
* 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;
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
@@ -589,6 +603,20 @@ static int log_do_header(
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");
}
}
static int write_to_journal(
int level,
int error,
@@ -602,21 +630,27 @@ static int write_to_journal(
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);
struct iovec iovec[4] = {
IOVEC_MAKE_STRING(header),
IOVEC_MAKE_STRING("MESSAGE="),
IOVEC_MAKE_STRING(buffer),
IOVEC_MAKE_STRING("\n"),
};
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 = ELEMENTSOF(iovec),
.msg_iovlen = n,
};
if (sendmsg(journal_fd, &msghdr, MSG_NOSIGNAL) < 0)
@@ -948,21 +982,27 @@ int log_struct_internal(
if (journal_fd >= 0) {
char header[LINE_MAX];
struct iovec iovec[17];
size_t n = 0;
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, ELEMENTSOF(iovec), &n, true, error, format, ap);
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,
@@ -972,7 +1012,7 @@ int log_struct_internal(
}
va_end(ap);
for (size_t i = 1; i < n; i += 2)
for (size_t i = 1; i < m; i += 2)
free(iovec[i].iov_base);
if (!fallback) {
@@ -1041,18 +1081,25 @@ int log_struct_iovec_internal(
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);
struct iovec iovec[1 + n_input_iovec*2];
iovec[0] = IOVEC_MAKE_STRING(header);
iovec[n++] = 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");
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 = 1 + n_input_iovec*2,
.msg_iovlen = n,
};
if (sendmsg(journal_fd, &msghdr, MSG_NOSIGNAL) >= 0)
@@ -1477,3 +1524,88 @@ void log_setup(void) {
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);
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));
_log_context_num_fields -= strv_length(c->fields);
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_free(LogContext *c) {
if (!c)
return NULL;
log_context_detach(c);
if (c->owned)
strv_free(c->fields);
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;
}
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;
}
+82
View File
@@ -7,8 +7,10 @@
#include <string.h>
#include <syslog.h>
#include "list.h"
#include "macro.h"
#include "ratelimit.h"
#include "stdio-util.h"
/* Some structures we reference but don't want to pull in headers for */
struct iovec;
@@ -420,3 +422,83 @@ typedef struct LogRateLimit {
#define log_ratelimit_warning_errno(error, ...) log_ratelimit_full_errno(LOG_WARNING, error, __VA_ARGS__)
#define log_ratelimit_error_errno(error, ...) log_ratelimit_full_errno(LOG_ERR, error, __VA_ARGS__)
#define log_ratelimit_emergency_errno(error, ...) log_ratelimit_full_errno(log_emergency_level(), error, __VA_ARGS__)
/*
* The log context allows attaching extra metadata to log messages written to the journal via log.h. We keep
* track of a thread local log context onto which we can push extra metadata fields that should be logged.
*
* LOG_CONTEXT_PUSH() will add the provided field to the log context and will remove it again when the
* current block ends. LOG_CONTEXT_PUSH_STRV() will do the same but for all fields in the given strv.
* LOG_CONTEXT_PUSHF() is like LOG_CONTEXT_PUSH() but takes a format string and arguments.
*
* Using the macros is as simple as putting them anywhere inside a block to add a field to all following log
* messages logged from inside that block.
*
* void myfunction(...) {
* ...
*
* LOG_CONTEXT_PUSHF("MYMETADATA=%s", "abc");
*
* // Every journal message logged will now have the MYMETADATA=abc
* // field included.
* }
*
* One special case to note is async code, where we use callbacks that are invoked to continue processing
* when some event occurs. For async code, there's usually an associated "userdata" struct containing all the
* information associated with the async operation. In this "userdata" struct, we can store a log context
* allocated with log_context_new() and freed with log_context_free(). We can then add and remove fields to
* the `fields` member of the log context object and all those fields will be logged along with each log
* message.
*/
typedef struct LogContext LogContext;
bool log_context_enabled(void);
LogContext* log_context_attach(LogContext *c);
LogContext* log_context_detach(LogContext *c);
LogContext* log_context_new(char **fields, bool owned);
LogContext* log_context_free(LogContext *c);
/* Same as log_context_new(), but frees the given fields strv on failure. */
LogContext* log_context_new_consume(char **fields);
/* Returns the number of attached log context objects. */
size_t log_context_num_contexts(void);
/* Returns the number of fields in all attached log contexts. */
size_t log_context_num_fields(void);
DEFINE_TRIVIAL_CLEANUP_FUNC(LogContext*, log_context_detach);
DEFINE_TRIVIAL_CLEANUP_FUNC(LogContext*, log_context_free);
#define LOG_CONTEXT_PUSH(...) \
LOG_CONTEXT_PUSH_STRV(STRV_MAKE(__VA_ARGS__))
#define LOG_CONTEXT_PUSHF(...) \
LOG_CONTEXT_PUSH(snprintf_ok((char[LINE_MAX]) {}, LINE_MAX, __VA_ARGS__))
#define _LOG_CONTEXT_PUSH_STRV(strv, c) \
_unused_ _cleanup_(log_context_freep) LogContext *c = log_context_new(strv, /*owned=*/ false);
#define LOG_CONTEXT_PUSH_STRV(strv) \
_LOG_CONTEXT_PUSH_STRV(strv, UNIQ_T(c, UNIQ))
/* LOG_CONTEXT_CONSUME_STR()/LOG_CONTEXT_CONSUME_STRV() are identical to
* LOG_CONTEXT_PUSH_STR()/LOG_CONTEXT_PUSH_STRV() except they take ownership of the given str/strv argument.
*/
#define _LOG_CONTEXT_CONSUME_STR(s, c, strv) \
_unused_ _cleanup_strv_free_ strv = strv_new(s); \
if (!strv) \
free(s); \
_unused_ _cleanup_(log_context_freep) LogContext *c = log_context_new_consume(TAKE_PTR(strv))
#define LOG_CONTEXT_CONSUME_STR(s) \
_LOG_CONTEXT_CONSUME_STR(s, UNIQ_T(c, UNIQ), UNIQ_T(sv, UNIQ))
#define _LOG_CONTEXT_CONSUME_STRV(strv, c) \
_unused_ _cleanup_(log_context_freep) LogContext *c = log_context_new_consume(strv);
#define LOG_CONTEXT_CONSUME_STRV(strv) \
_LOG_CONTEXT_CONSUME_STRV(strv, UNIQ_T(c, UNIQ))
+14 -9
View File
@@ -7,15 +7,20 @@
#include <sys/types.h>
#include "macro.h"
#include "memory-util.h"
#define snprintf_ok(buf, len, fmt, ...) \
({ \
char *_buf = (buf); \
size_t _len = (len); \
int _snpf = snprintf(_buf, _len, (fmt), ##__VA_ARGS__); \
_snpf >= 0 && (size_t) _snpf < _len ? _buf : NULL; \
})
_printf_(3, 4)
static inline char *snprintf_ok(char *buf, size_t len, const char *format, ...) {
va_list ap;
int r;
va_start(ap, format);
DISABLE_WARNING_FORMAT_NONLITERAL;
r = vsnprintf(buf, len, format, ap);
REENABLE_WARNING;
va_end(ap);
return r >= 0 && (size_t) r < len ? buf : NULL;
}
#define xsprintf(buf, fmt, ...) \
assert_message_se(snprintf_ok(buf, ELEMENTSOF(buf), fmt, ##__VA_ARGS__), "xsprintf: " #buf "[] must be big enough")
@@ -26,7 +31,7 @@ do { \
size_t _i, _k; \
/* See https://github.com/google/sanitizers/issues/992 */ \
if (HAS_FEATURE_MEMORY_SANITIZER) \
zero(_argtypes); \
memset(_argtypes, 0, sizeof(_argtypes)); \
_k = parse_printf_format((format), ELEMENTSOF(_argtypes), _argtypes); \
assert(_k < ELEMENTSOF(_argtypes)); \
for (_i = 0; _i < _k; _i++) { \
+16
View File
@@ -789,6 +789,22 @@ rollback:
return -ENOMEM;
}
int strv_extend_assignment(char ***l, const char *lhs, const char *rhs) {
char *j;
assert(l);
assert(lhs);
if (!rhs) /* value is optional, in which case we suppress the field */
return 0;
j = strjoin(lhs, "=", rhs);
if (!j)
return -ENOMEM;
return strv_consume(l, j);
}
int fputstrv(FILE *f, char * const *l, const char *separator, bool *space) {
bool b = false;
int r;
+2
View File
@@ -241,6 +241,8 @@ char** strv_skip(char **l, size_t n);
int strv_extend_n(char ***l, const char *value, size_t n);
int strv_extend_assignment(char ***l, const char *lhs, const char *rhs);
int fputstrv(FILE *f, char * const *l, const char *separator, bool *space);
#define strv_free_and_replace(a, b) \