dmesg: adjust timestamps according to suspended time

Timestamps in kernel log comes from monotonic clocksource which does not
tick when system suspended. Suspended time easily sums into hours and days
rendering human readable timestamps in dmesg useless.

Adjusting timestamps accouring to current delta between boottime and
monotonic clocksources produces accurate timestamps for messages printed
since last resume. Which are supposed to be most interesting.

Signed-off-by: Konstantin Khlebnikov <khlebnikov@yandex-team.ru>

diff --git a/include/monotonic.h b/include/monotonic.h
index 7a69d9e4b51e86d38bc3ade889eebe37edb3c7b8..380e59c3791ef32f9e17eaa903cf645f9b9c81fa 100644 (file)
--- a/include/monotonic.h
+++ b/include/monotonic.h
@@ -15,6 +15,8 @@
 
 extern int get_boot_time(struct timeval *boot_time);
 
+extern time_t get_suspended_time(void);
+
 extern int gettime_monotonic(struct timeval *tv);
 
 #endif /* UTIL_LINUX_MONOTONIC_H */

diff --git a/lib/monotonic.c b/lib/monotonic.c
index b684d8dd650a85a6c5a74c0f15c318905eb87c10..f0aeba6828e781747abbfac626fabf6d44d7fb7d 100644 (file)
--- a/lib/monotonic.c
+++ b/lib/monotonic.c
@@ -48,6 +48,18 @@ int get_boot_time(struct timeval *boot_time)
 #endif
 }
 
+time_t get_suspended_time(void)
+{
+#if defined(CLOCK_BOOTTIME) && defined(CLOCK_MONOTONIC)
+       struct timespec boot, mono;
+
+       if (clock_gettime(CLOCK_BOOTTIME, &boot) == 0 &&
+           clock_gettime(CLOCK_MONOTONIC, &mono) == 0)
+               return boot.tv_sec - mono.tv_sec;
+#endif
+       return 0;
+}
+
 int gettime_monotonic(struct timeval *tv)
 {
 #ifdef CLOCK_MONOTONIC

diff --git a/sys-utils/dmesg.1 b/sys-utils/dmesg.1
index 61a6ce89465d60e80a26383d04267405fb18279d..6c5773a6b211af8dc2496590f72141a841bb7788 100644 (file)
--- a/sys-utils/dmesg.1
+++ b/sys-utils/dmesg.1
@@ -161,6 +161,8 @@ source used for the logs is
 .B not updated after
 system
 .BR SUSPEND / RESUME .
+Timestamps are adjusted according to current delta between boottime and monotonic
+clocks, this works only for messages printed after last resume.
 .IP "\fB\-t\fR, \fB\-\-notime\fR"
 Do not print kernel's timestamps.
 .IP "\fB\-\-time\-format\fR \fIformat\fR"

diff --git a/sys-utils/dmesg.c b/sys-utils/dmesg.c
index ae1ebc74a2d91dd72f75588a016b717accfa810e..c78f01ca8755c4378af9c24627b8827b52d23e49 100644 (file)
--- a/sys-utils/dmesg.c
+++ b/sys-utils/dmesg.c
@@ -169,6 +169,7 @@ struct dmesg_control {
        struct timeval  lasttime;       /* last printed timestamp */
        struct tm       lasttm;         /* last localtime */
        struct timeval  boot_time;      /* system boot time */
+       time_t          suspended_time; /* time spent in suspeneded state */
 
        int             action;         /* SYSLOG_ACTION_* */
        int             method;         /* DMESG_METHOD_* */
@@ -824,7 +825,7 @@ static struct tm *record_localtime(struct dmesg_control *ctl,
                                   struct dmesg_record *rec,
                                   struct tm *tm)
 {
-       time_t t = ctl->boot_time.tv_sec + rec->tv.tv_sec;
+       time_t t = ctl->boot_time.tv_sec + ctl->suspended_time + rec->tv.tv_sec;
        return localtime_r(&t, tm);
 }
 
@@ -852,7 +853,7 @@ static char *iso_8601_time(struct dmesg_control *ctl, struct dmesg_record *rec,
                           char *buf, size_t bufsz)
 {
        struct timeval tv = {
-               .tv_sec = ctl->boot_time.tv_sec + rec->tv.tv_sec,
+               .tv_sec = ctl->boot_time.tv_sec + ctl->suspended_time + rec->tv.tv_sec,
                .tv_usec = rec->tv.tv_usec
        };
 
@@ -1301,8 +1302,16 @@ static inline int dmesg_get_boot_time(struct timeval *tv)
 
        return get_boot_time(tv);
 }
+
+static inline time_t dmesg_get_suspended_time(void)
+{
+       if (getenv("DMESG_TEST_BOOTIME"))
+               return 0;
+       return get_suspended_time();
+}
 #else
 # define dmesg_get_boot_time   get_boot_time
+# define dmesg_get_suspended_time      get_suspended_time
 #endif
 
 int main(int argc, char *argv[])
@@ -1499,9 +1508,12 @@ int main(int argc, char *argv[])
 
        if ((is_timefmt(&ctl, RELTIME) ||
             is_timefmt(&ctl, CTIME)   ||
-            is_timefmt(&ctl, ISO8601))
-           && dmesg_get_boot_time(&ctl.boot_time) != 0)
-               ctl.time_fmt = DMESG_TIMEFTM_NONE;
+            is_timefmt(&ctl, ISO8601))) {
+               if (dmesg_get_boot_time(&ctl.boot_time) != 0)
+                       ctl.time_fmt = DMESG_TIMEFTM_NONE;
+               else
+                       ctl.suspended_time = dmesg_get_suspended_time();
+       }
 
        if (delta)
                switch (ctl.time_fmt) {