From f8d3d1672a3ad901f0cb1ad0418cd9547450c125 Mon Sep 17 00:00:00 2001 From: Wojciech Dubowik Date: Mon, 23 Jan 2017 11:30:14 +0100 Subject: [PATCH] ubox: Add an option for more accurate timestamps in log Systemwide timestamps for syslog messages with ms accuracy are usefull for debugging timing problems. Signed-off-by: Wojciech Dubowik --- log/logd.c | 2 +- log/logread.c | 23 ++++++++++++++++++++--- 2 files changed, 21 insertions(+), 4 deletions(-) diff --git a/log/logd.c b/log/logd.c index 915348e..07aee2b 100644 --- a/log/logd.c +++ b/log/logd.c @@ -75,7 +75,7 @@ log_fill_msg(struct blob_buf *b, struct log_head *l) blobmsg_add_u32(b, "id", l->id); blobmsg_add_u32(b, "priority", l->priority); blobmsg_add_u32(b, "source", l->source); - blobmsg_add_u64(b, "time", l->ts.tv_sec * 1000LL); + blobmsg_add_u64(b, "time", (((__u64) l->ts.tv_sec) * 1000) + (l->ts.tv_nsec / 1000000)); } static int diff --git a/log/logread.c b/log/logread.c index 676bb82..edac1d9 100644 --- a/log/logread.c +++ b/log/logread.c @@ -62,6 +62,7 @@ static regex_t regexp_preg; static const char *log_file, *log_ip, *log_port, *log_prefix, *pid_file, *hostname, *regexp_pattern; static int log_type = LOG_STDOUT; static int log_size, log_udp, log_follow, log_trailer_null = 0; +static int log_timestamp; static const char* getcodetext(int value, CODE *codetable) { CODE *i; @@ -100,9 +101,11 @@ static int log_notify(struct blob_attr *msg) struct blob_attr *tb[__LOG_MAX]; struct stat s; char buf[512]; + char buf_ts[32]; uint32_t p; char *str; time_t t; + uint32_t t_ms = 0; char *c, *m; int ret = 0; @@ -134,6 +137,11 @@ static int log_notify(struct blob_attr *msg) regexec(®exp_preg, m, 0, NULL, 0) == REG_NOMATCH) return 0; t = blobmsg_get_u64(tb[LOG_TIME]) / 1000; + if (log_timestamp) { + t_ms = blobmsg_get_u64(tb[LOG_TIME]) % 1000; + snprintf(buf_ts, sizeof(buf_ts), "[%lu.%03u] ", + (unsigned long)t, t_ms); + } c = ctime(&t); p = blobmsg_get_u32(tb[LOG_PRIO]); c[strlen(c) - 1] = '\0'; @@ -143,6 +151,9 @@ static int log_notify(struct blob_attr *msg) snprintf(buf, sizeof(buf), "<%u>", p); strncat(buf, c + 4, 16); + if (log_timestamp) { + strncat(buf, buf_ts, sizeof(buf) - strlen(buf) - 1); + } if (hostname) { strncat(buf, hostname, sizeof(buf) - strlen(buf) - 1); strncat(buf, " ", sizeof(buf) - strlen(buf) - 1); @@ -172,8 +183,10 @@ static int log_notify(struct blob_attr *msg) uloop_timeout_set(&retry, 1000); } } else { - snprintf(buf, sizeof(buf), "%s %s.%s%s %s\n", - c, getcodetext(LOG_FAC(p) << 3, facilitynames), getcodetext(LOG_PRI(p), prioritynames), + snprintf(buf, sizeof(buf), "%s %s%s.%s%s %s\n", + c, log_timestamp ? buf_ts : "", + getcodetext(LOG_FAC(p) << 3, facilitynames), + getcodetext(LOG_PRI(p), prioritynames), (blobmsg_get_u32(tb[LOG_SOURCE])) ? ("") : (" kernel:"), m); ret = write(sender.fd, buf, strlen(buf)); } @@ -200,6 +213,7 @@ static int usage(const char *prog) " -P Prefix custom text to streamed messages\n" " -f Follow log messages\n" " -u Use UDP as the protocol\n" + " -t Add an extra timestamp\n" " -0 Use \\0 instead of \\n as trailer when using TCP\n" "\n", prog); return 1; @@ -246,7 +260,7 @@ int main(int argc, char **argv) signal(SIGPIPE, SIG_IGN); - while ((ch = getopt(argc, argv, "u0fcs:l:r:F:p:S:P:h:e:")) != -1) { + while ((ch = getopt(argc, argv, "u0fcs:l:r:F:p:S:P:h:e:t")) != -1) { switch (ch) { case 'u': log_udp = 1; @@ -290,6 +304,9 @@ int main(int argc, char **argv) regexp_pattern = optarg; } break; + case 't': + log_timestamp = 1; + break; default: return usage(*argv); } -- 2.11.0