RHEL 6 에서 dmesg를 통해 출력되는 kernel 메시지로그에 대해 인간 친화적인 timestamp로 출력되도록 하는 방법에 대한 안내이다.

 

RHEL 7 (또는 CentOS) 이상에서 커널메시지를 출력하기 위해 dmesg 명령을 입력하면 아래와 같이 uptime을 기준으로 시간이 출력된다.

[   26.669611] e1000e: enp5s0f0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: Rx/Tx
[   26.670111] IPv6: ADDRCONF(NETDEV_CHANGE): enp5s0f0: link becomes ready
[   26.791512] e1000e: enp5s0f1 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: Rx/Tx
[   26.792042] IPv6: ADDRCONF(NETDEV_CHANGE): enp5s0f1: link becomes ready
[140163.079080] perf: interrupt took too long (2514 > 2500), lowering kernel.perf_event_max_sample_rate to 79000
[214242.142133] perf: interrupt took too long (3153 > 3142), lowering kernel.perf_event_max_sample_rate to 63000
[216327.026247] e1000e: enp5s0f1 NIC Link is Down
[216331.701406] e1000e: enp5s0f1 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: Rx/Tx
[383832.356029] perf: interrupt took too long (3947 > 3941), lowering kernel.perf_event_max_sample_rate to 50000
[492966.131244] e1000e: enp5s0f1 NIC Link is Down
[494530.552504] e1000e: enp5s0f1 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: Rx/Tx
[1035594.212245] e1000e: enp5s0f1 NIC Link is Down
[1042247.228614] e1000e: enp5s0f1 NIC Link is Up 100 Mbps Full Duplex, Flow Control: Rx/Tx
[1042247.228735] e1000e 0000:05:00.1 enp5s0f1: 10/100 speed: disabling TSO

 

RHEL 7, 8에 포함된 dmesg (util-linux  rpm 패키지에 포함된)는 -T 옵션을 제공하여 인간 친화적인 시간으로도 출력이 가능하다.

[Sat Feb  8 18:05:19 2020] e1000e: enp5s0f0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: Rx/Tx
[Sat Feb  8 18:05:19 2020] IPv6: ADDRCONF(NETDEV_CHANGE): enp5s0f0: link becomes ready
[Sat Feb  8 18:05:19 2020] e1000e: enp5s0f1 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: Rx/Tx
[Sat Feb  8 18:05:19 2020] IPv6: ADDRCONF(NETDEV_CHANGE): enp5s0f1: link becomes ready
[Mon Feb 10 09:00:56 2020] perf: interrupt took too long (2514 > 2500), lowering kernel.perf_event_max_sample_rate to 79000
[Tue Feb 11 05:35:35 2020] perf: interrupt took too long (3153 > 3142), lowering kernel.perf_event_max_sample_rate to 63000
[Tue Feb 11 06:10:20 2020] e1000e: enp5s0f1 NIC Link is Down
[Tue Feb 11 06:10:24 2020] e1000e: enp5s0f1 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: Rx/Tx
[Thu Feb 13 04:42:05 2020] perf: interrupt took too long (3947 > 3941), lowering kernel.perf_event_max_sample_rate to 50000
[Fri Feb 14 11:00:59 2020] e1000e: enp5s0f1 NIC Link is Down
[Fri Feb 14 11:27:03 2020] e1000e: enp5s0f1 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: Rx/Tx
[Thu Feb 20 17:44:47 2020] e1000e: enp5s0f1 NIC Link is Down
[Thu Feb 20 19:35:40 2020] e1000e: enp5s0f1 NIC Link is Up 100 Mbps Full Duplex, Flow Control: Rx/Tx
[Thu Feb 20 19:35:40 2020] e1000e 0000:05:00.1 enp5s0f1: 10/100 speed: disabling TS

 

기본적으로 RHEL 6는 uptime 기준 시간도 출력이 되지 않는다.

uptime 기준으로 흘러간 시간을 출력되게 하려면 아래와 같이 적용한다.

- 임시적인 적용
# echo Y > /sys/module/printk/parameters/time

- 영구적인 적용
# vi /boot/grub/grub.conf
kernel 행에   printk.time=1   --> 추가

그런데 RHEL 6의 dmesg (util-linux-ng  rpm 패키지에 포함된)는 -T 옵션을 제공하지 않는다.

 

RHEL 6에서 인간 친화적인 시간으로 출력되게 하려면 2가지 방법이 있다.

1) syslog를 통해 로깅되는 messages 로그활용

messages 로그는 인간친화적인 시각이 표기되어 있다.

2) 스크립트를 이용하여 시간을 변형하여 출력

아래 내용과 같은 dmesg.sh 스크립트를 profile.d에 위치 시킨다.

# vim /etc/profile.d/dmesg.sh
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 를 쉘에서 입력하여 실행하면 기존 dmesg_with_human_timestamps 라는 함수를 실행하여 커널메시지를 출력해 준다.
  • 위 스크립트가 제대로 실행되려면 먼저 기본적으로 /sys/module/printk/parameters/time 또는 printk.time=1 이 적용되어 있어야 한다.
  • 적용 후 확인
[root@RHEL63-1 ~]# dmesg
[Mon Jun  1 15:14:31 2020] eth1: NIC Link is Up 10000 Mbps
[Mon Jun  1 15:14:32 2020] microcode: CPU0 sig=0x906eb, pf=0x1, revision=0xca
[Mon Jun  1 15:14:32 2020] platform microcode: firmware: requesting intel-ucode/06-9e-0b
[Mon Jun  1 15:14:32 2020] microcode: CPU1 sig=0x906eb, pf=0x1, revision=0xca
[Mon Jun  1 15:14:32 2020] platform microcode: firmware: requesting intel-ucode/06-9e-0b
[Mon Jun  1 15:14:32 2020] microcode: CPU2 sig=0x906eb, pf=0x1, revision=0xca
[Mon Jun  1 15:14:32 2020] platform microcode: firmware: requesting intel-ucode/06-9e-0b
[Mon Jun  1 15:14:32 2020] microcode: CPU3 sig=0x906eb, pf=0x1, revision=0xca
[Mon Jun  1 15:14:32 2020] platform microcode: firmware: requesting intel-ucode/06-9e-0b
[Mon Jun  1 15:14:32 2020] Microcode Update Driver: v2.00 <tigran@aivazian.fsnet.co.uk>, Peter Oruba

 

print dmesg with timestamp in human readable on the RHEL 6

댓글 남기기

이메일은 공개되지 않습니다. 필수 입력창은 * 로 표시되어 있습니다