How do I convert dmesg timestamp to custom date format?

With the help of dr answer, I wrote a workaround that makes the conversion to put in your .bashrc. It won't break anything if you don't have any timestamp or already correct timestamps.

dmesg_with_human_timestamps () { $(type -P dmesg) "$@" | perl -w -e 'use strict; my ($uptime) = do { local @ARGV="/proc/uptime";<>}; ($uptime) = ($uptime =~ /^(\d+)\./); foreach my $line (<>) { printf( ($line=~/^\[\s*(\d+)\.\d+\](.+)/) ? ( "[%s]%s\n", scalar localtime(time - $uptime + $1), $2 ) : $line ) }' } alias dmesg=dmesg_with_human_timestamps 

Also, a good reading on the dmesg timestamp conversion logic & how to enable timestamps when there are none: https://supportcenter.checkpoint.com/supportcenter/portal?eventSubmit_doGoviewsolutiondetails=&solutionid=sk92677

For systems without "dmesg -T" such as RHEL/CentOS 6, I liked the "dmesg_with_human_timestamps" function provided by lucas-cimon earlier. It has a bit of trouble with some of our boxes with large uptime though. Turns out that kernel timestamps in dmesg are derived from an uptime value kept by individual CPUs. Over time this gets out of sync with the real time clock. As a result, the most accurate conversion for recent dmesg entries will be based on the CPU clock rather than /proc/uptime. For example, on a particular CentOS 6.6 box here:

# grep "\.clock" /proc/sched_debug | head -1 .clock : 32103895072.444568 # uptime 15:54:05 up 371 days, 19:09, 4 users, load average: 3.41, 3.62, 3.57 # cat /proc/uptime 32123362.57 638648955.00 

Accounting for the CPU uptime being in milliseconds, there's an offset of nearly 5 1/2 hours here. So I revised the script and converted it to native bash in the process:

dmesg_with_human_timestamps () { FORMAT="%a %b %d %H:%M:%S %Y" now=$(date +%s) cputime_line=$(grep -m1 "\.clock" /proc/sched_debug) if [[ $cputime_line =~ [^0-9]*([0-9]*).* ]]; then cputime=$((BASH_REMATCH[1] / 1000)) fi dmesg | while IFS= read -r line; do if [[ $line =~ ^\[\ *([0-9]+)\.[0-9]+\]\ (.*) ]]; then stamp=$((now-cputime+BASH_REMATCH[1])) echo "[$(date +"${FORMAT}" --date=@${stamp})] ${BASH_REMATCH[2]}" else echo "$line" fi done } alias dmesgt=dmesg_with_human_timestamps 

So KevZero requested a less kludgy solution, so I came up with the following:

sed -r 's#^\[([0-9]+\.[0-9]+)\](.*)#echo -n "[";echo -n $(date --date="@$(echo "$(grep btime /proc/stat|cut -d " " -f 2)+\1" | bc)" +"%c");echo -n "]";echo -n "\2"#e' 

Here's an example:

$ dmesg|tail | sed -r 's#^\[([0-9]+\.[0-9]+)\](.*)#echo -n "[";echo -n $(date --date="@$(echo "$(grep btime /proc/stat|cut -d " " -f 2)+\1" | bc)" +"%c");echo -n "]";echo -n "\2"#e' [2015-12-09T04:29:20 COT] cfg80211: (57240000 KHz - 63720000 KHz @ 2160000 KHz), (N/A, 0 mBm), (N/A) [2015-12-09T04:29:23 COT] wlp3s0: authenticate with dc:9f:db:92:d3:07 [2015-12-09T04:29:23 COT] wlp3s0: send auth to dc:9f:db:92:d3:07 (try 1/3) [2015-12-09T04:29:23 COT] wlp3s0: authenticated [2015-12-09T04:29:23 COT] wlp3s0: associate with dc:9f:db:92:d3:07 (try 1/3) [2015-12-09T04:29:23 COT] wlp3s0: RX AssocResp from dc:9f:db:92:d3:07 (capab=0x431 status=0 aid=6) [2015-12-09T04:29:23 COT] wlp3s0: associated [2015-12-09T04:29:56 COT] thinkpad_acpi: EC reports that Thermal Table has changed [2015-12-09T04:29:59 COT] i915 0000:00:02.0: BAR 6: [??? 0x00000000 flags 0x2] has bogus alignment [2015-12-09T05:00:52 COT] thinkpad_acpi: EC reports that Thermal Table has changed 

If you want it to perform a bit better, put the timestamp from proc into a variable instead :)

dmesg -T may show wrong time, different from date command output.

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 

The below command gives you better output

dmesg | awk -F ] '{"cat /proc/uptime | cut -d \" \" -f 1" | getline st;a=substr( $1,2, length($1) - 1);print strftime("%F %H:%M:%S %Z",systime()-st+a)" -> "$0}' 

In recent versions of dmesg, you can just call dmesg -T.

If you don't have the -T option for dmesg as for example on Andoid, you can use the busybox version. The following solves also some other issues:

1. The [0.0000] format is preceded by something that looks like misplaced color information, prefixes like <6>.
2. Make integers from floats.

It is inspired by this blog post.

#!/bin/sh # Translate dmesg timestamps to human readable format # uptime in seconds uptime=$(cut -d " " -f 1 /proc/uptime) # remove fraction uptime=$(echo $uptime | cut -d "." -f1) # run only if timestamps are enabled if [ "Y" = "$(cat /sys/module/printk/parameters/time)" ]; then dmesg | sed "s/[^\[]*\[/\[/" | sed "s/^\[[ ]*\?\([0-9.]*\)\] \(.*\)/\\1 \\2/" | while read timestamp message; do timestamp=$(echo $timestamp | cut -d "." -f1) ts1=$(( $(busybox date +%s) - $uptime + $timestamp )) ts2=$(busybox date -d "@${ts1}") printf "[%s] %s\n" "$ts2" "$message" done else echo "Timestamps are disabled (/sys/module/printk/parameters/time)" fi 

Note, however, that this implementation is quite slow.

you will need to reference the "btime" in /proc/stat, which is the Unix epoch time when the system was latest booted. Then you could base on that system boot time and then add on the elapsed seconds given in dmesg to calculate timestamp for each events.

With older Linux distros yet another option is to use wrapping script, e.g. in Perl or Python.

See solutions here:

http://linuxaria.com/article/how-to-make-dmesg-timestamp-human-readable?lang=en http://jmorano.moretrix.com/2012/03/dmesg-human-readable-timestamps/

A caveat which the other answers don't seem to mention is that the time which is shown by dmesg doesn't take into account any sleep/suspend time. So there are cases where the usual answer of using dmesg -T doesn't work, and shows a completely wrong time.

A workaround for such situations is to write something to the kernel log at a known time and then use that entry as a reference to calculate the other times. Obviously, it will only work for times after the last suspend.

So to display the correct time for recent entries on machines which may have been suspended since their last boot, use something like this from my other answer here:

# 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 

Old question, but I just want to share this abomination:

BOOTTS=$(date -d@$(( $(date +%s) - $(cut -d. -f1 /proc/uptime) )) +%s); dmesg | while read line; do TS=$(echo "${line}"|cut -d. -f1|tr -cd 0123456789); UTS=$(( ${BOOTTS}+${TS} )); NTS=$(date -d@"${UTS}" +'%Y-%m-%d %H:%M:%S'); echo -n ${NTS}; echo $line|cut -d] -f2-; done 

Because of $reasons I own multiple devices with all sorts of limited and restricted command line environments featuring a wide variety of busybox configurations, and so far this "crown jewel" has produced human-readable dmesg output on all of them.

I needed to view the ring buffer log on an older embedded Linux device. The device didn't have the new -T option for dmesg, didn't have bc or even a version of sed or bash that worked with the examples above. I ended creating a script using AWK to format the log dates based on runejuhl's sed script. Here is the script in case it's useful to someone.

 #!/bin/sh # print kernel ring buffer (dmesg log) with readable times if (dmsg -T not available) # boot time in seconds boottime=$(echo $(grep -m1 "btime" /proc/stat) | grep -Eo "[0-9]*$") lines=$1 if [ -z $lines ]; then lines=10 fi #dislpay last x lines of kernel log using awk script instead of sed / bc dmesg | tail -n $lines | awk 'match($0, /^\[ *([0-9]+\.[0-9]+)\]/) \ { print strftime("[%a %d/%m/%Y %H:%M:%S]",sprintf("%.0f", ('$boottime' + substr($0, RSTART+1, RLENGTH-2)))) substr($0, RLENGTH+1) }' 

This reads the time the system booted and stores it in a variable, then parses the log extracting the timestamp of each line adding it on to the boot time, formatting it to a date time string and writing it out with the rest of the line.

The boot time line (btime) is read from /proc/stat and the time extracted
boottime=$(echo $(grep -m1 "btime" /proc/stat) | grep -Eo "[0-9]*$")

the AWK match command is used to find the timestamp with a format of [ 0.0]
match($0, /^\[ *([0-9]+\.[0-9]+)\]/)

After a regex match the RSTART and RLENGTH variables hold the start and length of matched chars. The time stamp is extracted using a substring command, ignoring the [ ] substr($0, RSTART+1, RLENGTH-2)

The timestamp is then added onto the boottime value and rounded back to an integer using sprintf("%.0f", timestamp + boottime)

Finally the time is formatted to a readable value using strftime("[%a %d/%m/%Y %H:%M:%S]", logdate) and the rest of the log line to printed using another substr command taking the rest of the line after the original timestamp substr($0, RLENGTH+1)