dmesg日志中加入时间戳
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
