logging: Improve logging format

This commit adds 2 improvemens to the ply_trace logging format:

1) It prefixes the log messages with timestamps (since system boot)

2) Previously function-names where right aligned / left padded to 45
characters. But they were prefixed with a [file:line] prefix which does
not have a fixed width, making the column aligment for the actual messages
fail resulting in hard to read logs.

This commit fixes 2. by printing "<timestamp> file:line:func" to a
prefix-buffer and then left-aligning / right padding this prefix buffer
to 75 chars.

The resulting logged lines now look like this:

00:00:01.741 main.c:1928:check_logging                                     : checking if console messages should be redirected and logged
00:00:01.741 main.c:1937:check_logging                                     : logging will be enabled!

Signed-off-by: Hans de Goede <hdegoede@redhat.com>
This commit is contained in:
Hans de Goede 2019-02-13 14:39:42 +01:00
parent 3d192d5c7a
commit 238e22b645

View file

@ -25,6 +25,7 @@
#include <stdint.h>
#include <string.h>
#include <sys/types.h>
#include <time.h>
#include <unistd.h>
typedef struct _ply_logger ply_logger_t;
@ -88,11 +89,21 @@ bool ply_logger_is_tracing_enabled (ply_logger_t *logger);
_old_errno = errno; \
if (ply_logger_is_tracing_enabled (logger)) \
{ \
struct timespec timespec = { 0, 0 }; \
char buf[128]; \
clock_gettime (CLOCK_MONOTONIC, &timespec); \
ply_logger_flush (logger); \
snprintf (buf, sizeof(buf), \
"%02d:%02d:%02d.%03d %s:%d:%s", \
(int)(timespec.tv_sec / 3600), \
(int)((timespec.tv_sec / 60) % 60), \
(int)(timespec.tv_sec % 60), \
(int)(timespec.tv_nsec / 1000000), \
__FILE__, __LINE__, __func__); \
errno = _old_errno; \
ply_logger_inject (logger, \
"[%s:%d] %45.45s:" format "\n", \
__FILE__, __LINE__, __func__, ## args); \
"%-75.75s: " format "\n", \
buf, ## args); \
ply_logger_flush (logger); \
errno = _old_errno; \
} \