22

The output of dmesg shows the number of second+milliseconds since the system start.

[   10.470000] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[   14.610000] device eth0 entered promiscuous mode
[   18.750000] cfg80211: Calling CRDA for country: DE
[   18.750000] cfg80211: Regulatory domain changed to country: DE

Q: How to put the seconds+milliseconds in to a readable format?

My dmesg:

root@OpenWrt:/tmp# dmesg -h
dmesg: invalid option -- h
BusyBox v1.19.4 (2013-03-14 11:28:31 UTC) multi-call binary.

Usage: dmesg [-c] [-n LEVEL] [-s SIZE]

Print or control the kernel ring buffer

    -c      Clear ring buffer after printing
    -n LEVEL    Set console logging level
    -s SIZE     Buffer size

To install util-Linux won't be possible, because there is not much available space:

root@OpenWrt:~# df -h
Filesystem                Size      Used Available Use% Mounted on
rootfs                    1.1M    956.0K    132.0K  88% /
/dev/root                 2.0M      2.0M         0 100% /rom
tmpfs                    14.3M    688.0K     13.6M   5% /tmp
tmpfs                   512.0K         0    512.0K   0% /dev
/dev/mtdblock3            1.1M    956.0K    132.0K  88% /overlay
overlayfs:/overlay        1.1M    956.0K    132.0K  88% /

.

root@OpenWrt:/tmp# which awk  perl sed bash sh shell tcsh
/usr/bin/awk
/bin/sed
/bin/sh


root@OpenWrt:~# date -h
date: invalid option -- h
BusyBox v1.19.4 (2013-03-14 11:28:31 UTC) multi-call binary.

Usage: date [OPTIONS] [+FMT] [TIME]

Display time (using +FMT), or set time

    [-s,--set] TIME Set time to TIME
    -u,--utc    Work in UTC (don't convert to local time)
    -R,--rfc-2822   Output RFC-2822 compliant date string
    -I[SPEC]    Output ISO-8601 compliant date string
            SPEC='date' (default) for date only,
            'hours', 'minutes', or 'seconds' for date and
            time to the indicated precision
    -r,--reference FILE Display last modification time of FILE
    -d,--date TIME  Display TIME, not 'now'
    -D FMT      Use FMT for -d TIME conversion
    -k      Set Kernel timezone from localtime and exit
8
  • What do you refer to as a 'readable' format? – UVV Jan 27 '14 at 15:09
  • I'm afraid you're probably out of luck then. If your system logs the kernel output to some kind of log (for example to /var/log/syslog on Debian systems, check that log; it might contain the same information but with readable timestamps. – Martin von Wittich Jan 27 '14 at 16:33
  • 1
    'readable' as human readable date time stamp, like you explained for the '-T' arg. – user55518 Jan 27 '14 at 16:36
  • 1
    Hmm, this will be very complex since you don't seem to have access to anything with date manipulation capabilities. Your date command does not support the -d flag, right? And no python either I guess? WHich awk implementation is this? Is it GNU awk at least? – terdon Jan 27 '14 at 17:01
  • 1
    Cool, if you have date -d, my updated answer should work. – terdon Jan 27 '14 at 17:42
30

I think that what you're looking for is -T as documented in man dmesg:

-T, --ctime

Print human readable timestamps. The timestamp could be inaccurate!

The time source used for the logs is not updated after system SUSPEND/RESUME.

So, for example:

[  518.511925] usb 2-1.1: new low-speed USB device number 7 using ehci-pci
[  518.615735] usb 2-1.1: New USB device found, idVendor=1c4f, idProduct=0002
[  518.615742] usb 2-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[  518.615747] usb 2-1.1: Product: USB Keykoard

Becomes:

[Mon Jan 27 16:22:42 2014] hid-generic 0003:1C4F:0002.0007: input,hidraw0: USB HID v1.10 Keyboard [USB USB Keykoard] on usb-0000:00:1d.0-1.1/input0
[Mon Jan 27 16:22:42 2014] input: USB USB Keykoard as /devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.1/2-1.1:1.1/input/input24
[Mon Jan 27 16:22:42 2014] hid-generic 0003:1C4F:0002.0008: input,hidraw1: USB HID v1.10 Device [USB USB Keykoard] on usb-0000:00:1d.0-1.1/input1

I found a cool trick here. The sed expression used there was wrong since it would fail when there was more than one ] in the dmesg line. I have modified it to work with all cases I found in my own dmesg output. So, this should work assuming your date behaves as expected:

base=$(cut -d '.' -f1 /proc/uptime); 
seconds=$(date +%s); 
dmesg | sed 's/\]//;s/\[//;s/\([^.]\)\.\([^ ]*\)\(.*\)/\1\n\3/' | 
while read first; do 
  read second; 
  first=`date +"%d/%m/%Y %H:%M:%S" --date="@$(($seconds - $base + $first))"`;
  printf "[%s] %s\n" "$first" "$second"; 
done 

Output looks like:

[27/01/2014 16:14:45] usb 2-1.1: new low-speed USB device number 7 using ehci-pci
[27/01/2014 16:14:45] usb 2-1.1: New USB device found, idVendor=1c4f, idProduct=0002
[27/01/2014 16:14:45] usb 2-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[27/01/2014 16:14:45] usb 2-1.1: Product: USB Keykoard
5
  • we can also add, -T flags only support for util-linux-ng-2.20.x and higher, so it will support Ubuntu 12.04 and higher and not in CentOS/RHEL 6.3 and lower – Rahul Patil Jan 27 '14 at 15:58
  • 3
    I've been using dmesg for years and I only learned about this flag now. Why did nobody tell me that? :D – Martin von Wittich Jan 27 '14 at 16:31
  • 1
    @MartinvonWittich same here, I just read the man page for the first time today :) – terdon Jan 27 '14 at 16:32
  • sorry, didn't said this in advance that I use openwrt. – user55518 Jan 27 '14 at 16:51
  • Just for the record: just as dmesg -T does, the script in the answer also shows wrong time upon hibernate. – Hi-Angel Apr 6 '16 at 12:00
6

your version of dmesg is obviously not the full-fledged one from util-linux but instead is provided by busybox.

busybox provides the basics of a multitude of utilities, but it doesn't provide all their nifty features.

if you want to use the -T flag as (rightly) suggested by terdon, you will need to use the dmesg binary provided by util-linux

me@server:/tmp$ busybox sh
BusyBox v1.21.1 (Debian 1:1.21.0-1) built-in shell (ash)
Enter 'help' for a list of built-in commands.

/tmp $ dmesg -T
dmesg: invalid option -- 'T'
BusyBox v1.21.1 (Debian 1:1.21.0-1) multi-call binary.

Usage: dmesg [-c] [-n LEVEL] [-s SIZE]

Print or control the kernel ring buffer

    -c      Clear ring buffer after printing
    -n LEVEL    Set console logging level
    -s SIZE     Buffer size

/tmp $ /bin/dmesg -T | tail -5
[Mon Jän 27 13:37:24 2014] hid-generic 0003:046D:C03E.0006: input,hidraw2: USB HID v1.10 Mouse [Logitech USB-PS/2 Optical Mouse] on usb-0000:00:1d.0-1.8/input0
[Mon Jän 27 15:59:32 2014] NVRM: API mismatch: the client has the version 304.117, but
[Mon Jän 27 15:59:32 2014] NVRM: this kernel module has the version 304.116.  Please
[Mon Jän 27 15:59:32 2014] NVRM: make sure that this kernel module and all NVIDIA driver
[Mon Jän 27 15:59:32 2014] NVRM: components have the same version.
/tmp $

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy