Scenario / Questions

I hope that here is somebody that can help me with this strange problem.

I think that i know why it is happening but i don’t know how to solve it. Maybe it is because the BIOS time isn’t set correct or something like it. But i don’t want to change the BIOS time of approximate 400+ servers. (Or change the BIOS batt)

root@spool:~# echo TEST > /dev/kmsg
root@spool:~# dmesg -T | tail -1
[Mon Feb 17 04:57:03 2014] TEST
root@spool:~# date
Mon Feb 17 11:45:17 CET 2014

The server is running ntp for time sync.

Anybody here that knows how to fix this problem in the OS?

Linux spool 3.2.0-4-amd64 #1 SMP Debian 3.2.46-1+deb7u1 x86_64 GNU/Linux

Why, when echoing to /dev/kmsg, the date/time of my message in dmesg is not synchronized with system date/time ?

Find below all possible solutions or suggestions for the above questions..

Suggestion: 1

To verify your theory (which, by the way, is sound), execute the following as root:

hwclock --show

This will show you your hardware clock on the server you are executing the command.

To synchronise your hardware clock with your system-time (which is managed by ntp), run the following command:

hwclock --systohc --utc

The last argument (–utc) tells hwclock to store the time in hardware clock in coordinated universal time.

Additionally, please keep in mind that man page for dmesg(1) say the following, so the behaviour you are experiencing is documented and valid:

   -T, --ctime
          Print human-readable timestamps.

          Be aware that the timestamp could be inaccurate!  The time
          source used for the logs is not updated after system
          SUSPEND/RESUME.

Suggestion: 2

dmesg just prints the kernel ringbuffer which logs messages with uptime in seconds from being started as timestamp.

So if you use the -T option all this uptime values are just added to the date your system was booted. If you had times sleeping in suspend or resume, they are lost, so in this cases -T option is not useful, as date/time values are not right then and back in past.

Suggestion: 3

To get accurate times for “recent” entries in dmesg, you could convert the dmesg timestamps to real time with some hacking of the output.

By “recent”, I mean times after the last suspend/resume, since (as others already pointed out) suspend times are not counted in the dmesg timestamp.

But if you need it often, like on a notebook, you could put something like the following into functions or aliases:

# write current time to kernel ring buffer
echo "timecheck: $(date +%s) = $(date +%F_%T)" | sudo tee /dev/kmsg

# use our "timecheck" entry to get the difference
# between the dmesg timestamp and real time
offset=$(dmesg | grep timecheck | tail -1 \
| perl -nle '($t1,$t2)=/^.(\d+)\S+ timecheck: (\d+)/; print $t2-$t1')

# pipe dmesg output through a Perl snippet to
# convert it's timestamp to correct readable times
dmesg | tail \
| perl -pe 'BEGIN{$offset=shift} s/^\[(\d+)\S+/localtime($1+$offset)/e' $offset

# or use this instead to keep dmesg colors
dmesg --color=always | tail \
| perl -pe 'BEGIN{$offset=shift} s/^(\x1b\[.*?m)?\[(\d+)\S+/$1.localtime($2+$offset)/e' $offset

Sample output:

...
Sat Jun 29 11:12:28 2019 wlp3s0: Limiting TX power to 30 (30 - 0) dBm as advertised by 10:5a:f7:53:1d:0f
Sat Jun 29 11:12:28 2019 IPv6: ADDRCONF(NETDEV_CHANGE): wlp3s0: link becomes ready
Sat Jun 29 11:34:16 2019 timecheck: 1561800856 = 2019-06-29_11:34:16
Sat Jun 29 12:10:11 2019 wlp3s0: cannot understand ECSA IE operating class, 5, ignoring

Compared to original dmesg output (which is off by 3 days):

$ dmesg | tail -4
[249424.746958] wlp3s0: Limiting TX power to 30 (30 - 0) dBm as advertised by 10:5a:f7:53:1d:0f
[249424.749662] IPv6: ADDRCONF(NETDEV_CHANGE): wlp3s0: link becomes ready
[250732.318826] timecheck: 1561800856 = 2019-06-29_11:34:16
[252887.828699] wlp3s0: cannot understand ECSA IE operating class, 5, ignoring

$ dmesg -T | tail -4
[Wed Jun 26 17:59:09 2019] wlp3s0: Limiting TX power to 30 (30 - 0) dBm as advertised by 10:5a:f7:53:1d:0f
[Wed Jun 26 17:59:09 2019] IPv6: ADDRCONF(NETDEV_CHANGE): wlp3s0: link becomes ready
[Wed Jun 26 18:20:57 2019] timecheck: 1561800856 = 2019-06-29_11:34:16
[Wed Jun 26 18:56:52 2019] wlp3s0: cannot understand ECSA IE operating class, 5, ignoring