bokumin.org

RSS Sitemap Mail
ritual-clearcut

fail2banのログがnewsyslogで止まる（FreeBSD）

Category: FreeBSD, newsyslog
Tag:

fail2ban Logs Stop with newsyslog (FreeBSD)

事の発端

fail2banのログ（/var/log/fail2ban.log）が、newsyslogのローテーション後に書き込みを止めてしまうという問題が私の環境で起きていました。とりあえず、今まではcronで毎日fail2banをrestartして無理やり直していました。

restartすれば直るので、まあ運用上の実害はなかったのですが、SIGHUPで再オープンしてくれないのか、なぜrestartだと直るのかがずっと気になっていたので、原因から調べ直すことにしました。

環境

  • FreeBSD 14.4
  • fail2ban (py312-fail2ban-1.1.0_8)

原因を調べる

前提として、newsyslogは何も指定しなければローテーション後にSIGHUPを送るだけです。
私の/etc/newsyslog.conf.d/fail2ban.confもそうなっていました。

root:wheel  640  4  *  @T00  JC  /var/run/fail2ban/fail2ban.pid

pid_cmd_file列に/var/run/fail2ban/fail2ban.pidを指定しているので、ローテーション後はこのPIDに対してSIGHUPが送られる書き方になっています。

つまりシグナル自体はちゃんと飛んでいて、そのSIGHUPをfail2ban側がログの再オープンとして扱ってくれることを期待した設定でした。
ただfail2banはSIGHUPをそういう意味では扱っていないので、問題点となっています。

調べてみると、同じ現象の報告が複数見つかりました。

  • fail2ban本家のdiscussionで、FreeBSD + newsyslogの組み合わせでまったく同じ症状が報告されていて、メンテナーから「fail2ban-client flushlogsを使え」という回答がついている
  • FreeBSDのフォーラムでも同種の質問が複数あり、最終的にflushlogsで解決したという報告が複数見つかる
  • 別の報告では、fail2ban-client set logtarget ...やreloadではログ出力が復活せず、flushlogsまたはrestartでのみ復活することが確認されている

最後の「reloadでは直らず、restartでは直る」というのは、私の環境で起きていた現象と一致します。つまりfail2banのログハンドルの再オープンはfail2ban-client経由の明示的な指示（flushlogs）でしか行われないという仕様に近い制約が根本原因のようです。newsyslog側の設定ミスというより、rename+create型のログローテーションに対してfail2ban自身がSIGHUPで反応する作りになっていない、という話でした。

対策の方針

対策としてはシンプルで、newsyslogがローテーションした直後に、fail2ban-client flushlogsを呼ぶようにするだけです。

どう実現するかですが、newsyslog.confにはRフラグというものがあって、pid_cmd_fileの列をPIDファイルではなくコマンドとして実行させることができます。

最初、これを使って newsyslog.conf に

JCR  /usr/local/bin/fail2ban-client flushlogs >/dev/null 2>&1

のように1行で直接書けないかと思ったのですが、これは動きません。
newsyslog.confの各行は空白区切りの固定カラムとしてパースされる仕様で、Rフラグ時のpid_cmd_file列はスペースを含まない1トークン（実行ファイルへのパス）である必要があります。後ろに置けるのはせいぜい数値のシグナル番号くらいで、flushlogsや>/dev/nullのような文字列を続けて書くと余分な列として誤解釈され、設定エラーになります。さらにpid_cmd_fileは/bin/sh -c経由ではなく直接execされるため、仮にパースを通ったとしても>や2>&1はシェルのリダイレクトとして機能しません。
※OpenBSDのnewsyslogなら二重引用符でいけるみたいです。便利ですね。

というわけで、引数付きコマンドやリダイレクトを使いたい場合は、素直に1トークンで呼べる小さなスクリプトを挟むのが正解でした。

実装手順

flushlogs用スクリプトを作成

私は/usr/local/bin/libexecに置きましたが、環境によって扱いやすいところに置いてもらえたらと思います。

#!/bin/sh
/usr/local/bin/fail2ban-client flushlogs >/dev/null 2>&1

作成したスクリプトの権限を調整します。

chmod 755 /usr/local/libexec/f2b-flushlogs.sh

中身は先程のflushlogsを叩く1行だけのスクリプトです。

newsyslog.conf.d/fail2ban.conf を変更

newsyslogを以下のように書き直しました。

/var/log/fail2ban.log  root:wheel  640  4  *  @T00  JCR  /usr/local/libexec/f2b-flushlogs.sh

反映前にdry−runして構文チェックしましょう。構文エラーなどがでなければ完了です。

newsyslog -nv

まとめ

原因を追わずにrestartで曖昧にしていた状態だったので、ちゃんと調べてみて、SIGHUPに対するfail2banの挙動と、newsyslog.confのRフラグの制約の両方がすっきりした気持ちです。
結果的にやったことはスクリプトを1本挟んだだけですが、なぜrestartでしか直らなかったのかが解決したのが収穫だったと思います。

restartを外したことでログの日次バーストもなくなったので、しばらくこの構成で運用しつつ、ローテーションの直後にログが増え続けているかを眺めようと思います。

参考にした記事

おわり