From 60464b1f1a1828ecf94ac85e40856693f61ab552 Mon Sep 17 00:00:00 2001 From: Karel Zak Date: Fri, 20 Jul 2012 19:45:36 +0200 Subject: dmesg: add --reltime to print human readable deltas [Jul20 09:50] device vnet0 entered promiscuous mode [ +0.002248] virbr0: topology change detected, propagating [ +0.000017] virbr0: port 2(vnet0) entered forwarding state [ +0.000036] virbr0: port 2(vnet0) entered forwarding state [ +0.001663] ADDRCONF(NETDEV_CHANGE): virbr0: link becomes ready [ +10.480914] vnet0: no IPv6 routers present [Jul20 14:35] xhci_hcd 0000:0e:00.0: WARN Event TRB for slot 3 ep 5 with no TDs queued? [Jul20 19:23] EXT4-fs (sda2): re-mounted. Opts: (null) [ +6.052980] EXT4-fs (sda2): re-mounted. Opts: (null) Suggested by Linus: http://thread.gmane.org/gmane.linux.kernel/1290886/focus=1296138 Signed-off-by: Karel Zak --- sys-utils/dmesg.c | 91 ++++++++++++++++++++++++++++++++++++++++++++----------- 1 file changed, 73 insertions(+), 18 deletions(-) (limited to 'sys-utils/dmesg.c') diff --git a/sys-utils/dmesg.c b/sys-utils/dmesg.c index 4c270d0f6..4367e98bf 100644 --- a/sys-utils/dmesg.c +++ b/sys-utils/dmesg.c @@ -118,6 +118,7 @@ struct dmesg_control { char facilities[ARRAY_SIZE(facility_names) / NBBY + 1]; struct timeval lasttime; /* last printed timestamp */ + struct tm lasttm; /* last localtime */ time_t boot_time; /* system boot time */ int action; /* SYSLOG_ACTION_* */ @@ -141,6 +142,7 @@ struct dmesg_control { decode:1, /* use "facility: level: " prefix */ notime:1, /* don't print timestamp */ delta:1, /* show time deltas */ + reltime:1, /* show human readable relative times */ ctime:1; /* show human readable time */ }; @@ -181,6 +183,7 @@ static void __attribute__((__noreturn__)) usage(FILE *out) " -c, --read-clear read and clear all messages\n" " -D, --console-off disable printing messages to console\n" " -d, --show-delta show time delta between printed messages\n" + " -e, --reltime show time delta in human readable format\n" " -E, --console-on enable printing messages to console\n" " -F, --file use the file instead of the kernel log buffer\n" " -f, --facility restrict output to defined facilities\n" @@ -570,6 +573,9 @@ static const char *skip_item(const char *begin, const char *end, const char *sep return begin; } +/* + * Parses one record from syslog(2) buffer + */ static int get_next_syslog_record(struct dmesg_control *ctl, struct dmesg_record *rec) { @@ -624,7 +630,7 @@ static int get_next_syslog_record(struct dmesg_control *ctl, if (*begin == '[' && (*(begin + 1) == ' ' || isdigit(*(begin + 1)))) { - if (ctl->delta || ctl->ctime) + if (ctl->delta || ctl->ctime || ctl->reltime) begin = parse_syslog_timestamp(begin + 1, &rec->tv); else if (ctl->notime) begin = skip_item(begin, end, "]"); @@ -690,22 +696,48 @@ static void raw_print(struct dmesg_control *ctl, const char *buf, size_t size) putchar('\n'); } +static struct tm *record_localtime(struct dmesg_control *ctl, + struct dmesg_record *rec, + struct tm *tm) +{ + time_t t = ctl->boot_time + rec->tv.tv_sec; + return localtime_r(&t, tm); +} + static char *record_ctime(struct dmesg_control *ctl, struct dmesg_record *rec, char *buf, size_t bufsiz) { - time_t t = ctl->boot_time + rec->tv.tv_sec; - const struct tm *tm; + struct tm tm; - tm = localtime(&t); - *buf = '\0'; + record_localtime(ctl, rec, &tm); - if (strftime(buf, bufsiz, "%a %b %e %H:%M:%S %Y", tm) == 0) + if (strftime(buf, bufsiz, "%a %b %e %H:%M:%S %Y", &tm) == 0) *buf = '\0'; return buf; } -static void print_record(struct dmesg_control *ctl, struct dmesg_record *rec) +static char *short_ctime(struct tm *tm, char *buf, size_t bufsiz) +{ + if (strftime(buf, bufsiz, "%b%e %H:%M", tm) == 0) + *buf = '\0'; + return buf; +} + +static double record_count_delta(struct dmesg_control *ctl, + struct dmesg_record *rec) +{ + double delta = 0; + + if (timerisset(&ctl->lasttime)) + delta = time_diff(&rec->tv, &ctl->lasttime); + + ctl->lasttime = rec->tv; + return delta; +} + +static void print_record(struct dmesg_control *ctl, + struct dmesg_record *rec) { char buf[256]; @@ -741,12 +773,6 @@ static void print_record(struct dmesg_control *ctl, struct dmesg_record *rec) * [sec.usec ] or [ctime ] */ if (ctl->delta) { - double delta = 0; - - if (timerisset(&ctl->lasttime)) - delta = time_diff(&rec->tv, &ctl->lasttime); - ctl->lasttime = rec->tv; - if (ctl->ctime) printf("[%s ", record_ctime(ctl, rec, buf, sizeof(buf))); else if (ctl->notime) @@ -754,7 +780,7 @@ static void print_record(struct dmesg_control *ctl, struct dmesg_record *rec) else printf("[%5d.%06d ", (int) rec->tv.tv_sec, (int) rec->tv.tv_usec); - printf("<%12.06f>] ", delta); + printf("<%12.06f>] ", record_count_delta(ctl, rec)); /* * [ctime] @@ -762,6 +788,27 @@ static void print_record(struct dmesg_control *ctl, struct dmesg_record *rec) } else if (ctl->ctime) printf("[%s] ", record_ctime(ctl, rec, buf, sizeof(buf))); + /* + * [reltime] + */ + else if (ctl->reltime) { + double delta; + struct tm cur; + + record_localtime(ctl, rec, &cur); + delta = record_count_delta(ctl, rec); + + if (cur.tm_min != ctl->lasttm.tm_min || + cur.tm_hour != ctl->lasttm.tm_hour || + cur.tm_yday != ctl->lasttm.tm_yday) + printf("[%s] ", short_ctime(&cur, buf, sizeof(buf))); + else if (delta < 10) + printf("[ %+8.06f] ", delta); + else + printf("[ %+9.06f] ", delta); + + ctl->lasttm = cur; + } /* * In syslog output the timestamp is part of the message and we don't @@ -772,7 +819,7 @@ static void print_record(struct dmesg_control *ctl, struct dmesg_record *rec) * the [sec.usec] string. */ if (ctl->method == DMESG_METHOD_KMSG && - !ctl->notime && !ctl->delta && !ctl->ctime) + !ctl->notime && !ctl->delta && !ctl->ctime && !ctl->reltime) printf("[%5d.%06d] ", (int) rec->tv.tv_sec, (int) rec->tv.tv_usec); mesg: @@ -977,6 +1024,7 @@ int main(int argc, char *argv[]) { "syslog", no_argument, NULL, 'S' }, { "raw", no_argument, NULL, 'r' }, { "read-clear", no_argument, NULL, 'c' }, + { "reltime", no_argument, NULL, 'e' }, { "show-delta", no_argument, NULL, 'd' }, { "ctime", no_argument, NULL, 'T' }, { "notime", no_argument, NULL, 't' }, @@ -990,7 +1038,7 @@ int main(int argc, char *argv[]) textdomain(PACKAGE); atexit(close_stdout); - while ((c = getopt_long(argc, argv, "CcDdEF:f:hkl:n:rSs:TtuVwx", + while ((c = getopt_long(argc, argv, "CcDdEeF:f:hkl:n:rSs:TtuVwx", longopts, NULL)) != -1) { switch (c) { case 'C': @@ -1012,6 +1060,11 @@ int main(int argc, char *argv[]) exclusive_option(&excl_act, EXCL_CONSOLE_ON, EXCL_ACT_ERR); ctl.action = SYSLOG_ACTION_CONSOLE_ON; break; + case 'e': + ctl.boot_time = get_boot_time(); + if (ctl.boot_time) + ctl.reltime = 1; + break; case 'F': ctl.filename = optarg; ctl.method = DMESG_METHOD_MMAP; @@ -1094,8 +1147,10 @@ int main(int argc, char *argv[]) errx(EXIT_FAILURE, _("--raw can't be used together with level, " "facility, decode, delta, ctime or notime options")); - if (ctl.notime && ctl.ctime) - errx(EXIT_FAILURE, _("--notime can't be used together with ctime ")); + if (ctl.notime && (ctl.ctime || ctl.reltime)) + errx(EXIT_FAILURE, _("--notime can't be used together with --ctime or --reltime")); + if (ctl.reltime && ctl.ctime) + errx(EXIT_FAILURE, _("--reltime can't be used together with --ctime ")); switch (ctl.action) { case SYSLOG_ACTION_READ_ALL: -- cgit v1.2.3-55-g7522