root宛メールを普段使うメールアドレスに転送しています
毎日何かしらのメールが届いていますが、ここ2週間くらい届いていないことに気が付きました
原因調査
postfixのログ確認
まずpostfixのログを確認しました
systemctl status postfix.service ● postfix.service - Postfix Mail Transport Agent Loaded: loaded (/usr/lib/systemd/system/postfix.service; enabled; vendor preset: disabled) Active: failed (Result: exit-code) since 金 2022-04-01 06:32:02 JST; 1 weeks 6 days ago Process: 1708 ExecStop=/usr/sbin/postfix stop (code=exited, status=0/SUCCESS) Process: 1729 ExecStart=/usr/sbin/postfix start (code=exited, status=0/SUCCESS) Process: 1726 ExecStartPre=/usr/libexec/postfix/chroot-update (code=exited, status=0/SUCCESS) Process: 1722 ExecStartPre=/usr/libexec/postfix/aliasesdb (code=exited, status=0/SUCCESS) Main PID: 1805 (code=exited, status=1/FAILURE) Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable.
ステータスが「failed」になっている上、「Journal has been rotated since unit was started. Log output is incomplete or unavailable.」というエラーが表示されています
ジャーナルに関するエラーっぽいので、ジャーナルのサービスも見てみることにします
ジャーナルのログ確認
systemctl status systemd-journald
● systemd-journald.service - Journal Service
Loaded: loaded (/usr/lib/systemd/system/systemd-journald.service; static; vendor preset: disabled)
Active: active (running) since 水 2021-12-15 15:21:45 JST; 3 months 28 days ago
Docs: man:systemd-journald.service(8)
man:journald.conf(5)
Main PID: 488 (systemd-journal)
Status: "Processing requests..."
CGroup: /system.slice/systemd-journald.service
mq488 /usr/lib/systemd/systemd-journald
4月 09 00:40:02 xxx.xxx.com systemd-journal[488]: Suppressed 143283 messages from /user.slice/user
4月 10 00:45:01 xxx.xxx.com systemd-journal[488]: Suppressed 143392 messages from /user.slice/user
4月 11 00:40:01 xxx.xxx.com systemd-journal[488]: Suppressed 143277 messages from /user.slice/user
4月 12 00:45:01 xxx.xxx.com systemd-journal[488]: Suppressed 143401 messages from /user.slice/user
4月 13 00:45:01 xxx.xxx.com systemd-journal[488]: Suppressed 143426 messages from /user.slice/user
4月 14 00:40:01 xxx.xxx.com systemd-journal[488]: Suppressed 143448 messages from /user.slice/user
Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable.
Suppressed xxxxxx messagesと表示されていて多くのログが記録できなかったことが書かれています
また、postfixのステータスと同様に、「Journal has been rotated since unit was started. Log output is incomplete or unavailable.」とエラーが表示されていました
ログの容量確認
ll -h /var/log/maillog* -rw------- 1 root root 1.8M 4月 14 13:38 /var/log/maillog -rw------- 1 root root 23M 3月 20 05:13 /var/log/maillog-20220320 -rw------- 1 root root 271M 3月 27 03:38 /var/log/maillog-20220327 -rw------- 1 root root 212M 4月 3 01:32 /var/log/maillog-20220403 -rw------- 1 root root 932K 4月 10 06:41 /var/log/maillog-20220410
オプションにhを付けて、容量を見やすくしてます
20220327から急にログの容量が増えていることが分かります
どのようなログが表示されているのか内容を確認してみます
ログの内容確認
メールが来なくなったのが4月1日からなので、そのあたりのログを確認します
vi /var/log/maillog-20220403 Apr 1 01:32:46 xxxxxx dovecot: auth-worker(17267): pam Apr 1 01:32:46 xxxxxx dovecot: auth-worker(17266): Debug: Apr 1 01:32:46 xxxxxx dovecot: auth: Debug: Apr 1 01:32:46 xxxxxx dovecot: auth: Debug:
詳細は省きますが、ログを見ていると「dovecot:auth-worker」、「dovecot:auth: Debug:」などdovecotのログがかなりたくさん表示されていました
dovecotのログ設定を見てみます
dovecotのログ設定確認
そういえばdovecot構築しているときにエラー出力を詳細に表示する設定があったなーと思いまして、設定が入っているか見てみました
vi /etc/dovecot/dovecot.conf auth_verbose = yes auth_debug = yes
下2行がdovecotの詳細なエラー出力を表示させる設定です
これが原因でしょう
以前dovecotを構築していた時に、確認用にログを詳細に出すようにしていたので、当時の設定を戻しそびれていたんだと思います
解決策
dovecot設定変更
先ほどの2行を消去しました
vi /etc/dovecot/dovecot.conf auth_verbose = yes ←消す auth_debug = yes ←消す
あとは各サービスを再起動です
サービス再起動
まずは設定変更したのでdovecot
systemctl restart dovecot
次は、サービスが止まっているpostfix
systemctl restart postfix
最後にジャーナルです
systemctl restart systemd-journald
サービスステータス確認
各ステータスを確認し、サービスがactiveでエラーが出ていなければOKです
systemctl status dovecot
systemctl status postfix
systemctl status systemd-journald
コメント