本章節,是要講解系統日誌的架構與介紹
在一個標準的作業系統中,會有系統日誌,並分別存放檔案在某些路徑底下,每一種之系統log檔案所存放的資訊也有所不同,以下列出幾個重要的系統日誌檔案清單:
/var/log/messages
:這個檔案會存放大部分系統之資訊,像是關於使用者驗證的日誌、收發信箱之處理訊息、排程工作執行以及那些系統錯誤有關的訊息。/var/log/secure
:這個檔案會存放有關於作業系統上安全與驗證相關事件的訊息。/var/log/maillog
:這個檔案會存放有關於mail server的日誌訊息。/var/log/cron
:這個檔案會存放有關於排程工作執行的紀錄與相關日誌訊息。在寫入一筆日誌訊息的時候,需要注意每一個日誌都有分等級的,相關的日誌等級如下:
相關的基本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)