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 <Wojciech.Dubowik@neratec.com>

diff --git a/log/logd.c b/log/logd.c
index 915348e..07aee2b 100644 (file)
--- 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_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
 }
 
 static int

diff --git a/log/logread.c b/log/logread.c
index 676bb82..edac1d9 100644 (file)
--- 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 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;
 
 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];
        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 p;
        char *str;
        time_t t;

+       uint32_t t_ms = 0;

        char *c, *m;
        int ret = 0;
 
        char *c, *m;
        int ret = 0;
 


@@ -134,6 +137,11 @@ static int log_notify(struct blob_attr *msg)
            regexec(&regexp_preg, m, 0, NULL, 0) == REG_NOMATCH)
                return 0;
        t = blobmsg_get_u64(tb[LOG_TIME]) / 1000;
            regexec(&regexp_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';
        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);
 
                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);
                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 {
                        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));
        }
                        (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>        Prefix custom text to streamed messages\n"
                "    -f                 Follow log messages\n"
                "    -u                 Use UDP as the protocol\n"
                "    -P <prefix>        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;
                "    -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);
 
 
        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;
                switch (ch) {
                case 'u':
                        log_udp = 1;


@@ -290,6 +304,9 @@ int main(int argc, char **argv)
                                regexp_pattern = optarg;
                        }
                        break;
                                regexp_pattern = optarg;
                        }
                        break;

+               case 't':
+                       log_timestamp = 1;
+                       break;

                default:
                        return usage(*argv);
                }
                default:
                        return usage(*argv);
                }