Linuxにおけるシステムログ
どのようなコンピュータシステムでもそうですが、セキュリティ面や障害発生時などの追跡に使うログはLinuxシステム上ではいくつかの機能から成っています。
以下に私がイメージできたLinuxシステムにおけるjournaldとrsyslogの関係を図示します。
※RHEL(CentOS)の7系
syslog
Syslog は、ログメッセージをIPネットワーク上で転送するための標準規格である。"Syslog" という用語は、その通信プロトコルを指すだけでなく、Syslog メッセージを送信するアプリケーションやライブラリに対しても使われる。
Syslog は一般に、コンピュータシステムの管理とセキュリティ監視を目的として使われる。いくつか問題はあるものの、syslog は各種プラットフォーム上で広くサポートされている。そのため、Syslog を使って様々なシステムのログデータを1つの集中リポジトリで管理することも可能である。
syslogでは様々な事象をログファイルに記録したり、他の機器やプログラムからの出力を指定した出力先に送ることができます。
ネットワーク機器からのログをサーバに収集するなどの用途でも活用される。
古くから使用されているログ管理の仕組みですが、近年では新たな仕組みとしてrsyslogやsyslog-ngが採用されてます。
LPIC的にはrsyslogが重要となるので、ここではrsyslogを中心に見ていきます。
rsyslog
rsyslogはsyslogの次世代にあたるログ管理を行うシステムユーティリティです。
主要な機能として、各種デーモンやプログラムからログを収集し、ファイルに出力するという機能を持ちますが、特に現在では多様な機能を備えているため、単にそれだけの機能と思わずにできることを確実に把握していった方がよさそうです。
その中で実際に処理を実施しているのが、rsyslogdデーモンになります。
rsyslogの設定ファイル
rsyslogの設定ファイルは主要な設定を行う「/etc/rsyslog.conf」と「/etc/rsyslog.d/」配下に配置された各種confファイルになります。
■rsyslog.confにおけるグローバル設定
まずはファイル全体にかかる設定部分を確認します。
この辺は、LPIC的には重要度は下がるかもしれませんので軽めにいきます。
・モジュールの読み込み
rsyslogで実現するプラグイン機能のためにモジュールの読み込みを行います。
$ModLoad imuxsock
・作業ディレクトリ
以降の設定で使用する作業ディレクトリの指定。
$WorkDirectory /var/lib/rsyslog
・書式設定
ActionFileDefaultTemplate RSYSLOG_TraditionalFileFormat
・設定ディレクトリ
読み込みを行う詳細な設定ファイルを指定します。
$IncludeConfig /etc/rsyslog.d/*.conf
ログ出力の設定
LPIC的にはこちらのどのようなログをどこに出力するかという設定の方が重要度は上がります。
実践的にもログの設定を変更する場合には、他はデフォルト設定のまま運用してもこちらの設定の方は変更することの方がおおいのではないかと思います。
先に書式を示します。
コンピュータ内で行った事象を全て記録すると、ログファイルだけでも膨大な量になってしまうため、ある程度必要なものに絞って出力を行うことが多いでしょう。
どの出力元（ファシリティ）のどのくらいの重要度（プライオリティ）の事象をどこへ（出力先）出力するかというイメージでしょうか。詳細はこの後追っていきます。
[ファシリティ].[プライオリティ] [出力先]
■ファシリティ
ファシリティはメッセージの生成元のことで、各種プロセスなどが該当します。
・主要なファシリティ一覧
| ファシリティ | 内容 |
|---|---|
| auth | ログインなどの認証 |
| cron | クーロン |
| deamon | デーモン |
| kern | カーネル |
| lpr | 印刷システム |
| メールサービス | |
| user | ユーザアプリケーション |
| local0-7 | 0～7のローカルシステム |
■プライオリティ
プライオリティは出力メッセージの重要度を記述します。
基本的にはプライオリティが低いほど多くの情報を出力することになります。低い場合にはより多くの情報を出力することになり、ややもすると重要な情報が埋もれてしまうことも考えられるので、適切なプライオリティを設定する必要があります。
・プライオリティ一覧
下にいくほど多くのプライオリティが低く、多くの情報を出力することになります。
| プライオリティ | 内容 |
|---|---|
| emerg | 緊急 |
| alert | 早急に対応が必要 |
| crit | 深刻な事象 |
| err | 一般的なエラー |
| warning | 一般的な警告 |
| notice | 一般的な通知 |
| info | 一般的な情報 |
| debug | デバック情報 |
| none | ログを出力しない |
■出力先
出力先はイメージそのままですが、ファイル（ログファイル）以外の出力形式も試験的に出題範囲になるので、記述方法は把握しておく必要があります。
・出力先の記述形式
| 出力先 | 内容 |
|---|---|
| /var/log/message | ログファイルに出力 |
| /dev/tty1 | コンソールに出力 |
| @[ホスト名] | ホストにUDPで出力 |
| @@[ホスト名] | ホストにTCPで出力 |
| * | ログイン中の全てのユーザに出力 |
■rsyslog.confファイルの記述例
以下に記述例として、私の環境のデフォルト設定をコメント行を除いて出力します。
[wantan@localhost ~]$ cat /etc/rsyslog.conf | grep -v '^\s*#' | grep -v '^\s*$' $ModLoad imuxsock # provides support for local system logging (e.g. via logger command) $ModLoad imjournal # provides access to the systemd journal $WorkDirectory /var/lib/rsyslog $ActionFileDefaultTemplate RSYSLOG_TraditionalFileFormat $IncludeConfig /etc/rsyslog.d/*.conf $OmitLocalLogging on $IMJournalStateFile imjournal.state *.info;mail.none;authpriv.none;cron.none /var/log/messages authpriv.* /var/log/secure mail.* -/var/log/maillog cron.* /var/log/cron *.emerg :omusrmsg:* uucp,news.crit /var/log/spooler local7.* /var/log/boot.log
ログ出力系コマンド
loggerコマンド
ログに関するコマンドの一つにloggerコマンドというコマンドがあります。
loggerコマンドは前述のrsyslogによるログ出力を手動で実行するようなイメージになります。
■オプション
・-p：プライオリティを指定する
・-t：タグを設定する
・コマンドの実行例
logger -p cron.info "test message"
なお出力先については一般的に指定されませんが、rsyslog.confを参照してプライオリティに応じて出力先を決定します。
例えば上記の例では「cron」の設定を確認すると。
[root@localhost log]# grep cron /etc/rsyslog.conf *.info;mail.none;authpriv.none;cron.none /var/log/messages # Log cron stuff cron.* /var/log/cron
cronはプライオリティに限らず/var/log/cronに出力するのでファイルを確認してみる。
[root@localhost log]# tail -f /var/log/cron Dec 17 22:52:09 localhost wantan: test message Dec 17 23:00:01 localhost CROND[1521]: (wantan) CMD (source /usr/local/bin/vmstat.sh) Dec 17 23:01:01 localhost CROND[1526]: (root) CMD (run-parts /etc/cron.hourly) Dec 17 23:01:01 localhost run-parts(/etc/cron.hourly)[1526]: starting 0anacron Dec 17 23:01:01 localhost anacron[1535]: Anacron started on 2020-12-17 Dec 17 23:01:01 localhost run-parts(/etc/cron.hourly)[1537]: finished 0anacron Dec 17 23:01:01 localhost anacron[1535]: Normal exit (0 jobs run)
一番上の行にloggerコマンドによる出力がされていることが分かる。
loggerコマンドはrsyslogdにより出力されるログが、想定した出力先に出力されているかなど検証に使用することが多いようです。
systemd-catコマンド
systemd-catコマンドもloggerコマンドと似ており、手動でジャーナルファイル（ログファイル）に出力を行うことができますが、こちらはコマンドの結果を出力することを前提とされているようです。
原則としてはsystemdを採用したディストリビューションで使用することになります。
・コマンドの実行例
[root@localhost log]# systemd-cat df -h
・ログの出力結果例（抜粋）
[root@localhost log]# tail -n 20 /var/log/messages Dec 17 23:31:29 localhost journal: ファイルシス サイズ 使用 残り 使用% マウント位置 Dec 17 23:31:29 localhost journal: devtmpfs 475M 0 475M 0% /dev Dec 17 23:31:29 localhost journal: tmpfs 487M 0 487M 0% /dev/shm Dec 17 23:31:29 localhost journal: tmpfs 487M 7.6M 479M 2% /run Dec 17 23:31:29 localhost journal: tmpfs 487M 0 487M 0% /sys/fs/cgroup Dec 17 23:31:29 localhost journal: /dev/mapper/centos-root 17G 3.3G 14G 20% / Dec 17 23:31:29 localhost journal: /dev/sda1 1014M 168M 847M 17% /boot Dec 17 23:31:29 localhost journal: tmpfs 98M 0 98M 0% /run/user/1000
プライオリティの-pオプションによりできますが、基本的にはファシリティはsyslogになるようです。
なので、標準であれば結果は「/var/log/messages」に出力されます。
journalctlコマンド
journalctlコマンドはsystemdを採用したシステムにおいて、ログ（ジャーナル）を表示・参照するためのコマンドになります。
試験的な重要度はそれなりにあるっぽいですが、普段使用していない（私もそう）とオプションが多くてやや大変なイメージ。
■主要オプション
| オプション | フル表記 | 内容 |
|---|---|---|
| -a | --all | 全てのログを出力 |
| -f | --follow | ログ末尾を表示し続ける |
| -r | --reverse | 新しい順に出力 |
| -x | --catalog | 追加説明で出力 |
| -k | --dmesg | カーネルメッセージを出力 |
| -b | --boot | ブート時のメッセージを出力 |
| -p | --priority= | 指定プライオリティ以上のメッセージを出力 |
| -u | --unit= | 指定Unitのログを出力 |
| -l | --full | 表示可能な全てのログを出力 |
| --until | 指定した時刻までのログを表示 | |
| --vacuum-size= | 総量が指定サイズを下回るまでアーカイブジャーナルを削除 | |
| --vacuum-time= | 指定期間より古いアーカイブジャーナルを削除 |
以下にいくつかの実行例を示します。
・ジャーナルログを表示する
オプションなしで実行すると古い方のログからページャ形式（lessコマンドと同様）で表示されます。
[root@localhost log]# journalctl -- Logs begin at 日 2020-12-20 23:14:25 JST, end at 日 2020-12-20 23:40:01 JST. -- 12月 20 23:14:25 localhost.localdomain systemd-journal[89]: Runtime journal is using 6.0M (max allowed 48.6M, trying to leave 72.9M free of 480.0M available → current limit 48.6M). 12月 20 23:14:25 localhost.localdomain kernel: Initializing cgroup subsys cpuset 12月 20 23:14:25 localhost.localdomain kernel: Initializing cgroup subsys cpu 12月 20 23:14:25 localhost.localdomain kernel: Initializing cgroup subsys cpuacct 12月 20 23:14:25 localhost.localdomain kernel: Linux version 3.10.0-1127.13.1.el7.x86_64 (mockbuild@kbuilder.bsys.centos.org) (gcc version 4.8.5 20150623 (Red Hat 4.8.5-39) (GCC) ) #1 SMP Tue Jun 23 15:46:38 UTC 2020 12月 20 23:14:25 localhost.localdomain kernel: Command line: BOOT_IMAGE=/vmlinuz-3.10.0-1127.13.1.el7.x86_64 root=/dev/mapper/centos-root ro crashkernel=auto spectre_v2=retpoline rd.lvm.lv=centos/root rd.lvm.lv=centos/swap rhgb quiet LANG=ja_JP.UTF-8 12月 20 23:14:25 localhost.localdomain kernel: Disabled fast string operations 12月 20 23:14:25 localhost.localdomain kernel: e820: BIOS-provided physical RAM map: 12月 20 23:14:25 localhost.localdomain kernel: BIOS-e820: [mem 0x0000000000000000-0x000000000009ebff] usable ＊＊省略＊＊
・追加ログのリアルタイム表示する
「tail -f」コマンドと同様の挙動で、追加されたログを表示していきます。
[root@localhost log]# journalctl -f -- Logs begin at 日 2020-12-20 23:14:25 JST. -- 12月 20 23:38:57 localhost.localdomain systemd[1]: Starting Network Manager Script Dispatcher Service... 12月 20 23:38:57 localhost.localdomain dhclient[856]: bound to 192.168.142.11 -- renewal in 858 seconds. 12月 20 23:38:57 localhost.localdomain dbus[681]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher' 12月 20 23:38:57 localhost.localdomain systemd[1]: Started Network Manager Script Dispatcher Service. 12月 20 23:38:57 localhost.localdomain nm-dispatcher[1382]: req:1 'dhcp4-change' [ens33]: new request (3 scripts) 12月 20 23:38:57 localhost.localdomain nm-dispatcher[1382]: req:1 'dhcp4-change' [ens33]: start running ordered scripts... 12月 20 23:40:01 localhost.localdomain systemd[1]: Started Session 6 of user wantan. 12月 20 23:40:01 localhost.localdomain CROND[1402]: (wantan) CMD (source /usr/local/bin/vmstat.sh) 12月 20 23:50:01 localhost.localdomain systemd[1]: Started Session 7 of user wantan. 12月 20 23:50:01 localhost.localdomain CROND[1428]: (wantan) CMD (source /usr/local/bin/vmstat.sh)
・カーネルからのメッセージを表示
「dmesg」と同様の出力になる。
[root@localhost log]# journalctl -k -- Logs begin at 日 2020-12-20 23:14:25 JST, end at 日 2020-12-20 23:53:16 JST. -- 12月 20 23:14:25 localhost.localdomain kernel: Initializing cgroup subsys cpuset 12月 20 23:14:25 localhost.localdomain kernel: Initializing cgroup subsys cpu 12月 20 23:14:25 localhost.localdomain kernel: Initializing cgroup subsys cpuacct 12月 20 23:14:25 localhost.localdomain kernel: Linux version 3.10.0-1127.13.1.el7.x86_64 (mockbuild@kbuilder.bsys.centos.org) (gcc version 4.8.5 20150623 (Red Hat 4.8.5-39) (GCC) ) #1 SMP Tue Jun 23 15:46:38 UTC 2020 12月 20 23:14:25 localhost.localdomain kernel: Command line: BOOT_IMAGE=/vmlinuz-3.10.0-1127.13.1.el7.x86_64 root=/dev/mapper/centos-root ro crashkernel=auto spectre_v2=retpoline rd.lvm.lv=centos/root rd.lvm.lv=centos/swap rhgb quiet LANG=ja_JP.UTF-8 12月 20 23:14:25 localhost.localdomain kernel: Disabled fast string operations 12月 20 23:14:25 localhost.localdomain kernel: e820: BIOS-provided physical RAM map: 12月 20 23:14:25 localhost.localdomain kernel: BIOS-e820: [mem 0x0000000000000000-0x000000000009ebff] usable 12月 20 23:14:25 localhost.localdomain kernel: BIOS-e820: [mem 0x000000000009ec00-0x000000000009ffff] reserved
但し、dmesgと比較して出力形式は多少異なります。
[root@localhost log]# dmesg [ 0.000000] Initializing cgroup subsys cpuset [ 0.000000] Initializing cgroup subsys cpu [ 0.000000] Initializing cgroup subsys cpuacct [ 0.000000] Linux version 3.10.0-1127.13.1.el7.x86_64 (mockbuild@kbuilder.bsys.centos.org) (gcc version 4.8.5 20150623 (Red Hat 4.8.5-39) (GCC) ) #1 SMP Tue Jun 23 15:46:38 UTC 2020 [ 0.000000] Command line: BOOT_IMAGE=/vmlinuz-3.10.0-1127.13.1.el7.x86_64 root=/dev/mapper/centos-root ro crashkernel=auto spectre_v2=retpoline rd.lvm.lv=centos/root rd.lvm.lv=centos/swap rhgb quiet LANG=ja_JP.UTF-8 [ 0.000000] Disabled fast string operations [ 0.000000] e820: BIOS-provided physical RAM map: [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009ebff] usable [ 0.000000] BIOS-e820: [mem 0x000000000009ec00-0x000000000009ffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000000dc000-0x00000000000fffff] reserved
・エラー以上のプライオリティのみを表示する
特定プライオリティ以上の重要度のメッセージのみを出力することができます。
[root@localhost log]# journalctl -p err -- Logs begin at 日 2020-12-20 23:14:25 JST, end at 月 2020-12-21 00:10:01 JST. -- 12月 20 23:14:26 localhost.localdomain kernel: sd 0:0:0:0: [sda] Assuming drive cache: write through 12月 20 23:14:33 localhost.localdomain kernel: piix4_smbus 0000:00:07.3: SMBus Host Controller not enabled! 12月 20 23:14:46 localhost.localdomain systemd[1]: Failed to start Crash recovery kernel arming. 12月 20 23:14:47 localhost.localdomain rsyslogd[1049]: imjournal: fscanf on state file `/var/lib/rsyslog/imjournal.state' failed [v8.24.0-52.el7_8.2 try http://www.rsyslog.com/e/2027 ] 12月 20 23:14:47 localhost.localdomain rsyslogd[1049]: imjournal: ignoring invalid state file [v8.24.0-52.el7_8.2]
・特定時刻のログを出力する
--sinceオプションと--untilオプションを組み合わせ、またはどちらかを使用することで時刻を指定します。
[root@localhost log]# journalctl --since "2020-12-20 23:15:00" --until "2020-12-21 00:00:00" -- Logs begin at 日 2020-12-20 23:14:25 JST, end at 月 2020-12-21 00:20:01 JST. -- 12月 20 23:15:00 localhost.localdomain systemd[1]: Started MySQL Server. 12月 20 23:15:00 localhost.localdomain systemd[1]: Reached target Multi-User System. 12月 20 23:15:00 localhost.localdomain systemd[1]: Starting Update UTMP about System Runlevel Changes... 12月 20 23:15:00 localhost.localdomain systemd[1]: Started Update UTMP about System Runlevel Changes. 12月 20 23:15:00 localhost.localdomain systemd[1]: Startup finished in 715ms (kernel) + 3.527s (initrd) + 31.587s (userspace) = 35.830s. 12月 20 23:15:06 localhost.localdomain sshd[1269]: Accepted password for wantan from 192.168.142.1 port 49876 ssh2 12月 20 23:15:06 localhost.localdomain systemd[1]: Created slice User Slice of wantan. 12月 20 23:15:06 localhost.localdomain systemd[1]: Started Session 1 of user wantan. 12月 20 23:15:06 localhost.localdomain systemd-logind[674]: New session 1 of user wantan. 12月 20 23:15:06 localhost.localdomain sshd[1269]: pam_unix(sshd:session): session opened for user wantan by (uid=0) 12月 20 23:15:19 localhost.localdomain su[1303]: (to root) wantan on pts/0 12月 20 23:15:19 localhost.localdomain su[1303]: pam_unix(su:session): session opened for user root by wantan(uid=1000)
・出力結果をディスプレイに表示する
デフォルトではページャ形式で表示されるので、grepコマンドその他にパイプで渡す場合などには「--no-pager」オプションで表示します。
[root@localhost log]# journalctl --no-pager | grep MySQL 12月 20 23:14:46 localhost.localdomain systemd[1]: Starting MySQL Server... 12月 20 23:15:00 localhost.localdomain systemd[1]: Started MySQL Server.
・エマージェンシーモードでの推奨出力
エマージェンシーモードで出力を促されるオプションとして「-xb」があります。
「-x」は説明は付与し、「-b」でブート起動時のログを出力しています。
[root@localhost log]# journalctl -xb --no-pager -- Logs begin at 日 2020-12-20 23:14:25 JST, end at 月 2020-12-21 00:30:01 JST. -- 12月 20 23:14:25 localhost.localdomain systemd-journal[89]: Runtime journal is using 6.0M (max allowed 48.6M, trying to leave 72.9M free of 480.0M available → current limit 48.6M). 12月 20 23:14:25 localhost.localdomain kernel: Initializing cgroup subsys cpuset 12月 20 23:14:25 localhost.localdomain kernel: Initializing cgroup subsys cpu 12月 20 23:14:25 localhost.localdomain kernel: Initializing cgroup subsys cpuacct
設定ファイル
ここまで紹介してきたjournalctlコマンドですが、その実態ファイルが存在する場所についてはディストリビューションなどによって異なるようです。
/var/log/journalや/var/run/log/journalや/var/run/log/journal/配下など。。
私の場合は/var/run/log/journal/配下のファイルにありました。
/run/log/journal/a44f5442fb4247c3b4b99c4a9ef8f08d/system.journal
いずれにしても共通点としてはバイナリファイルになっていること。なので基本コマンドでは参照できず、参照のためにjournalctlコマンドを使用する必要があります。
またjournalファイルに関する設定は「/etc/systemd/journald.conf」ファイルに設定されます。
揮発性であるjournalファイルを再起動時も維持する設定やファイルの最大サイズなどを規定するようですが、試験的な重要度はなんとも図りにくいところです。
各設定項目を空で覚えるのは結構厳しそうな感じ。
以下には私の環境の設定ファイルを例示しますが、デフォルトでは全てコメントアウトされていました。
[Journal] #Storage=auto #Compress=yes #Seal=yes #SplitMode=uid #SyncIntervalSec=5m #RateLimitInterval=30s #RateLimitBurst=1000 #SystemMaxUse= #SystemKeepFree= #SystemMaxFileSize= #RuntimeMaxUse= #RuntimeKeepFree= #RuntimeMaxFileSize= #MaxRetentionSec= #MaxFileSec=1month #ForwardToSyslog=yes #ForwardToKMsg=no #ForwardToConsole=no #ForwardToWall=yes #TTYPath=/dev/console #MaxLevelStore=debug #MaxLevelSyslog=debug #MaxLevelKMsg=notice #MaxLevelConsole=info #MaxLevelWall=emerg #LineMax=48K
ログローテーション
ログに関する最後に、ログローテーションについて扱います。
サービスを提供するサーバなどはほぼ常に稼働しているため、数日も経てば膨大なログを発行します。
そのような状況で、ログを一つのファイルに追記し続けるのは容量を食ったり、本当に参照したい部分に対する追跡性が落ちたりします。そのため、Linux（他のOSでもだいたいそうだと思いますが）では発行日付ごとにログファイルを分けたり、不要になったログを削除するログローテーションの仕組みが用意されています。
logrotate
Linuxではログローテーションの仕組みとして、一般的にlogrotate（コマンド）が用意されています。
試験的にはログローテーションと言ったらこのlogrotateという認識で問題ないと思います。
もし、パッとイメージがつかない場合には/var/log/配下を覗いて見るのがはやい。
通常は特に自分で設定していなくても以下のようにローテーションが行われているはず。
-rw-------. 1 root root 11497 12月 22 00:10 cron -rw-------. 1 root root 13445 11月 28 19:42 cron-20201128 -rw-------. 1 root root 9329 11月 29 03:31 cron-20201129 -rw-------. 1 root root 6674 12月 14 19:25 cron-20201214 -rw-------. 1 root root 6508 12月 20 00:10 cron-20201220
■設定ファイル
logroateの設定ファイルは「/etc/logrotate.conf」です。
以下に私の環境でのデフォルト設定ファイルを示します。
#ローテーション周期 weekly #バックアップログの保存期間 rotate 4 #ローテーション後、空のログファイルを生成 create #ローテーションしたファイルの末尾に日付をつける dateext #/etc/logrotate.dを設定ファイルとして読み込む include /etc/logrotate.d #wtmpファイルの設定 /var/log/wtmp { monthly create 0664 root utmp minsize 1M rotate 1 }
ーーーーーーーーーーーーーーーーー
・前回（第八回）
www.wantanblog.com
・次回（第十回）
www.wantanblog.com
