printk-timestamp-converter 4.0.0

Why not “dmesg -T”

As noted, dmesg -T is the same as dmesg_format_dates –drift=0 and become inaccurate over time, because the tick clock is affected by frequency scaling etc.

Thus, it is recommended to have a cron job that runs printk_mark_drift as described below, maybe on half-day intervals to keep things accurate. More or less depending on precision desired and average drift of system.

You can use the dmesg_get_drifts application to show all current marked drifts to gauge how inaccurate your systems clock is.

Sample

Here is a sample showing the inaccuracies that can creep in:

First, show that dmesg can’t handle the printk drift

[cmd]$ date; sudo bash -c ‘echo “Hello World” > /dev/kmsg’; dmesg -T | grep ‘Hello World’ | tail -n1

Wed Sep 9 01:13:56 EDT 2015

[Wed Sep 9 01:14:31 2015] Hello World

Next, show that dmesg_format_dates does work with the printk drifts

[cmd]$ date; sudo bash -c ‘echo “Hello World” > /dev/kmsg’; ./dmesg_format_dates | grep ‘Hello World’ | tail -n1

Wed Sep 9 01:14:11 EDT 2015

[Wed Sep 9 01:14:11 2015] Hello World

Applications

dmesg_format_dates

This application runs “dmesg” (or you can pipe in a pre-recorded dmesg, e.g. from logs) and uses the calculated drifts to derive accurate timestamps.

Run this command to output the kernel log replacing the printk timestamps with calculated timestamps (in one of several formats), taking into account drift.

Output

Supported output modes are:

• Local Time (DEFAULT) -l or --local . Standard “ctime” format including local timezone information

• UTC -u or --utc . Standard “ctime” format given in UTC (no timezone, also known as GMT or Zulu)

• Epoch -e or --epoch . UNIX Epoch time. Given as number of seconds since Jan 1 1970

Subseconds

The output for local time and UTC are given in ctime format, which has a resolution of 1 second.

You may also pass -s or --subsec to add subseconds to the output.

This will output 2 significant digits of subseconds (accuracy +- 10ms) which is the maximum available from the uptime clock.

Epoch mode always outputs subseconds.

printk_mark_drift

Adds a drift marker to the kmsg log. These are used to calculate the drift. The more of these you have, the more accurate your timestamps are within.

You should consider having a cron job mark the log every couple hours to get up-to-the-second accuracy when using dmesg_format_dates

dmesg_get_drifts

This application will show the drifts within the dmesg log (the timestamp, how much the clock has drifted at that point).

Use this to analyize how much your machine is drifting to determine how often you should be marking the drifts (for accurate timestamps)

printk_time_convert

This application takes a single timestamp and converts it to either a local ctime, utc ctime, or epoch timestamp. It will add a drift note if a recent one is not available.

Output

Output modes for printk_time_convert are the same as dmesg_format_dates. See above for usage options, or --help.

How can I configure my kmsg to log timestamps?

Set the value of /sys/module/printk/parameters/time to “Y” (e.x. echo “Y” > /sys/module/printk/parameters/time)

Module

This package provides printk_timestamp_converter which is a python module you can use directly.

The pydoc documentation is available here: http://htmlpreview.github.io/?https://github.com/kata198/printk-timestamp-formatter/blob/master/doc/printk_timestamp_converter.html