CentOS7(RHEL7)でメールログが正常に出なかったときの対応
CentOS7で構築されたシステムでメルマガ配信などを行った際に、Posrfixのメールログ(/var/log/maillog)が
送信件数と比較して異常に少なかったので、その時の対応方法をメモしておきます。
CentOS7のメールログの出力の仕組み
CentOS7からログの出力はsystemd-journald.service(Journald)で管理されている。
Journaldからrsyslogがログを抜き取って、見慣れた/var/log/maillogを生成していました。
※説明はこちらが分かりやすいかもしれません
Linux女子部 systemd徹底入門
出力制限のログを確認
下記のようなログが出力されていたら、制限に引っかかってログが捨てられています。
Oct 13 19:15:35 moge journal: Suppressed 8385 messages from /system.slice/postfix.service
実際にjournalctlコマンドでpostfixのログを見ても制限された非常に少ないログ件数しかありませんでした。
Journaldの出力制限
journald.confのmanページに記載がある通り、10秒間で200以上のメッセージ出力が発生すると制限がかかります。
サービス毎の制限みたいなので、他のログ出力は妨げられることはないそうです。
[hoge@moge ~]$ man journald.conf
RateLimitInterval=, RateLimitBurst=
Configures the rate limiting that is applied to all messages generated on the system. If, in
the time interval defined by RateLimitInterval=, more messages than specified in
RateLimitBurst= are logged by a service, all further messages within the interval are
dropped until the interval is over. A message about the number of dropped messages is
generated. This rate limiting is applied per-service, so that two services which log do not
interfere with each other's limits. Defaults to 200 messages in 10s. The time specification
for RateLimitInterval= may be specified in the following units: "s", "min", "h", "ms", "us".
To turn off any kind of rate limiting, set either value to 0.
journaldの出力制限を緩和
出力したいメールの出力件数と時間から超えない程度に大きな値を設定して様子をみることにしました。
メールの件数だけを考慮すればいいので予測は立てやすいかと。
RateLimitInterval=10s
RateLimitBurst=20000
注意
メールログなどはメール1通で5～6メッセージ出力されるので計算を間違えないように注意が必要です。
journaldの出力は正常に出力されるようになった
journalctlコマンドでの出力結果は正常に出力されるようになったことが確認できました。
sudo journalctl -u postfix --no-pager | wc -l
ただ、まだメールログは正常に出力されていません！！
案の定、今度は下記のようなメッセージが捨てられた旨のログが出力されていました。
Oct 14 16:16:40 moge rsyslogd-2177: imjournal: begin to drop messages due to rate-limiting
Oct 14 16:17:18 moge rsyslogd-2177: imjournal: 108443 messages lost due to rate-limiting
rsyslogの出力制限
rsyslogがjournalからのログを受け取って出力するモジュールにも出力制限がありました。
seconds では、レート制限の間隔を設定します。この間隔内に処理されるメッセージ数は、burst_number で指定して値を超えることはでき ません。デフォルト設定は、600 秒あたり 20,000 メッセージです。Rsyslog は、この指定された時間枠内で最大バースト後に届いたメッセージを破棄します。
※詳細はこちら
サポート -> 製品マニュアル -> Red Hat Enterprise Linux -> 7 -> システム管理者のガイド - 18.6. RSYSLOG での構造化ロギング
rsyslogの出力制限の緩和
出力したいメールの出力件数と時間から超えない程度に大きな値を設定して様子をみることにしました。
この設定はメールだけじゃなく他のログ出力（/var/log/messages等）の件数も考慮する必要があるので
制限をかけるならかなり大きくする必要があります。
$imjournalRatelimitInterval 600
$imjournalRatelimitBurst 2400000
注意
下記の設定はjournalを経由しない方式でログを出力する場合の設定なので間違えないように
$SystemLogRateLimitInterval
$SystemLogRateLimitBurst
rsyslogの出力も正常に出力されるようになった
これで/var/log/maillogに正常な件数のログが出力されるようになりました。
最後に
実は出力されていなかったってパターンは、世の中的に結構ありそうな気がします。
/var/log/messages に制限に引っかかったログが出ていないかチェックしてみてはいかがでしょうか。
参考リンク
JOURNAL: SUPPRESSED MESSAGES FROM /SYSTEM.SLICE/POSTFIX.SERVICE
Linux女子部 systemd徹底入門
サポート -> 製品マニュアル -> Red Hat Enterprise Linux -> 7 -> システム管理者のガイド - 18.6. RSYSLOG での構造化ロギング
追記
2015/12/10
実は上記の設定値では、一部正常に動作していなかったことが発覚しました。
こちらを踏まえて計算すると
$imjournalRatelimitBurst 2400000 -> 40704
として動作していたと考えられます。