iT邦幫忙

2021 iThome 鐵人賽

DAY 18
0
IT管理

Rocky Linux 8:系統管理與維運實戰系列 第 18

第13章:分析、儲存與存取系統日誌介紹(一)

前言

本章節,是要講解系統日誌的架構與介紹

系統日誌

在一個標準的作業系統中,會有系統日誌,並分別存放檔案在某些路徑底下,每一種之系統log檔案所存放的資訊也有所不同,以下列出幾個重要的系統日誌檔案清單:

  • /var/log/messages:這個檔案會存放大部分系統之資訊,像是關於使用者驗證的日誌、收發信箱之處理訊息、排程工作執行以及那些系統錯誤有關的訊息。
  • /var/log/secure:這個檔案會存放有關於作業系統上安全與驗證相關事件的訊息。
  • /var/log/maillog:這個檔案會存放有關於mail server的日誌訊息。
  • /var/log/cron:這個檔案會存放有關於排程工作執行的紀錄與相關日誌訊息。

寫入日誌訊息至檔案

在寫入一筆日誌訊息的時候,需要注意每一個日誌都有分等級的,相關的日誌等級如下:

  • 當等級代號為0的時候,則此日誌等級為緊急,表示作業系統無法使用,可能是server有問題。
  • 當等級代號為1的時候,則此日誌等級為警告,表示這個動作必會立即的發生。
  • 當等級代號為2的時候,則此日誌訊息為危急,表示有危急的事情發生。
  • 當等級代號為3的時候,則此日誌訊息為錯誤,表示有非危急的錯誤發生。
  • 當等級代號為4的時候,則此日誌訊息為警告,表示有警告的事件發生。
  • 當等級代號為5的時候,則此日誌訊息通知,表示是正常的訊號事件訊息。
  • 當等級代號為6的時候,則日誌訊息為資訊,表示是一些資訊,意思是運作正常的訊息。
  • 當等級代號為7的時候,則日誌訊息為除錯的意思,表示是這些訊息是除錯等級的訊息。

相關的基本rsyslog設定檔範例如下:

#### RULES ####

# Log all kernel messages to the console.
# Logging much else clutters up the screen.
#kern.*                                                 /dev/console

# Log anything (except mail) of level info or higher.
# Don't log private authentication messages!
*.info;mail.none;authpriv.none;cron.none                /var/log/messages

# The authpriv file has restricted access.
authpriv.*                                              /var/log/secure

# Log all the mail messages in one place.
mail.*                                                  -/var/log/maillog


# Log cron stuff
cron.*                                                  /var/log/cron

# Everybody gets emergency messages
*.emerg                                                 :omusrmsg:*

# Save news errors of level crit and higher in a special file.
uucp,news.crit                                          /var/log/spooler

# Save boot messages also to boot.log
local7.*                                                /var/log/boot.log

上述的設定檔也在/etc/rsyslog.conf檔案中,從弟38行開始即是,並一直到第65行,每一個種類服務都會對應到一個日誌檔案,這些日誌檔案也就是先前所提到預設的日誌檔案路徑。

分析日誌項目

首先,以下面這個範例來介紹日誌中,在一行訊息中的欄位:

Sep 18 00:01:03 localhost kernel: Linux version 4.18.0-305.3.1.el8_4.x86_64 (mockbuild@ord1-prod-x86build003.svc.aws.rockylinux.org) (gcc version 8.4.1 20200928 (Red Hat 8.4.1-1) (GCC)) #1 SMP Thu Jun 17 07:52:48 UTC 2021

一開始會有一個時間,指的是這個日誌什麼時候被記錄的,接著是哪個主機傳送這個訊息,程式或是程序名稱以及PID(Process id)數字,來傳送這個訊息的;最後就是這個傳送的訊息內容。

監控日誌訊息

我們可以使用tail這個指令來監控日誌的訊息,透過監控日誌的訊息可以及時知道日誌訊息,使用這個指令並搭配-f參數便可以自動的刷新檔案內容,相關的指令執行方式如下:

[rockylinux@workstation ~]$ sudo tail -f /var/log/messages
[sudo] password for rockylinux:
Oct  4 01:12:49 workstation systemd[1]: Started Cleanup of Temporary Directories.
Oct  4 01:30:02 workstation systemd[1]: Starting dnf makecache...
Oct  4 01:30:06 workstation dnf[2683]: Rocky Linux 8 - AppStream                       5.8 kB/s | 4.8 kB     00:00
Oct  4 01:30:07 workstation dnf[2683]: Rocky Linux 8 - BaseOS                          5.8 kB/s | 4.3 kB     00:00
Oct  4 01:30:09 workstation dnf[2683]: Rocky Linux 8 - Extras                          2.8 kB/s | 3.5 kB     00:01
Oct  4 01:30:10 workstation dnf[2683]: Extra Packages for Enterprise Linux Modular 8 - 6.0 kB/s | 8.1 kB     00:01
Oct  4 01:30:11 workstation dnf[2683]: Extra Packages for Enterprise Linux 8 - x86_64   11 kB/s | 8.3 kB     00:00
Oct  4 01:30:14 workstation dnf[2683]: Metadata cache created.
Oct  4 01:30:14 workstation systemd[1]: dnf-makecache.service: Succeeded.
Oct  4 01:30:14 workstation systemd[1]: Started dnf makecache.

由上述的指令執行輸出的訊息可以知道,查看系統日誌需要root使用者權限,而使用-f參數進行刷新的話,則此程序會卡在前景,一直監控有無新的訊息進來,若要結束的話,則按下「ctrl」加上「C」鍵來停止即可。

我們繼續讓這個監控日誌訊息卡在前景,接著開啟另一個終端機並輸入下列的指令:

[rockylinux@workstation ~]$ logger test_message
[rockylinux@workstation ~]$

接著回去看監控日誌的訊息輸出,則可以看到下列的訊息:

.......
Oct  4 01:47:03 workstation rockylinux[2908]: test_message

從上述可以看到,我們發送的「test_message」之日誌訊息已經成功的寫到此日誌檔案裡面了,而logger指令是用來寫入一筆訊息到/var/log/messages之檔案中,預設是user.notice,其對應到的等級為5。

有些服務則有自己的設定檔案去定義其產生出來的日誌訊息要以什麼樣的等級存放與呈現,以SSHD服務舉例來說,它就有自己的日誌訊息等級與標籤可以自行定義,相關的設定檔在/etc/ssh/sshd_config檔案中的第37行,並呈現此設定檔之設定內容如下:

......
# Logging
#SyslogFacility AUTH
SyslogFacility AUTHPRIV
#LogLevel INFO
......

尋找事件

為了要取得日誌訊息,則可以使用journalctl來做到,可以用來找尋所有系統的所有日誌訊息,相關的指令執行輸出的訊息如下:

[rockylinux@workstation ~]$ sudo journalctl
-- Logs begin at Mon 2021-10-04 00:57:49 CST, end at Mon 2021-10-04 01:57:08 CST. --
Oct 04 00:57:49 workstation kernel: Linux version 4.18.0-305.19.1.el8_4.x86_64 (mockbuild@ord1-prod-x86buil>
Oct 04 00:57:49 workstation kernel: Command line: BOOT_IMAGE=(hd0,msdos1)/vmlinuz-4.18.0-305.19.1.el8_4.x86>
Oct 04 00:57:49 workstation kernel: x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'
Oct 04 00:57:49 workstation kernel: x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'
Oct 04 00:57:49 workstation kernel: x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'
Oct 04 00:57:49 workstation kernel: x86/fpu: xstate_offset[2]:  576, xstate_sizes[2]:  256
Oct 04 00:57:49 workstation kernel: x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using >
Oct 04 00:57:49 workstation kernel: BIOS-provided physical RAM map:
Oct 04 00:57:49 workstation kernel: BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
Oct 04 00:57:49 workstation kernel: BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved
Oct 04 00:57:49 workstation kernel: BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
Oct 04 00:57:49 workstation kernel: BIOS-e820: [mem 0x0000000000100000-0x000000007ffeffff] usable
Oct 04 00:57:49 workstation kernel: BIOS-e820: [mem 0x000000007fff0000-0x000000007fffffff] ACPI data
Oct 04 00:57:49 workstation kernel: BIOS-e820: [mem 0x00000000fec00000-0x00000000fec00fff] reserved
Oct 04 00:57:49 workstation kernel: BIOS-e820: [mem 0x00000000fee00000-0x00000000fee00fff] reserved
Oct 04 00:57:49 workstation kernel: BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
Oct 04 00:57:49 workstation kernel: NX (Execute Disable) protection: active
Oct 04 00:57:49 workstation kernel: SMBIOS 2.5 present.
Oct 04 00:57:49 workstation kernel: DMI: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
Oct 04 00:57:49 workstation kernel: Hypervisor detected: KVM
Oct 04 00:57:49 workstation kernel: kvm-clock: Using msrs 4b564d01 and 4b564d00
Oct 04 00:57:49 workstation kernel: kvm-clock: cpu 0, msr 20601001, primary cpu clock
Oct 04 00:57:49 workstation kernel: kvm-clock: using sched offset of 13263841095 cycles
Oct 04 00:57:49 workstation kernel: clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4d>
Oct 04 00:57:49 workstation kernel: tsc: Detected 3292.524 MHz processor
Oct 04 00:57:49 workstation kernel: e820: update [mem 0x00000000-0x00000fff] usable ==> reserved
lines 1-27

預設會進入閱讀模式,因此需要按下「q」鍵來離開文字閱讀器模式,若不要進入閱讀器模式,則可以再加入「--no-pgaer」之參數來做到;若要印出指定的行數日誌事件訊息,則可以使用-n這個參數來做到,假設要印出最後的5行日誌事件訊息,則可以使用下列的指令做到:

[rockylinux@workstation ~]$ sudo journalctl -n 5
-- Logs begin at Mon 2021-10-04 00:57:49 CST, end at Mon 2021-10-04 01:58:43 CST. --
Oct 04 01:57:08 workstation sudo[3048]: pam_unix(sudo:session): session opened for user root by rockylinux(>
Oct 04 01:57:14 workstation sudo[3048]: pam_unix(sudo:session): session closed for user root
Oct 04 01:58:43 workstation sudo[3070]: rockylinux : TTY=pts/0 ; PWD=/home/rockylinux ; USER=root ; COMMAND>
Oct 04 01:58:43 workstation sudo[3070]: pam_systemd(sudo:session): Cannot create session: Already running i>
Oct 04 01:58:43 workstation sudo[3070]: pam_unix(sudo:session): session opened for user root by rockylinux(>
lines 1-6/6 (END)

若是使用journalctl要持續監控的話,則可以加上「-f」參數來做到,這個參數會印出目前事件訊息的最後10筆,餅卡住前景進行日誌事件的監控,相關執行指令的輸出訊息如下:

[rockylinux@workstation ~]$ sudo journalctl -f
-- Logs begin at Mon 2021-10-04 00:57:49 CST. --
Oct 04 02:00:33 workstation sudo[3096]: pam_unix(sudo:session): session opened for user root by rockylinux(uid=0)
Oct 04 02:00:34 workstation sudo[3096]: pam_unix(sudo:session): session closed for user root
Oct 04 02:01:01 workstation CROND[3100]: (root) CMD (run-parts /etc/cron.hourly)
Oct 04 02:01:01 workstation run-parts[3103]: (/etc/cron.hourly) starting 0anacron
Oct 04 02:01:01 workstation anacron[3111]: Anacron started on 2021-10-04
Oct 04 02:01:01 workstation anacron[3111]: Normal exit (0 jobs run)
Oct 04 02:01:01 workstation run-parts[3113]: (/etc/cron.hourly) finished 0anacron
Oct 04 02:01:53 workstation sudo[3122]: rockylinux : TTY=pts/0 ; PWD=/home/rockylinux ; USER=root ; COMMAND=/bin/journalctl -f
Oct 04 02:01:53 workstation sudo[3122]: pam_systemd(sudo:session): Cannot create session: Already running in a session or user slice
Oct 04 02:01:53 workstation sudo[3122]: pam_unix(sudo:session): session opened for user root by rockylinux(uid=0)

若要看其他的權限與等級的日誌訊息,則可以加上「-p」參數並搭配等級的名稱,以下面執行指令的為例:

[rockylinux@workstation ~]$ sudo journalctl -p info
-- Logs begin at Mon 2021-10-04 00:57:49 CST, end at Mon 2021-10-04 02:05:32 CST. --
Oct 04 00:57:49 workstation kernel: Linux version 4.18.0-305.19.1.el8_4.x86_64 (mockbuild@ord1-prod-x86buil>
Oct 04 00:57:49 workstation kernel: Command line: BOOT_IMAGE=(hd0,msdos1)/vmlinuz-4.18.0-305.19.1.el8_4.x86>
Oct 04 00:57:49 workstation kernel: x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'
Oct 04 00:57:49 workstation kernel: x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'
Oct 04 00:57:49 workstation kernel: x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'
Oct 04 00:57:49 workstation kernel: x86/fpu: xstate_offset[2]:  576, xstate_sizes[2]:  256
Oct 04 00:57:49 workstation kernel: x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using >
Oct 04 00:57:49 workstation kernel: BIOS-provided physical RAM map:
Oct 04 00:57:49 workstation kernel: BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
Oct 04 00:57:49 workstation kernel: BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved
Oct 04 00:57:49 workstation kernel: BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
Oct 04 00:57:49 workstation kernel: BIOS-e820: [mem 0x0000000000100000-0x000000007ffeffff] usable
Oct 04 00:57:49 workstation kernel: BIOS-e820: [mem 0x000000007fff0000-0x000000007fffffff] ACPI data
Oct 04 00:57:49 workstation kernel: BIOS-e820: [mem 0x00000000fec00000-0x00000000fec00fff] reserved
Oct 04 00:57:49 workstation kernel: BIOS-e820: [mem 0x00000000fee00000-0x00000000fee00fff] reserved
Oct 04 00:57:49 workstation kernel: BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
Oct 04 00:57:49 workstation kernel: NX (Execute Disable) protection: active
Oct 04 00:57:49 workstation kernel: SMBIOS 2.5 present.
Oct 04 00:57:49 workstation kernel: DMI: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
Oct 04 00:57:49 workstation kernel: Hypervisor detected: KVM
Oct 04 00:57:49 workstation kernel: kvm-clock: Using msrs 4b564d01 and 4b564d00
Oct 04 00:57:49 workstation kernel: kvm-clock: cpu 0, msr 20601001, primary cpu clock
Oct 04 00:57:49 workstation kernel: kvm-clock: using sched offset of 13263841095 cycles
Oct 04 00:57:49 workstation kernel: clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4d>
Oct 04 00:57:49 workstation kernel: tsc: Detected 3292.524 MHz processor
Oct 04 00:57:49 workstation kernel: last_pfn = 0x7fff0 max_arch_pfn = 0x400000000
lines 1-27

同樣的,也可以指定時間,假設要看從今天開始的日誌訊息,則可以搭配--since這個參數來做到,相關執行指令輸出的訊息如下:

[rockylinux@workstation ~]$ sudo journalctl --since today
-- Logs begin at Mon 2021-10-04 00:57:49 CST, end at Mon 2021-10-04 02:06:44 CST. --
Oct 04 00:57:49 workstation kernel: Linux version 4.18.0-305.19.1.el8_4.x86_64 (mockbuild@ord1-prod-x86buil>
Oct 04 00:57:49 workstation kernel: Command line: BOOT_IMAGE=(hd0,msdos1)/vmlinuz-4.18.0-305.19.1.el8_4.x86>
Oct 04 00:57:49 workstation kernel: x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'
Oct 04 00:57:49 workstation kernel: x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'
Oct 04 00:57:49 workstation kernel: x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'
Oct 04 00:57:49 workstation kernel: x86/fpu: xstate_offset[2]:  576, xstate_sizes[2]:  256
Oct 04 00:57:49 workstation kernel: x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using >
Oct 04 00:57:49 workstation kernel: BIOS-provided physical RAM map:
Oct 04 00:57:49 workstation kernel: BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
Oct 04 00:57:49 workstation kernel: BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved
Oct 04 00:57:49 workstation kernel: BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
Oct 04 00:57:49 workstation kernel: BIOS-e820: [mem 0x0000000000100000-0x000000007ffeffff] usable
Oct 04 00:57:49 workstation kernel: BIOS-e820: [mem 0x000000007fff0000-0x000000007fffffff] ACPI data
Oct 04 00:57:49 workstation kernel: BIOS-e820: [mem 0x00000000fec00000-0x00000000fec00fff] reserved
Oct 04 00:57:49 workstation kernel: BIOS-e820: [mem 0x00000000fee00000-0x00000000fee00fff] reserved
Oct 04 00:57:49 workstation kernel: BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
Oct 04 00:57:49 workstation kernel: NX (Execute Disable) protection: active
Oct 04 00:57:49 workstation kernel: SMBIOS 2.5 present.
Oct 04 00:57:49 workstation kernel: DMI: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
Oct 04 00:57:49 workstation kernel: Hypervisor detected: KVM
Oct 04 00:57:49 workstation kernel: kvm-clock: Using msrs 4b564d01 and 4b564d00
Oct 04 00:57:49 workstation kernel: kvm-clock: cpu 0, msr 20601001, primary cpu clock
Oct 04 00:57:49 workstation kernel: kvm-clock: using sched offset of 13263841095 cycles
Oct 04 00:57:49 workstation kernel: clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4d>
Oct 04 00:57:49 workstation kernel: tsc: Detected 3292.524 MHz processor
Oct 04 00:57:49 workstation kernel: e820: update [mem 0x00000000-0x00000fff] usable ==> reserved
lines 1-27

另外,也可以使用指定區間時間方式,來設定一個區間中所有的日誌訊息印出來,相關的執行指令結果與輸出如下所示:

[rockylinux@workstation ~]$ sudo journalctl --since "2021-10-04 02:00" --until "2021-10-04 02:01"
-- Logs begin at Mon 2021-10-04 00:57:49 CST, end at Mon 2021-10-04 02:10:47 CST. --
Oct 04 02:00:33 workstation sudo[3096]: rockylinux : TTY=pts/0 ; PWD=/home/rockylinux ; USER=root ; COMMAN>
Oct 04 02:00:33 workstation sudo[3096]: pam_systemd(sudo:session): Cannot create session: Already running >
Oct 04 02:00:33 workstation sudo[3096]: pam_unix(sudo:session): session opened for user root by rockylinux>
Oct 04 02:00:34 workstation sudo[3096]: pam_unix(sudo:session): session closed for user root
lines 1-5/5 (END)

從上述的執行指令所輸出訊息得知,指定了從「2021-10-04 02:00」到「2021-10-04 02:01」之間所有的日誌訊息。

若要印出更進一步的日誌訊息,則可以加上「-o」指令來做到,並印出每一行日誌訊息更進一步的資訊,相關執行指令的方式如下:

[rockylinux@workstation ~]$ sudo journalctl -o verbose
-- Logs begin at Mon 2021-10-04 00:57:49 CST, end at Mon 2021-10-04 02:12:14 CST. --
Mon 2021-10-04 00:57:49.016975 CST [s=bb474c55c28e46f4acdf3f7ab2cb8098;i=1;b=b799208c374f4d01a15b01fc01908>
    _SOURCE_MONOTONIC_TIMESTAMP=0
    _TRANSPORT=kernel
    PRIORITY=5
-- Logs begin at Mon 2021-10-04 00:57:49 CST, end at Mon 2021-10-04 02:12:14 CST. --
Mon 2021-10-04 00:57:49.016975 CST [s=bb474c55c28e46f4acdf3f7ab2cb8098;i=1;b=b799208c374f4d01a15b01fc01908>
    _SOURCE_MONOTONIC_TIMESTAMP=0
......

此外,也可以使用「_SYSTEMD_UNIT」與「_PID」之參數來指定要觀看某一個背景服務的日誌訊息,以Apache server為例,可以知道背景服務名稱為「httpd.service」,並可以使用「sudo systemctl status httpd.service」來觀看此背景服務目前跑在哪一個process id上,假設prcoess id為1230,而相關執行指令所輸出的訊息如下:

[rockylinux@workstation ~]$ sudo journalctl _SYSTEMD_UNIT=httpd.service _PID=1230
-- Logs begin at Mon 2021-10-04 00:57:49 CST, end at Mon 2021-10-04 02:19:10 CST. --
Oct 04 00:58:36 workstation httpd[1230]: AH00558: httpd: Could not reliably determine the server's fully q>
Oct 04 00:58:36 workstation httpd[1230]: Server configured, listening on: port 80
lines 1-3/3 (END)

課後練習

  • 請打開「workstation」虛擬機器,並以「rockylinux」之使用者登入並開啟終端機。
  • 使用「tail」這個指令來監控「/var/log/messages」上的日誌訊息,並設法在監控期間發送一個日誌等級為user.notice之訊息。
  • 除了使用「-n」參數來觀看目前指定日誌訊息內容之最後行數,也可以用其他的指令搭配做到,請使用「tail」指令並找出最後10行的日誌訊息,要同時用到「journalctl」與「tail」指令,並請以一行完成這個指令。
  • 找到SSHD服務目前所執行的程序狀態與資訊,並取得其prcoess id,並使用「journalctl」來指定SSHD服務與其prcoess id找到SSHD相關的日誌訊息。

上一篇
第12章:SSH遠端連線設定與原理介紹(三)
下一篇
第13章:分析、儲存與存取系統日誌介紹(二)
系列文
Rocky Linux 8:系統管理與維運實戰23

尚未有邦友留言

立即登入留言