dmesg time vs system time time isn't correct
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 ?
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.
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.
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 so it appears in dmesg output
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
Workaround is journalctl with -k, --dmesg. I am using -k as it is shorter:
journalctl -k
It will show only kernel messages and correct time.
To show only kernel lines matching phrase:
journalctl -kg phrase