linux dmesg日志中加入时间戳

朴灿烈づ我的快乐病毒、 2021-09-01 11:29 701阅读 0赞

**目录**

dmesg命令相关包

dmesg日志查看

解决方法一：通过新增监控日志kern来解决

解决方法二：修改内核参数

时间戳转换脚本

--------------------

### dmesg命令相关包 ###

CentOS 7之前的版本的dmesg日志是没有时间戳的，原因是`util-linux-ng`版本太低,不具备日期显示功能

[root@centos6 ~]#rpm -qf /bin/dmesg
    util-linux-ng-2.17.2-12.28.el6_9.2.x86_64

`util-linux-2.20+`才会有时间戳功能

[root@centos7 ~]#rpm -qf /bin/dmesg
    util-linux-2.23.2-52.el7.x86_64

### dmesg日志查看 ###

dmesg查看的日志存放在 **/var/log/dmesg**

CentOS 6 dmesg信息,无时间戳

[root@centos6 ~]#dmesg |tail
    ISO 9660 Extensions: Microsoft Joliet Level 3
    ISO 9660 Extensions: RRIP_1991A
    usb 2-2.1: USB disconnect, device number 4
    usb 2-2.1: new full speed USB device number 5 using uhci_hcd
    usb 2-2.1: New USB device found, idVendor=0e0f, idProduct=0008
    usb 2-2.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
    usb 2-2.1: Product: Virtual Bluetooth Adapter
    usb 2-2.1: Manufacturer: VMware
    usb 2-2.1: SerialNumber: 000650268328
    usb 2-2.1: configuration #1 chosen from 1 choice

CentOS 7 dmesg信息，`dmesg -T`可以显示时间戳

[root@centos7 ~]#dmesg -T  |tail
    [Fri Sep 21 00:55:32 2018] usb 2-2.1: SerialNumber: 000650268328
    [Fri Sep 21 00:56:39 2018] ISO 9660 Extensions: Microsoft Joliet Level 3
    [Fri Sep 21 00:56:39 2018] ISO 9660 Extensions: RRIP_1991A
    [Fri Sep 21 09:43:28 2018] usb 2-2.1: USB disconnect, device number 12
    [Fri Sep 21 09:43:28 2018] usb 2-2.1: new full-speed USB device number 13 using uhci_hcd
    [Fri Sep 21 09:43:28 2018] usb 2-2.1: New USB device found, idVendor=0e0f, idProduct=0008
    [Fri Sep 21 09:43:28 2018] usb 2-2.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
    [Fri Sep 21 09:43:28 2018] usb 2-2.1: Product: Virtual Bluetooth Adapter
    [Fri Sep 21 09:43:28 2018] usb 2-2.1: Manufacturer: VMware
    [Fri Sep 21 09:43:28 2018] usb 2-2.1: SerialNumber: 000650268328

日志无时间戳的原因

原因是`/sys/module/printk/parameters/time`为N即0，不开启状态

`/sys/module/*`包含所有编译的模块信息

> 这里有系统中所有模块的信息，不论这些模块是以内联(inlined)方式编译到内核映像文件(vmlinuz)中还是编译为外部模块(ko文件)，都可能会出现在 /sys/module 中：
> 
> 编译为外部模块(ko文件)在加载后会出现对应的 /sys/module/<module\_name>/, 并且在这个目录下会出现一些属性文件和属性目录来表示此外部模块的一些信息，如版本号、加载状态、所提供的驱动程序等；
> 
> 编译为内联方式的模块则只在当它有非0属性的模块参数时会出现对应的  
> **/sys/module/<module\_name>**, 这些模块的可用参数会出现在  
> **/sys/modules/<modname>/parameters/<param\_name>** 中

`/sys/module/printk/parameters/time` 这个可读写参数控制着内联模块 printk 在打印内核消息时是否加上时间前缀；所有内联模块的参数也可以由 `<module_name>.<param_name>=<value>` 的形式写在内核启动参数上

如启动内核时加上参数 `printk.time=1` 与 向 `/sys/module/printk/parameters/time` 写入1的效果相同；没有非0属性参数的内联模块不会出现于此。

--------------------

CentOS 6的printk.time值为N

[root@centos6 ~]#cat /sys/module/printk/parameters/time
    N

CentOS 7的printk.time值为Y

[root@centos7 ~]#cat /sys/module/printk/parameters/time 
    Y

### 解决方法一：通过新增监控日志kern来解决 ###

1. 修改`/sys/module/printk/parameters/time`参数

使其开始为今后日志添加时间戳，但是重启后会失效

可以使用dmesg查询

[root@centos6 ~]#echo 1 >/sys/module/printk/parameters/time
    [root@centos6 ~]#cat  /sys/module/printk/parameters/time
    Y

2. 在监控日志配置`/etc/rsyslog.conf`中，添加监控kern的信息，并重启rsyslog服务

从服务重启后开始生效，kern日志都记录在`/var/log/kern.log`中

但重启后用dmesg查看的日志依然没有时间戳；因为/sys/下的目录存放的是系统内存的信息，重启会失效；

同时，`/var/log/kern.log`中的日志的时间格式是人类易读的

[root@centos6 ~]#sed -i '/local7/a\kern.*       /var/log/kern.log' /etc/rsyslog.conf
    [root@centos6 /]#grep kern.log  /etc/rsyslog.conf  
    kern.*          /var/log/kern.log
    [root@centos6 /]#service rsyslog restart
    Shutting down system logger:                               [  OK  ]
    Starting system logger:                                    [  OK  ]
    [root@centos6 /]#

查询日志

[root@centos6 ~]#cat /var/log/kern.log 
    Sep  1 03:29:09 centos6 kernel: imklog 5.8.10, log source = /proc/kmsg started.
    [root@centos6 ~]#dmesg |tail
    usb 2-2.1: USB disconnect, device number 4
    usb 2-2.1: new full speed USB device number 5 using uhci_hcd
    usb 2-2.1: New USB device found, idVendor=0e0f, idProduct=0008
    usb 2-2.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
    usb 2-2.1: Product: Virtual Bluetooth Adapter
    usb 2-2.1: Manufacturer: VMware
    usb 2-2.1: SerialNumber: 000650268328
    usb 2-2.1: configuration #1 chosen from 1 choice
    [ 1065.215969] ISO 9660 Extensions: Microsoft Joliet Level 3
    [ 1065.218372] ISO 9660 Extensions: RRIP_1991A

3. 重启后查询日志

`dmesg`日志，再次无时间戳

[root@centos6 ~]#dmesg |tail -n 5
    e1000: eth0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
    e1000: eth1 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
    type=1305 audit(1535743941.130:3): audit_pid=1510 old=0 auid=4294967295 ses=4294967295 res=1
    eth0: no IPv6 routers present
    eth1: no IPv6 routers present

`/var/log/kern.log`日志，依然有时间

[root@centos6 ~]#tail -n 5 /var/log/kern.log 
    Sep  1 03:32:21 centos6 kernel: e1000: eth0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
    Sep  1 03:32:21 centos6 kernel: e1000: eth1 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
    Sep  1 03:32:21 centos6 kernel: type=1305 audit(1535743941.130:3): audit_pid=1510 old=0 auid=4294967295 ses=4294967295 res=1
    Sep  1 03:32:23 centos6 kernel: eth0: no IPv6 routers present
    Sep  1 03:32:27 centos6 kernel: eth1: no IPv6 routers present

### 解决方法二：修改内核参数 ###

1. 修改`/sys/module/printk/parameters/time`为1，此时打印日志时间生效，但是重启后会失效

`echo 1 >/sys/module/printk/parameters/time`

[root@centos6 ~]#echo 1 >/sys/module/printk/parameters/time
    [root@centos6 ~]#cat  /sys/module/printk/parameters/time
    Y

2. 修改启动时的内核参数`/boot/grub/grub.conf`

grub.conf所需要修改的行 `sed -rn '/^[^#].*kernel(.*)/p' /boot/grub/grub.conf`

[root@centos6 ~]#sed -rn '/^[^#].*kernel(.*)/p' /boot/grub/grub.conf 
        kernel /vmlinuz-2.6.32-754.el6.x86_64 ro root=/dev/mapper/VolGroup-lv_root rd_NO_LUKS LANG=en_US.UTF-8 rd_NO_MD rd_LVM_LV=VolGroup/lv_swap SYSFONT=latarcyrheb-sun16 crashkernel=auto rd_LVM_LV=VolGroup/lv_root  KEYBOARDTYPE=pc KEYTABLE=us rd_NO_DM rhgb quiet

3. 在最后添加 `prinkt.time=1`,备份原配置; 在内核启动时添加参数，这样重启就不会失效了

`sed -r -i.bak 's@(^[^#].*kernel.*)$@\1 printk.time=1@' /boot/grub/grub.conf`

[root@centos6 ~]#sed -r -i.bak 's@(^[^#].*kernel.*)$@\1 printk.time=1@' /boot/grub/grub.conf

`sed -rn '/^[^#].*kernel(.*)/p' /boot/grub/grub.conf` 查看修改后配置

[root@centos6 ~]#sed -rn '/^[^#].*kernel(.*)/p' /boot/grub/grub.conf
        kernel /vmlinuz-2.6.32-754.el6.x86_64 ro root=/dev/mapper/VolGroup-lv_root rd_NO_LUKS LANG=en_US.UTF-8 rd_NO_MD rd_LVM_LV=VolGroup/lv_swap SYSFONT=latarcyrheb-sun16 crashkernel=auto rd_LVM_LV=VolGroup/lv_root  KEYBOARDTYPE=pc KEYTABLE=us rd_NO_DM rhgb quiet printk.time=1

4. 查看dmesg信息

已经打上了时按戳，但不是人类可读的形式，这个数值是值开启到日志发生时所经过的时间，单位是秒，需要做换算

[root@centos6 /]#dmesg |tail
    usb 2-2.1: USB disconnect, device number 4
    usb 2-2.1: new full speed USB device number 5 using uhci_hcd
    usb 2-2.1: New USB device found, idVendor=0e0f, idProduct=0008
    usb 2-2.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
    usb 2-2.1: Product: Virtual Bluetooth Adapter
    usb 2-2.1: Manufacturer: VMware
    usb 2-2.1: SerialNumber: 000650268328
    usb 2-2.1: configuration #1 chosen from 1 choice
    [ 1140.744469] ISO 9660 Extensions: Microsoft Joliet Level 3
    [ 1140.746766] ISO 9660 Extensions: RRIP_1991A
    [root@centos6 /]#

两种方法相同点

都能实现，配置完成后立刻生效，记录配置完成后的相关带时间戳的日志信息

都能实现重启后依然显示带时间戳的内核日志信息

对配置前的日志都不能再加上时间戳了，因为之前的功能并为开启；

dmesg显示的时间均为人类不易读的格式，需要转换

两种方法不同点

方法一添加了kern日志，dmesg重启后不带时间戳，同时，kern日志不能直接用 dmesg查看

方法二修改了内核参数，内核信息都可以从dmesg中查看，重启依然有效

kern日志的时间戳是人类易读的方式，dmesg时间戳不易读

--------------------

### 时间戳转换脚本 ###

还有点小BUG，过滤不全，仅供参考

脚本

#!/bin/bash
    # /root/bin/dmesg_with_human_timestamps.sh
    
    dmesg | while read msg; do
    
        # 过滤无时间戳的日志条目，无需转换
        if [ `echo "$msg" |cut -c 1` !=  "[" ] ;then
            echo $msg
            continue
        fi
        
        # 获取每条日志的非可读秒数
        no_human_timestamps=`echo $msg |grep -E  -o "\b[0-9]+\.[0-9]{6}\b"`
        
        # 获取每条日志的从1970-01-01开始到日志记录时的秒数
        real=`echo "$(date +%s)-$(awk '{print $1}' /proc/uptime)+$no_human_timestamps" |bc`
        
        # 人类可读格式
        human_timestamps=`date -d @$real`
        
        # 转换并打印
        echo "$msg" | sed -rn 's@'"$no_human_timestamps"'@'"$human_timestamps"'@p' 
    done

设置dmesg别名

[root@app6 bin]#echo 'alias dmesg="/root/bin/dmesg_with_human_timestamps.sh"' >> ~/.bashrc

测试

[root@app6 bin]#type -a dmesg
    dmesg is aliased to `/root/bin/dmesg_with_human_timestamps.sh'
    dmesg is /bin/dmesg