diff options
Diffstat (limited to '')
-rw-r--r-- | src/lib/event-log.c | 461 |
1 files changed, 461 insertions, 0 deletions
diff --git a/src/lib/event-log.c b/src/lib/event-log.c new file mode 100644 index 0000000..f8f2f79 --- /dev/null +++ b/src/lib/event-log.c @@ -0,0 +1,461 @@ +/* Copyright (c) 2017-2018 Dovecot authors, see the included COPYING file */ + +#include "lib.h" +#include "str.h" +#include "event-filter.h" +#include "lib-event-private.h" + +unsigned int event_filter_replace_counter = 1; + +static struct event_filter *global_debug_log_filter = NULL; +static struct event_filter *global_debug_send_filter = NULL; +static struct event_filter *global_core_log_filter = NULL; + +#undef e_error +void e_error(struct event *event, + const char *source_filename, unsigned int source_linenum, + const char *fmt, ...) +{ + struct event_log_params params = { + .log_type = LOG_TYPE_ERROR, + .source_filename = source_filename, + .source_linenum = source_linenum, + }; + va_list args; + + va_start(args, fmt); + T_BEGIN { + event_logv(event, ¶ms, fmt, args); + } T_END; + va_end(args); +} + +#undef e_warning +void e_warning(struct event *event, + const char *source_filename, unsigned int source_linenum, + const char *fmt, ...) +{ + struct event_log_params params = { + .log_type = LOG_TYPE_WARNING, + .source_filename = source_filename, + .source_linenum = source_linenum, + }; + va_list args; + + va_start(args, fmt); + T_BEGIN { + event_logv(event, ¶ms, fmt, args); + } T_END; + va_end(args); +} + +#undef e_info +void e_info(struct event *event, + const char *source_filename, unsigned int source_linenum, + const char *fmt, ...) +{ + struct event_log_params params = { + .log_type = LOG_TYPE_INFO, + .source_filename = source_filename, + .source_linenum = source_linenum, + }; + va_list args; + + va_start(args, fmt); + T_BEGIN { + event_logv(event, ¶ms, fmt, args); + } T_END; + va_end(args); +} + +#undef e_debug +void e_debug(struct event *event, + const char *source_filename, unsigned int source_linenum, + const char *fmt, ...) +{ + struct event_log_params params = { + .log_type = LOG_TYPE_DEBUG, + .source_filename = source_filename, + .source_linenum = source_linenum, + }; + va_list args; + + va_start(args, fmt); + T_BEGIN { + event_logv(event, ¶ms, fmt, args); + } T_END; + va_end(args); +} + +#undef e_log +void e_log(struct event *event, enum log_type level, + const char *source_filename, unsigned int source_linenum, + const char *fmt, ...) +{ + struct event_log_params params = { + .log_type = level, + .source_filename = source_filename, + .source_linenum = source_linenum, + }; + va_list args; + + va_start(args, fmt); + T_BEGIN { + event_logv(event, ¶ms, fmt, args); + } T_END; + va_end(args); +} + +struct event_get_log_message_context { + const struct event_log_params *params; + + string_t *log_prefix; + const char *message; + unsigned int type_pos; + + bool replace_prefix:1; + bool str_out_done:1; +}; + +static inline void ATTR_FORMAT(2, 0) +event_get_log_message_str_out(struct event_get_log_message_context *glmctx, + const char *fmt, va_list args) +{ + const struct event_log_params *params = glmctx->params; + string_t *str_out = params->base_str_out; + + /* The message is appended once in full, rather than incremental during + the recursion. */ + + if (glmctx->str_out_done || str_out == NULL) + return; + + /* append the current log prefix to the string buffer */ + if (params->base_str_prefix != NULL && !glmctx->replace_prefix) + str_append(str_out, params->base_str_prefix); + str_append_str(str_out, glmctx->log_prefix); + + if (glmctx->message != NULL) { + /* a child event already constructed a message */ + str_append(str_out, glmctx->message); + } else { + va_list args_copy; + + /* construct message from format and arguments */ + VA_COPY(args_copy, args); + str_vprintfa(str_out, fmt, args_copy); + va_end(args_copy); + } + + /* finished with the string buffer */ + glmctx->str_out_done = TRUE; +} + +static bool ATTR_FORMAT(4, 0) +event_get_log_message(struct event *event, + struct event_get_log_message_context *glmctx, + unsigned int prefixes_dropped, + const char *fmt, va_list args) +{ + const struct event_log_params *params = glmctx->params; + const char *prefix = event->log_prefix; + bool ret = FALSE; + + /* Reached the base event? */ + if (event == params->base_event) { + /* Append the message to the provided string buffer. */ + event_get_log_message_str_out(glmctx, fmt, args); + /* Insert the base send prefix */ + if (params->base_send_prefix != NULL) { + str_insert(glmctx->log_prefix, 0, + params->base_send_prefix); + ret = TRUE; + } + } + + /* Call the message amendment callback for this event if there is one. + */ + if (event->log_message_callback != NULL) { + const char *in_message; + + /* construct the log message composed by children and arguments + */ + if (glmctx->message == NULL) { + str_vprintfa(glmctx->log_prefix, fmt, args); + in_message = str_c(glmctx->log_prefix); + } else if (str_len(glmctx->log_prefix) == 0) { + in_message = glmctx->message; + } else { + str_append(glmctx->log_prefix, glmctx->message); + in_message = str_c(glmctx->log_prefix); + } + + /* reformat the log message */ + glmctx->message = event->log_message_callback( + event->log_message_callback_context, + glmctx->params->log_type, in_message); + + /* continue with a cleared prefix buffer (as prefix is now part + of *message_r). */ + str_truncate(glmctx->log_prefix, 0); + ret = TRUE; + } + + if (event->log_prefix_callback != NULL) { + prefix = event->log_prefix_callback( + event->log_prefix_callback_context); + } + if (event->log_prefix_replace) { + /* this event replaces all parent log prefixes */ + glmctx->replace_prefix = TRUE; + glmctx->type_pos = (prefix == NULL ? 0 : strlen(prefix)); + event_get_log_message_str_out(glmctx, fmt, args); + } + if (prefix != NULL) { + if (event->log_prefix_replace || prefixes_dropped == 0) { + str_insert(glmctx->log_prefix, 0, prefix); + ret = TRUE; + } else if (prefixes_dropped > 0) { + prefixes_dropped--; + } + } + if (event->parent == NULL) { + event_get_log_message_str_out(glmctx, fmt, args); + if (params->base_event == NULL && + params->base_send_prefix != NULL && + !glmctx->replace_prefix) { + str_insert(glmctx->log_prefix, 0, + params->base_send_prefix); + ret = TRUE; + } + } else if (!event->log_prefix_replace && + (!params->no_send || !glmctx->str_out_done)) { + prefixes_dropped += event->log_prefixes_dropped; + if (event_get_log_message(event->parent, glmctx, + prefixes_dropped, fmt, args)) + ret = TRUE; + } + return ret; +} + +void event_log(struct event *event, const struct event_log_params *params, + const char *fmt, ...) +{ + va_list args; + + va_start(args, fmt); + event_logv(event, params, fmt, args); + va_end(args); +} + +#undef event_want_log_level +bool event_want_log_level(struct event *event, enum log_type level, + const char *source_filename, + unsigned int source_linenum) +{ + struct failure_context ctx = { .type = LOG_TYPE_DEBUG }; + + if (level >= event->min_log_level) { + /* Always log when level is at least this high */ + return TRUE; + } + + if (event->debug_level_checked_filter_counter == event_filter_replace_counter) { + /* Log filters haven't changed since we last checked this, so + we can rely on the last cached value. FIXME: this doesn't + work correctly if event changes and the change affects + whether the filters would match. */ + return event->sending_debug_log; + } + event->debug_level_checked_filter_counter = + event_filter_replace_counter; + + if (event->forced_debug) { + /* Debugging is forced for this event (and its children) */ + event->sending_debug_log = TRUE; + } else if (global_debug_log_filter != NULL && + event_filter_match_source(global_debug_log_filter, event, + source_filename, source_linenum, &ctx)) { + /* log_debug filter matched */ + event->sending_debug_log = TRUE; + } else if (global_core_log_filter != NULL && + event_filter_match_source(global_core_log_filter, event, + source_filename, source_linenum, &ctx)) { + /* log_core_filter matched */ + event->sending_debug_log = TRUE; + } else { + event->sending_debug_log = FALSE; + } + return event->sending_debug_log; +} + +#undef event_want_level +bool event_want_level(struct event *event, enum log_type level, + const char *source_filename, + unsigned int source_linenum) +{ + if (event_want_log_level(event, level, source_filename, source_linenum)) + return TRUE; + + /* see if debug send filtering matches */ + if (global_debug_send_filter != NULL) { + struct failure_context ctx = { .type = LOG_TYPE_DEBUG }; + + if (event_filter_match_source(global_debug_send_filter, event, + source_filename, source_linenum, + &ctx)) + return TRUE; + } + return FALSE; +} + +static void ATTR_FORMAT(3, 0) +event_logv_params(struct event *event, const struct event_log_params *params, + const char *fmt, va_list args) +{ + struct event_get_log_message_context glmctx; + + struct failure_context ctx = { + .type = params->log_type, + }; + bool abort_after_event = FALSE; + + i_assert(!params->no_send || params->base_str_out != NULL); + + if (global_core_log_filter != NULL && + event_filter_match_source(global_core_log_filter, event, + event->source_filename, + event->source_linenum, &ctx)) + abort_after_event = TRUE; + + i_zero(&glmctx); + glmctx.params = params; + glmctx.log_prefix = t_str_new(64); + if (!event_get_log_message(event, &glmctx, 0, fmt, args)) { + /* keep log prefix as it is */ + if (params->base_str_out != NULL && !glmctx.str_out_done) { + va_list args_copy; + + VA_COPY(args_copy, args); + str_vprintfa(params->base_str_out, fmt, args_copy); + va_end(args_copy); + } + if (!params->no_send) + event_vsend(event, &ctx, fmt, args); + } else if (params->no_send) { + /* don't send the event */ + } else if (glmctx.replace_prefix) { + /* event overrides the log prefix (even if it's "") */ + ctx.log_prefix = str_c(glmctx.log_prefix); + ctx.log_prefix_type_pos = glmctx.type_pos; + if (glmctx.message != NULL) + event_send(event, &ctx, "%s", glmctx.message); + else + event_vsend(event, &ctx, fmt, args); + } else { + /* append to log prefix, but don't fully replace it */ + if (glmctx.message != NULL) + str_append(glmctx.log_prefix, glmctx.message); + else + str_vprintfa(glmctx.log_prefix, fmt, args); + event_send(event, &ctx, "%s", str_c(glmctx.log_prefix)); + } + if (abort_after_event) + abort(); +} + +void event_logv(struct event *event, const struct event_log_params *params, + const char *fmt, va_list args) +{ + const char *orig_source_filename = event->source_filename; + unsigned int orig_source_linenum = event->source_linenum; + int old_errno = errno; + + if (params->source_filename != NULL) { + event_set_source(event, params->source_filename, + params->source_linenum, TRUE); + } + + (void)event_want_log_level(event, params->log_type, + event->source_filename, + event->source_linenum); + + event_ref(event); + event_logv_params(event, params, fmt, args); + event_set_source(event, orig_source_filename, + orig_source_linenum, TRUE); + event_unref(&event); + errno = old_errno; +} + +struct event *event_set_forced_debug(struct event *event, bool force) +{ + if (force) + event->forced_debug = TRUE; + event_recalculate_debug_level(event); + return event; +} + +struct event *event_unset_forced_debug(struct event *event) +{ + event->forced_debug = FALSE; + event_recalculate_debug_level(event); + return event; +} + +void event_set_global_debug_log_filter(struct event_filter *filter) +{ + event_unset_global_debug_log_filter(); + global_debug_log_filter = filter; + event_filter_ref(global_debug_log_filter); + event_filter_replace_counter++; +} + +struct event_filter *event_get_global_debug_log_filter(void) +{ + return global_debug_log_filter; +} + +void event_unset_global_debug_log_filter(void) +{ + event_filter_unref(&global_debug_log_filter); + event_filter_replace_counter++; +} + +void event_set_global_debug_send_filter(struct event_filter *filter) +{ + event_unset_global_debug_send_filter(); + global_debug_send_filter = filter; + event_filter_ref(global_debug_send_filter); + event_filter_replace_counter++; +} + +struct event_filter *event_get_global_debug_send_filter(void) +{ + return global_debug_send_filter; +} + +void event_unset_global_debug_send_filter(void) +{ + event_filter_unref(&global_debug_send_filter); + event_filter_replace_counter++; +} + +void event_set_global_core_log_filter(struct event_filter *filter) +{ + event_unset_global_core_log_filter(); + global_core_log_filter = filter; + event_filter_ref(global_core_log_filter); + event_filter_replace_counter++; +} + +struct event_filter *event_get_global_core_log_filter(void) +{ + return global_core_log_filter; +} + +void event_unset_global_core_log_filter(void) +{ + event_filter_unref(&global_core_log_filter); + event_filter_replace_counter++; +} |