From: Timo Sirainen Date: Mon, 6 Oct 2014 17:16:07 +0000 (+0300) Subject: log_timestamp setting supports now %{usecs} X-Git-Tag: 2.2.14~56 X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=d4f004105cd7159aa9ade6b019eaecce9e94f382;p=thirdparty%2Fdovecot%2Fcore.git log_timestamp setting supports now %{usecs} This is mainly useful for debugging. --- diff --git a/src/lib/failures.c b/src/lib/failures.c index 249072d259..5e4e7e6d97 100644 --- a/src/lib/failures.c +++ b/src/lib/failures.c @@ -45,7 +45,8 @@ static struct failure_context failure_ctx_error = { .type = LOG_TYPE_ERROR }; static int log_fd = STDERR_FILENO, log_info_fd = STDERR_FILENO, log_debug_fd = STDERR_FILENO; -static char *log_prefix = NULL, *log_stamp_format = NULL; +static char *log_prefix = NULL; +static char *log_stamp_format = NULL, *log_stamp_format_suffix = NULL; static bool failure_ignore_errors = FALSE, log_prefix_sent = FALSE; static bool coredump_on_error = FALSE; @@ -54,12 +55,17 @@ i_internal_error_handler(const struct failure_context *ctx, const char *format, va_list args); /* kludgy .. we want to trust log_stamp_format with -Wformat-nonliteral */ -static const char *get_log_stamp_format(const char *unused) +static const char * +get_log_stamp_format(const char *format_arg, unsigned int timestamp_usecs) ATTR_FORMAT_ARG(1); -static const char *get_log_stamp_format(const char *unused ATTR_UNUSED) +static const char *get_log_stamp_format(const char *format_arg ATTR_UNUSED, + unsigned int timestamp_usecs) { - return log_stamp_format; + if (log_stamp_format_suffix == NULL) + return log_stamp_format; + return t_strdup_printf("%s%06u%s", log_stamp_format, + timestamp_usecs, log_stamp_format_suffix); } void failure_exit(int status) @@ -73,16 +79,19 @@ static void log_prefix_add(const struct failure_context *ctx, string_t *str) { const struct tm *tm = ctx->timestamp; char buf[256]; - time_t now; + struct timeval now; if (log_stamp_format != NULL) { if (tm == NULL) { - now = time(NULL); - tm = localtime(&now); + if (gettimeofday(&now, NULL) < 0) + i_panic("gettimeofday() failed: %m"); + tm = localtime(&now.tv_sec); + } else { + now.tv_usec = ctx->timestamp_usecs; } if (strftime(buf, sizeof(buf), - get_log_stamp_format("unused"), tm) > 0) + get_log_stamp_format("unused", now.tv_usec), tm) > 0) str_append(str, buf); } if (log_prefix != NULL) @@ -702,8 +711,18 @@ void i_set_debug_file(const char *path) void i_set_failure_timestamp_format(const char *fmt) { + const char *p; + i_free(log_stamp_format); - log_stamp_format = i_strdup(fmt); + i_free_and_null(log_stamp_format_suffix); + + p = strstr(fmt, "%{usecs}"); + if (p == NULL) + log_stamp_format = i_strdup(fmt); + else T_BEGIN { + log_stamp_format = i_strdup_until(fmt, p); + log_stamp_format_suffix = i_strdup(p + 8); + } T_END; } void i_set_failure_send_ip(const struct ip_addr *ip) @@ -746,4 +765,5 @@ void failures_deinit(void) i_free_and_null(log_prefix); i_free_and_null(log_stamp_format); + i_free_and_null(log_stamp_format_suffix); } diff --git a/src/lib/failures.h b/src/lib/failures.h index 9861b6eb4b..014c214262 100644 --- a/src/lib/failures.h +++ b/src/lib/failures.h @@ -36,6 +36,7 @@ struct failure_context { enum log_type type; int exit_status; /* for LOG_TYPE_FATAL */ const struct tm *timestamp; /* NULL = use time() + localtime() */ + unsigned int timestamp_usecs; }; #define DEFAULT_FAILURE_STAMP_FORMAT "%b %d %H:%M:%S " diff --git a/src/log/log-connection.c b/src/log/log-connection.c index 64faa8d9a4..630aec6d8b 100644 --- a/src/log/log-connection.c +++ b/src/log/log-connection.c @@ -81,7 +81,8 @@ static void log_parse_option(struct log_connection *log, static void client_log_ctx(struct log_connection *log, - const struct failure_context *ctx, time_t log_time, + const struct failure_context *ctx, + const struct timeval *log_time, const char *prefix, const char *text) { struct log_error err; @@ -98,7 +99,7 @@ client_log_ctx(struct log_connection *log, case LOG_TYPE_PANIC: memset(&err, 0, sizeof(err)); err.type = ctx->type; - err.timestamp = log_time; + err.timestamp = log_time->tv_sec; err.prefix = prefix; err.text = text; log_error_buffer_add(log->errorbuf, &err); @@ -111,7 +112,8 @@ client_log_ctx(struct log_connection *log, static void client_log_fatal(struct log_connection *log, struct log_client *client, - const char *line, time_t log_time, const struct tm *tm) + const char *line, const struct timeval *log_time, + const struct tm *tm) { struct failure_context failure_ctx; const char *prefix = log->default_prefix; @@ -119,6 +121,7 @@ client_log_fatal(struct log_connection *log, struct log_client *client, memset(&failure_ctx, 0, sizeof(failure_ctx)); failure_ctx.type = LOG_TYPE_FATAL; failure_ctx.timestamp = tm; + failure_ctx.timestamp_usecs = log_time->tv_usec; if (client != NULL) { if (client->prefix != NULL) @@ -133,7 +136,8 @@ client_log_fatal(struct log_connection *log, struct log_client *client, } static void -log_parse_master_line(const char *line, time_t log_time, const struct tm *tm) +log_parse_master_line(const char *line, const struct timeval *log_time, + const struct tm *tm) { struct log_connection *const *logs, *log; struct log_client *client; @@ -186,7 +190,7 @@ log_parse_master_line(const char *line, time_t log_time, const struct tm *tm) static void log_it(struct log_connection *log, const char *line, - time_t log_time, const struct tm *tm) + const struct timeval *log_time, const struct tm *tm) { struct failure_line failure; struct failure_context failure_ctx; @@ -223,6 +227,7 @@ log_it(struct log_connection *log, const char *line, memset(&failure_ctx, 0, sizeof(failure_ctx)); failure_ctx.type = failure.log_type; failure_ctx.timestamp = tm; + failure_ctx.timestamp_usecs = log_time->tv_usec; prefix = client != NULL && client->prefix != NULL ? client->prefix : log->default_prefix; @@ -279,7 +284,7 @@ static void log_connection_input(struct log_connection *log) { const char *line; ssize_t ret; - time_t now; + struct timeval now; struct tm tm; if (!log->handshaked) { @@ -291,11 +296,12 @@ static void log_connection_input(struct log_connection *log) while ((ret = i_stream_read(log->input)) > 0 || ret == -2) { /* get new timestamps for every read() */ - now = time(NULL); - tm = *localtime(&now); + if (gettimeofday(&now, NULL) < 0) + i_panic("gettimeofday() failed: %m"); + tm = *localtime(&now.tv_sec); while ((line = i_stream_next_line(log->input)) != NULL) - log_it(log, line, now, &tm); + log_it(log, line, &now, &tm); } if (log->input->eof)