	copyright 1998-2018 by Mark Verboom

Go back to What's new

Dmesg with readable timestamps

To blog index

Tuesday, 27 September, 2011

Dmesg with readable timestamps

2015/09/01 Update

As I found recently, with the introduction of util-linux v2.20 the follow options where added:

--ctime (short -T)

which convert the timestamps to human readable.

2011/09/27 Original entry

Dmesg is a really useful tool to look at recent log messages from the kernel, especially when there is a problem. A while ago the option to include timestamps in kernel messages was added, which gives you a seconds since boot indication of when a message occurred.

[ 46.451673] Bluetooth: BNEP filters: protocol multicast
[ 46.489223] Bluetooth: SCO (Voice Link) ver 0.6
[ 46.489224] Bluetooth: SCO socket layer initialized
[ 46.890497] lp0: using parport0 (interrupt-driven).
[ 46.927571] ppdev: user-space parallel port driver
[ 50.376608] ttyS1: LSR safety check engaged!
[ 50.439012] ttyS2: LSR safety check engaged!
[ 50.451335] ttyS3: LSR safety check engaged!
[14700.482957] loop: module loaded
[14700.595479] ISO 9660 Extensions: Microsoft Joliet Level 3
[14700.608103] ISO 9660 Extensions: RRIP_1991A
[15111.879308] CPU0 attaching NULL sched-domain.
[15111.879311] CPU1 attaching NULL sched-domain.
[15111.908068] CPU0 attaching sched-domain:
[15111.908072] domain 0: span 0-1 level MC
[15111.908075] groups: 0 1
[15111.908079] CPU1 attaching sched-domain:
[15111.908081] domain 0: span 0-1 level MC
[15111.908083] groups: 1 0
[15569.597056] Bluetooth: HIDP (Human Interface Emulation) ver 1.2

Although this provides good information, it is not really human readable. You can't see at a glance if a problem is recent or not without knowing the boot time of the system.

A simple oneliner can take care of that.

gawk -v uptime=$( grep btime /proc/stat | cut -d ' ' -f 2 ) '/^[[ 0-9.]*]/ { print strftime("[%Y/%m/%d %H:%M:%S]", substr($0,2,index($0,".")-2)+uptime) substr($0,index($0,"]")+1) }'

Piping the output from dmesg through the onliner gives the following output:

[2011/09/27 07:07:05] Bluetooth: BNEP filters: protocol multicast [2011/09/27 07:07:05] Bluetooth: SCO (Voice Link) ver 0.6
[2011/09/27 07:07:05] Bluetooth: SCO socket layer initialized
[2011/09/27 07:07:05] lp0: using parport0 (interrupt-driven).
[2011/09/27 07:07:05] ppdev: user-space parallel port driver
[2011/09/27 07:07:09] ttyS1: LSR safety check engaged!
[2011/09/27 07:07:09] ttyS2: LSR safety check engaged!
[2011/09/27 07:07:09] ttyS3: LSR safety check engaged!
[2011/09/27 11:11:19] loop: module loaded
[2011/09/27 11:11:19] ISO 9660 Extensions: Microsoft Joliet Level 3
[2011/09/27 11:11:19] ISO 9660 Extensions: RRIP_1991A
[2011/09/27 11:18:10] CPU0 attaching NULL sched-domain.
[2011/09/27 11:18:10] CPU1 attaching NULL sched-domain.
[2011/09/27 11:18:10] CPU0 attaching sched-domain:
[2011/09/27 11:18:10] domain 0: span 0-1 level MC
[2011/09/27 11:18:10] groups: 0 1
[2011/09/27 11:18:10] CPU1 attaching sched-domain:
[2011/09/27 11:18:10] domain 0: span 0-1 level MC
[2011/09/27 11:18:10] groups: 1 0
[2011/09/27 11:25:48] Bluetooth: HIDP (Human Interface Emulation) ver 1.2

Much better readable :)