Merge pull request #26916 from DaanDeMeyer/log-context-ref

log: Avoid pushing the same fields more than once on the log context
This commit is contained in:
Daan De Meyer
2023-03-22 22:07:45 +01:00
committed by GitHub
7 changed files with 128 additions and 41 deletions

View File

@@ -42,7 +42,7 @@
#include "utf8.h"
#define SNDBUF_SIZE (8*1024*1024)
#define IOVEC_MAX 128U
#define IOVEC_MAX 256U
static log_syntax_callback_t log_syntax_callback = NULL;
static void *log_syntax_callback_userdata = NULL;
@@ -73,11 +73,14 @@ static bool prohibit_ipc = false;
static char *log_abort_msg = NULL;
typedef struct LogContext {
unsigned n_ref;
/* 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;
char *key;
char *value;
bool owned;
LIST_FIELDS(struct LogContext, ll);
} LogContext;
@@ -631,6 +634,15 @@ static void log_do_context(struct iovec *iovec, size_t iovec_len, size_t *n) {
iovec[(*n)++] = c->input_iovec[i];
iovec[(*n)++] = IOVEC_MAKE_STRING("\n");
}
if (c->key && c->value) {
if (*n + 3 >= iovec_len)
return;
iovec[(*n)++] = IOVEC_MAKE_STRING(c->key);
iovec[(*n)++] = IOVEC_MAKE_STRING(c->value);
iovec[(*n)++] = IOVEC_MAKE_STRING("\n");
}
}
}
@@ -1580,33 +1592,67 @@ bool log_context_enabled(void) {
return saved_log_context_enabled;
}
LogContext* log_context_attach(LogContext *c) {
static LogContext* log_context_attach(LogContext *c) {
assert(c);
_log_context_num_fields += strv_length(c->fields);
_log_context_num_fields += c->n_input_iovec;
_log_context_num_fields += !!c->key;
return LIST_PREPEND(ll, _log_context, c);
}
LogContext* log_context_detach(LogContext *c) {
static LogContext* log_context_detach(LogContext *c) {
if (!c)
return NULL;
assert(_log_context_num_fields >= strv_length(c->fields) + c->n_input_iovec);
assert(_log_context_num_fields >= strv_length(c->fields) + c->n_input_iovec +!!c->key);
_log_context_num_fields -= strv_length(c->fields);
_log_context_num_fields -= c->n_input_iovec;
_log_context_num_fields -= !!c->key;
LIST_REMOVE(ll, _log_context, c);
return NULL;
}
LogContext* log_context_new(char **fields, bool owned) {
LogContext* log_context_new(const char *key, const char *value) {
assert(key);
assert(endswith(key, "="));
assert(value);
LIST_FOREACH(ll, i, _log_context)
if (i->key == key && i->value == value)
return log_context_ref(i);
LogContext *c = new(LogContext, 1);
if (!c)
return NULL;
*c = (LogContext) {
.n_ref = 1,
.key = (char *) key,
.value = (char *) value,
};
return log_context_attach(c);
}
LogContext* log_context_new_strv(char **fields, bool owned) {
if (!fields)
return NULL;
LIST_FOREACH(ll, i, _log_context)
if (i->fields == fields) {
assert(!owned);
return log_context_ref(i);
}
LogContext *c = new(LogContext, 1);
if (!c)
return NULL;
*c = (LogContext) {
.n_ref = 1,
.fields = fields,
.owned = owned,
};
@@ -1614,15 +1660,22 @@ LogContext* log_context_new(char **fields, bool owned) {
return log_context_attach(c);
}
LogContext* log_context_newv(struct iovec *input_iovec, size_t n_input_iovec, bool owned) {
LogContext* log_context_new_iov(struct iovec *input_iovec, size_t n_input_iovec, bool owned) {
if (!input_iovec || n_input_iovec == 0)
return NULL; /* Nothing to do */
return NULL;
LIST_FOREACH(ll, i, _log_context)
if (i->input_iovec == input_iovec && i->n_input_iovec == n_input_iovec) {
assert(!owned);
return log_context_ref(i);
}
LogContext *c = new(LogContext, 1);
if (!c)
return NULL;
*c = (LogContext) {
.n_ref = 1,
.input_iovec = input_iovec,
.n_input_iovec = n_input_iovec,
.owned = owned,
@@ -1631,7 +1684,7 @@ LogContext* log_context_newv(struct iovec *input_iovec, size_t n_input_iovec, bo
return log_context_attach(c);
}
LogContext* log_context_free(LogContext *c) {
static LogContext* log_context_free(LogContext *c) {
if (!c)
return NULL;
@@ -1640,21 +1693,25 @@ LogContext* log_context_free(LogContext *c) {
if (c->owned) {
strv_free(c->fields);
iovec_array_free(c->input_iovec, c->n_input_iovec);
free(c->key);
free(c->value);
}
return mfree(c);
}
LogContext* log_context_new_consume(char **fields) {
LogContext *c = log_context_new(fields, /*owned=*/ true);
DEFINE_TRIVIAL_REF_UNREF_FUNC(LogContext, log_context, log_context_free);
LogContext* log_context_new_strv_consume(char **fields) {
LogContext *c = log_context_new_strv(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);
LogContext* log_context_new_iov_consume(struct iovec *input_iovec, size_t n_input_iovec) {
LogContext *c = log_context_new_iov(input_iovec, n_input_iovec, /*owned=*/ true);
if (!c)
iovec_array_free(input_iovec, n_input_iovec);

View File

@@ -458,39 +458,44 @@ 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_newv(struct iovec *input_iovec, size_t n_input_iovec, bool owned);
LogContext* log_context_free(LogContext *c);
LogContext* log_context_new(const char *key, const char *value);
LogContext* log_context_new_strv(char **fields, bool owned);
LogContext* log_context_new_iov(struct iovec *input_iovec, size_t n_input_iovec, bool owned);
/* Same as log_context_new(), but frees the given fields strv/iovec on failure. */
LogContext* log_context_new_consume(char **fields);
LogContext* log_context_new_consumev(struct iovec *input_iovec, size_t n_input_iovec);
LogContext* log_context_new_strv_consume(char **fields);
LogContext* log_context_new_iov_consume(struct iovec *input_iovec, size_t n_input_iovec);
LogContext *log_context_ref(LogContext *c);
LogContext *log_context_unref(LogContext *c);
DEFINE_TRIVIAL_CLEANUP_FUNC(LogContext*, log_context_unref);
/* 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_KEY_VALUE(key, value, c) \
_unused_ _cleanup_(log_context_unrefp) LogContext *c = log_context_new(key, value);
#define LOG_CONTEXT_PUSH_KEY_VALUE(key, value) \
_LOG_CONTEXT_PUSH_KEY_VALUE(key, value, UNIQ_T(c, UNIQ))
#define _LOG_CONTEXT_PUSH_STRV(strv, c) \
_unused_ _cleanup_(log_context_freep) LogContext *c = log_context_new(strv, /*owned=*/ false);
_unused_ _cleanup_(log_context_unrefp) LogContext *c = log_context_new_strv(strv, /*owned=*/ false);
#define LOG_CONTEXT_PUSH_STRV(strv) \
_LOG_CONTEXT_PUSH_STRV(strv, UNIQ_T(c, UNIQ))
#define _LOG_CONTEXT_PUSH_IOV(input_iovec, n_input_iovec, c) \
_unused_ _cleanup_(log_context_freep) LogContext *c = log_context_newv(input_iovec, n_input_iovec, /*owned=*/ false);
_unused_ _cleanup_(log_context_unrefp) LogContext *c = log_context_new_iov(input_iovec, n_input_iovec, /*owned=*/ false);
#define LOG_CONTEXT_PUSH_IOV(input_iovec, n_input_iovec) \
_LOG_CONTEXT_PUSH_IOV(input_iovec, n_input_iovec, UNIQ_T(c, UNIQ))
@@ -504,19 +509,19 @@ DEFINE_TRIVIAL_CLEANUP_FUNC(LogContext*, log_context_free);
_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))
_unused_ _cleanup_(log_context_unrefp) LogContext *c = log_context_new_strv_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);
_unused_ _cleanup_(log_context_unrefp) LogContext *c = log_context_new_strv_consume(strv);
#define LOG_CONTEXT_CONSUME_STRV(strv) \
_LOG_CONTEXT_CONSUME_STRV(strv, UNIQ_T(c, UNIQ))
#define _LOG_CONTEXT_CONSUME_IOV(input_iovec, n_input_iovec, c) \
_unused_ _cleanup_(log_context_freep) LogContext *c = log_context_new_consumev(input_iovec, n_input_iovec);
_unused_ _cleanup_(log_context_unrefp) LogContext *c = log_context_new_iov_consume(input_iovec, n_input_iovec);
#define LOG_CONTEXT_CONSUME_IOV(input_iovec, n_input_iovec) \
_LOG_CONTEXT_CONSUME_IOV(input_iovec, n_input_iovec, UNIQ_T(c, UNIQ))

View File

@@ -5568,6 +5568,8 @@ int exec_spawn(Unit *unit,
assert(params);
assert(params->fds || (params->n_socket_fds + params->n_storage_fds <= 0));
LOG_CONTEXT_PUSH_UNIT(unit);
if (context->std_input == EXEC_INPUT_SOCKET ||
context->std_output == EXEC_OUTPUT_SOCKET ||
context->std_error == EXEC_OUTPUT_SOCKET) {

View File

@@ -1208,3 +1208,13 @@ typedef struct UnitForEachDependencyData {
/* Note: this matches deps that have *any* of the atoms specified in match_atom set */
#define UNIT_FOREACH_DEPENDENCY(other, u, match_atom) \
_UNIT_FOREACH_DEPENDENCY(other, u, match_atom, UNIQ_T(data, UNIQ))
#define _LOG_CONTEXT_PUSH_UNIT(unit, u, c) \
const Unit *u = (unit); \
const ExecContext *c = unit_get_exec_context(u); \
LOG_CONTEXT_PUSH_KEY_VALUE(u->manager->unit_log_field, u->id); \
LOG_CONTEXT_PUSH_KEY_VALUE(u->manager->invocation_log_field, u->invocation_id_string); \
LOG_CONTEXT_PUSH_IOV(c ? c->log_extra_fields : NULL, c ? c->n_log_extra_fields : 0)
#define LOG_CONTEXT_PUSH_UNIT(unit) \
_LOG_CONTEXT_PUSH_UNIT(unit, UNIQ_T(u, UNIQ), UNIQ_T(c, UNIQ))

View File

@@ -2940,7 +2940,7 @@ static int process_fd_check(sd_bus *bus, sd_bus_message *m) {
}
static int process_message(sd_bus *bus, sd_bus_message *m) {
_unused_ _cleanup_(log_context_freep) LogContext *c = NULL;
_unused_ _cleanup_(log_context_unrefp) LogContext *c = NULL;
int r;
assert(bus);
@@ -2950,7 +2950,7 @@ static int process_message(sd_bus *bus, sd_bus_message *m) {
bus->iteration_counter++;
if (log_context_enabled())
c = log_context_new_consume(bus_message_make_log_fields(m));
c = log_context_new_strv_consume(bus_message_make_log_fields(m));
log_debug_bus_message(m);

View File

@@ -242,14 +242,14 @@ _public_ int sd_device_monitor_stop(sd_device_monitor *m) {
static int device_monitor_event_handler(sd_event_source *s, int fd, uint32_t revents, void *userdata) {
_cleanup_(sd_device_unrefp) sd_device *device = NULL;
_unused_ _cleanup_(log_context_freep) LogContext *c = NULL;
_unused_ _cleanup_(log_context_unrefp) LogContext *c = NULL;
sd_device_monitor *m = ASSERT_PTR(userdata);
if (device_monitor_receive_device(m, &device) <= 0)
return 0;
if (log_context_enabled())
c = log_context_new_consume(device_make_log_fields(device));
c = log_context_new_strv_consume(device_make_log_fields(device));
if (m->callback)
return m->callback(m, device, m->userdata);

View File

@@ -80,9 +80,10 @@ static void test_log_context(void) {
LOG_CONTEXT_PUSH_STRV(strv);
LOG_CONTEXT_PUSH_STRV(strv);
/* Test that the log context was set up correctly. */
assert_se(log_context_num_contexts() == 4);
assert_se(log_context_num_fields() == 6);
/* Test that the log context was set up correctly. The strv we pushed twice should only
* result in one log context which is reused. */
assert_se(log_context_num_contexts() == 3);
assert_se(log_context_num_fields() == 4);
/* Test that everything still works with modifications to the log context. */
test_log_struct();
@@ -94,8 +95,8 @@ static void test_log_context(void) {
LOG_CONTEXT_PUSH_STRV(strv);
/* Check that our nested fields got added correctly. */
assert_se(log_context_num_contexts() == 6);
assert_se(log_context_num_fields() == 9);
assert_se(log_context_num_contexts() == 4);
assert_se(log_context_num_fields() == 5);
/* Test that everything still works in a nested block. */
test_log_struct();
@@ -104,18 +105,18 @@ static void test_log_context(void) {
}
/* Check that only the fields from the nested block got removed. */
assert_se(log_context_num_contexts() == 4);
assert_se(log_context_num_fields() == 6);
assert_se(log_context_num_contexts() == 3);
assert_se(log_context_num_fields() == 4);
}
assert_se(log_context_num_contexts() == 0);
assert_se(log_context_num_fields() == 0);
{
_cleanup_(log_context_freep) LogContext *ctx = NULL;
_cleanup_(log_context_unrefp) LogContext *ctx = NULL;
char **strv = STRV_MAKE("SIXTH=ijn", "SEVENTH=PRP");
assert_se(ctx = log_context_new(strv, /*owned=*/ false));
assert_se(ctx = log_context_new_strv(strv, /*owned=*/ false));
assert_se(log_context_num_contexts() == 1);
assert_se(log_context_num_fields() == 2);
@@ -146,6 +147,7 @@ static void test_log_context(void) {
assert_se(iovw);
assert_se(iovw_consume(iovw, strdup("MNO=pqr"), STRLEN("MNO=pqr") + 1) == 0);
LOG_CONTEXT_PUSH_IOV(iov, ELEMENTSOF(iov));
LOG_CONTEXT_PUSH_IOV(iov, ELEMENTSOF(iov));
LOG_CONTEXT_CONSUME_IOV(iovw->iovec, iovw->count);
LOG_CONTEXT_PUSH("STU=vwx");
@@ -158,6 +160,17 @@ static void test_log_context(void) {
test_log_syntax();
}
{
LOG_CONTEXT_PUSH_KEY_VALUE("ABC=", "QED");
LOG_CONTEXT_PUSH_KEY_VALUE("ABC=", "QED");
assert_se(log_context_num_contexts() == 1);
assert_se(log_context_num_fields() == 1);
test_log_struct();
test_long_lines();
test_log_syntax();
}
assert_se(log_context_num_contexts() == 0);
assert_se(log_context_num_fields() == 0);
}