画像準備中
概要
自作スクリプト（bash, python）を systemd に登録してサービス化している。
スクリプト内で出力するログに severity を付けるのに苦労したため、まとめた。
条件
- systemd のサービス単位でまとめてログを見たい（
journalctl -u <サービス名>の実行結果に表示されること） - ログを severity 付きで syslog サーバに転送したい
結論
- bash の場合
echo "<SEVERITY_NUMBER>MESSAGE"
- python の場合
print("<SEVERITY_NUMBER>MESSAGE")
環境
概要図
画像準備中
※取り急ぎこんな感じ
----------------------------------------------------- ------------------- | bash --> systemd --> journald --> rsyslogd (client) | ---> | rsyslogd (server) | ----------------------------------------------------- -------------------
構成
前提
- bash のコードで説明する。
事象とか困っていることとか
step 1
まずは echo するだけの bash スクリプトを作成し、systemd のサービスに登録した。
設定
#!/bin/bash echo "This is info message." echo "This is err message."
[Unit] Description=logging-test [Service] Type=simple ExecStart=bash /tmp/logging-test.bash [Install] WantedBy=multi-user.target
実行
[root@server ~]# systemctl start logging-test.service
確認
[root@server ~]# journalctl -u logging-test.service -- Logs begin at Sun 2024-02-25 22:21:52 JST, end at Tue 2024-02-27 20:56:20 JST. -- 2月 27 20:56:20 server systemd[1]: Started logging-test. 2月 27 20:56:20 server bash[441780]: This is info message. 2月 27 20:56:20 server bash[441780]: This is err message. 2月 27 20:56:20 server systemd[1]: logging-test.service: Succeeded.
※ info 抜粋
[root@server ~]# journalctl -u logging-test.service -p info..info -- Logs begin at Sun 2024-02-25 22:21:52 JST, end at Tue 2024-02-27 20:56:20 JST. -- 2月 27 20:56:20 server systemd[1]: Started logging-test. 2月 27 20:56:20 server bash[441780]: This is info message. 2月 27 20:56:20 server bash[441780]: This is err message. 2月 27 20:56:20 server systemd[1]: logging-test.service: Succeeded.
※ err 抜粋
[root@server ~]# journalctl -u logging-test.service -p err..err -- Logs begin at Sun 2024-02-25 22:21:52 JST, end at Tue 2024-02-27 20:56:20 JST. -- -- No entries --
どちらのログも severity は info になっている。
step 2
ここからが本題。This is err message. のログの severity を err にしたい。logger で試してみた。
設定
#!/bin/bash logger -p info "This is info message." logger -p err "This is err message."
実行
[root@server ~]# systemctl start logging-test.service
確認
[root@server ~]# journalctl -u logging-test.service -- Logs begin at Sun 2024-02-25 22:21:52 JST, end at Tue 2024-02-27 20:59:11 JST. -- --- snip --- 2月 27 20:59:09 server systemd[1]: Started logging-test. 2月 27 20:59:09 server systemd[1]: logging-test.service: Succeeded.
ログが記録されていない。
systemd のユニット（サービス）のログに記録されるのは、あくまでスクリプト内の標準出力と標準エラー出力のみ。logger は直接 journald (rsyslogd) にログを送っているため、ここには記録されない。
なお、syslog サーバ側では severity 付きでログを受信できている。
調査
systemd のユニット（サービス）としてログを出力しつつ、 severity を指定する方法を探したところ、以下が見つかった。Thank you so much ! 0pointer.de
echo コマンドの頭に severity の識別子を付与するらしい。なんだ、そんな書式聞いたことがない。
echo "<SEVERITY_NUMBER>MESSAGE"
SEVERITY_NUMBER と severity の対応は以下。
| SEVERITY_NUMBER | severity |
|---|---|
| 0 | Emergency |
| 1 | Alert |
| 2 | Critical |
| 3 | Error |
| 4 | Warning |
| 5 | Notice |
| 6 | Informational |
| 7 | Debug |
検証
設定
#!/bin/bash echo "<6>This is info message." echo "<3>This is err message."
実行
[root@server ~]# systemctl start logging-test.service
確認
[root@server ~]# journalctl -u logging-test.service -- Logs begin at Sun 2024-02-25 22:21:52 JST, end at Tue 2024-02-27 21:11:26 JST. -- --- snip --- 2月 27 21:11:24 server systemd[1]: Started logging-test. 2月 27 21:11:24 server bash[441844]: This is info message. 2月 27 21:11:24 server bash[441844]: This is err message. 2月 27 21:11:24 server systemd[1]: logging-test.service: Succeeded.
※ info 抜粋
[root@server ~]# journalctl -u logging-test.service -p info..info -- Logs begin at Sun 2024-02-25 22:21:52 JST, end at Tue 2024-02-27 21:11:26 JST. -- --- snip --- 2月 27 21:11:24 server systemd[1]: Started logging-test. 2月 27 21:11:24 server bash[441844]: This is info message. 2月 27 21:11:24 server systemd[1]: logging-test.service: Succeeded.
※ err 抜粋
[root@server ~]# journalctl -u logging-test.service -p err..err -- Logs begin at Sun 2024-02-25 22:21:52 JST, end at Tue 2024-02-27 21:11:26 JST. -- 2月 27 21:11:24 server bash[441844]: This is err message.
おお、<3>、<6> の文字がログから消えている。面白い。
そして、 severity が付与されている。
syslog サーバ側でも severity 付きで受信できている。
補足
- bash の printf だと以下。
printf "<6>This is info message.\n" printf "<3>This is err message.\n"
- python だと以下。
print("<6>This is info message.") print("<3>This is err message.")
- ちなみにログインシェルで実行しても意味はない。
[root@server ~]# echo "<3>This is err message." <3>This is err message.
- journalctl コマンドに
-o verboseを付けると severity が見える（PRIORITY という項目） 。
[root@server ~]# journalctl -u logging-test.service -o verbose
Tue 2024-02-27 21:57:10.029831 JST [s=e9efc3fea5734e74aa01d2375b257426;i=5b55;b=783be12125304676a886445aea612545;m=27e368ef58;t=6125c90734a>
SYSLOG_FACILITY=3
_UID=0
_GID=0
_CAP_EFFECTIVE=1ffffffffff
_BOOT_ID=xxx
_MACHINE_ID=xxx
_HOSTNAME=server
_TRANSPORT=stdout
PRIORITY=3
_COMM=bash
SYSLOG_IDENTIFIER=bash
_SYSTEMD_UNIT=logging-test.service
MESSAGE=This is err message.
_STREAM_ID=xxx
_PID=442722
_SYSTEMD_INVOCATION_ID=xxx
あとがき
狐につままれた気分。設定やコーディングで解決するイメージしか持っていなかった。まさか OS の既存の実装に答えがあるとは。。。
参考記事
https://0pointer.de/blog/projects/journal-submit.html
※検索用ワード シビアリティ/セベリティ/プライオリティ/ログレベル
