如何将dmesg的时间戳转换为自定义日期格式?

186
我正在努力理解 dmesg 的时间戳,并发现很难将其转换为 Java 日期或自定义日期格式。
示例的 dmesg 日志条目:
[14614.647880] airo(eth1): link lost (missed beacons)

如何将 14614.647880 转换为标准日期?
12个回答

308
理解dmesg时间戳非常简单:它是自内核启动以来的秒数。因此,如果有启动时间(uptime),您可以将秒数相加并以任何您喜欢的格式显示出来。
或者更好的是,您可以使用dmesg的-T命令行选项并解析可读的格式。
来自man page的说明:
-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.

13
有哪个命令接受-T参数?我的dmesg命令没有,手册也没有提到。(Linux Mint Debian Edition) - gyorgyabraham
1
我的(来自Ubuntu 13.04下的util-linux 2.20.1的dmesg) - user180100
2
无法在Redhat和/或Oracle Linux 5.6中使用,rpm -qf /bin/dmesg => util-linux-2.13-0.56.0.2.el5 - michael
9
此选项出现在 util-linux 2.20 中。根据发行说明:ftp://ftp.kernel.org/pub/linux/utils/util-linux/v2.20/v2.20-ReleaseNotes - ks1322
1
@xealits 感谢你的跟进,真是太好了 :) 关于这个问题,我认为理解部分只是次要的,“将其转换为Java日期/自定义日期格式” 才是核心部分,但你可能有不同的看法。祝你愉快的一天 ;) - user180100
显示剩余3条评论

36

dr的帮助下,我编写了一个解决方法,可以将转换放入您的.bashrc中。如果您没有时间戳或已经正确的时间戳,则它不会影响任何内容。

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

另外,有关dmesg时间戳转换逻辑以及在没有时间戳的情况下如何启用时间戳的好文章: https://supportcenter.checkpoint.com/supportcenter/portal?eventSubmit_doGoviewsolutiondetails=&solutionid=sk92677


小改进:您可以在管道中删除“tail -1”,并让awk从其缓冲区的最后一行读取并打印。 local dmesg_bin = $(type -a dmesg | awk 'END {print $ NF}') - Brian Onn
@Lucas:你能解释一下为什么要使用“type -a dmesg|...”而不是$(which dmesg)吗?使用三级管道获取该路径有什么优势吗? - Stabledog
@Stabledog:好问题。关于为什么使用type而不是which,请参见此问题的解释。我编辑了我的答案以避免无用的三个竖杠。 - Lucas Cimon
这个 Bash/Perl 代码片段对我很有用。我需要管理一个旧的 RHEL5.7 机器,但是 dmesg 没有打印人类可读时间戳的选项。 - Paul M

24

对于没有"dmesg -T"命令的系统,例如RHEL/CentOS 6,我喜欢之前由lucas-cimon提供的"dmesg_with_human_timestamps"函数。但是它在一些具有长时间运行的服务器上存在问题。原来,dmesg中的内核时间戳是根据各个CPU保持的正常运行时间值计算出来的。随着时间的推移,它会与实时时钟不同步。因此,对于最新的dmesg条目,最准确的转换将基于CPU时钟而不是/proc/uptime。例如,在这里的某个特定的CentOS 6.6服务器上:

# 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

考虑到CPU正常运行时间以毫秒为单位,这里有一个近5个半小时的偏差。因此,我重新编写了脚本并将其转换为本地bash:

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

函数在zsh中无法工作。必须在bash中正常运行。话虽如此,在一台已运行221天的机器上,该解决方案的时间戳精确到实际分钟。其他解决方案显示根本原因事件发生在当天早些时候2个小时以上。感谢Allen。你解救了我的下午。 - Trenton
RHEL5.x机器似乎没有/proc/sched_debug :-( - Paul M

20

所以KevZero要求一个更简洁的解决方案,因此我想出了以下方法:

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'

这是一个例子:

$ 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

如果你希望它表现得更好一些,那就将进程中的时间戳放入一个变量中 :)


9

dmesg -T 可能显示错误的时间,与 date 命令输出不同。

解决方法是使用带有 -k, --dmesg 的 journalctl 命令。由于它更短,我选择使用 -k:

journalctl -k

它将只显示内核消息和正确时间。

要仅显示匹配短语的内核行:

journalctl -kg phrase

6
如果你没有像在Andoid上一样的-T选项,你可以使用busybox版本。下面的代码还可以解决其他一些问题:
  1. [0.0000]格式前面是看起来错位的颜色信息,前缀像<6>
  2. 将浮点数转换为整数。
这受到了这篇博客文章的启发。
#!/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                                                                                                                      

请注意,然而这种实现方法相当缓慢。

6
在最近版本的dmesg中,您只需要调用dmesg -T即可。

3
RC在你之前已经给出了相同的答案,两年前。 - josch

3

您需要在/proc/stat中引用“btime”,这是系统最新启动时的Unix纪元时间。然后,您可以基于系统启动时间并添加在dmesg中给出的经过的秒数来计算每个事件的时间戳。


3

2

以下命令可以给您更好的输出

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}'

伟大的一句话,甚至适用于OpenWRT。 - undefined

网页内容由stack overflow 提供, 点击上面的
可以查看英文原文,
原文链接