2020年9月末現在にfail2banに入っているpfパケットフィルタ用のアクション設定の内、Ban対象IPアドレスが発生した際に発動するactionbanは以下のようなの。条件によって多少違うかもだけど。
block drop quick proto tcp from <f2b-フィルタルール名> to any
仮にフィルタルール名をexampleとしてルールを作成して運用し、Ban対象になるログが記録されたとする。そのIPアドレスは192.168.0.11とする。
/var/log/fail2ban.log2020-09-30 12:00:00,000 fail2ban.actions [191]: NOTICE [example] Ban 192.168.0.11fail2banのフィルタルールexampleが作ったルール
# pfctl -a "f2b/example" -s rules block drop quick proto tcp fromf2b-exampleのフィルタルールでBanされているIPアドレスリストto any
# pfctl -a "f2b/example" -t f2b-example -T show
192.168.0.11
192.168.0.47
fail2banでexampleフィルタルールを有効にしたことで発生しているルールは予定どおりで問題ないように見える。
BanされているIPアドレスリストに192.168.0.11が含まれているので予定どおりの動作になっている。
そして、暫く後に確認したところ、192.168.0.11からはもう訪れることがなくなっていることが確認できた。
ところが
もう一度fail2banのログを見る
/var/log/fail2ban.log2020-09-30 12:00:10,500 fail2ban.filter [191]: INFO [localban] Found 192.168.0.11 - 2020-09-30 12:00:10 2020-09-30 12:00:11,000 fail2ban.actions [191]: NOTICE [localban] 192.168.0.11 already banned
しばらくこんなのが続いていた。「アクセスされたけど既にBanされてる」というメッセージ。凄い矛盾というかおかしな話。
サービスログを確認する
Sep 30 11:59:40 hoge example[25572]: client=[192.168.0.11], undesirable record
Sep 30 11:59:50 hoge example[25572]: client=[192.168.0.11], undesirable record
Sep 30 12:00:00 hoge example[25572]: client=[192.168.0.11], undesirable record
Sep 30 12:00:10 hoge example[25572]: client=[192.168.0.11], undesirable record
Sep 30 12:00:20 hoge example[25572]: client=[192.168.0.11], undesirable record
Sep 30 12:00:30 hoge example[25572]: client=[192.168.0.11], undesirable record
Sep 30 12:00:40 hoge example[25572]: client=[192.168.0.11], undesirable record
Sep 30 12:00:50 hoge example[25572]: client=[192.168.0.11], undesirable record
Sep 30 12:01:00 hoge example[25572]: client=[192.168.0.11], undesirable record
Sep 30 12:01:10 hoge example[25572]: client=[192.168.0.11], undesirable record
Sep 30 12:01:20 hoge example[25572]: client=[192.168.0.11], undesirable record
Sep 30 12:01:30 hoge example[25572]: client=[192.168.0.11], undesirable record
Sep 30 12:01:40 hoge example[25572]: client=[192.168.0.11], undesirable record
Sep 30 12:01:50 hoge example[25572]: client=[192.168.0.11], undesirable record
Sep 30 12:02:00 hoge example[25572]: client=[192.168.0.11], undesirable record
Sep 30 12:02:10 hoge example[25572]: client=[192.168.0.11], undesirable record
Sep 30 12:02:20 hoge example[25572]: client=[192.168.0.11], undesirable record
Sep 30 12:02:30 hoge example[25572]: client=[192.168.0.11], undesirable record
Sep 30 12:02:40 hoge example[25572]: client=[192.168.0.11], undesirable record
Sep 30 12:02:50 hoge example[25572]: client=[192.168.0.11], undesirable record
黄色の行がfail2banによってBanが確定したログ。Banされた時刻以降もたしかにアクセスが続いている。
12:00:00にBanされたら以降のアクセスは無いことを期待すると思うが、実際にはしばらく(意外と長く)アクセスが続くことがある。
fail2banがログを読んでBanと認識したのが実際には12:00:00より数分遅いのかというとそうではないらしい。そしてBan対象の192.168.0.11から全く新しい通信を行おうとした場合は12:00:00直後からでもアクセスできないっぽい。
どうも、セッションが切断されずに継続される場合はBanを発生させても通信は遮断されないよう。辞めた従業員を翌日以降も顔パスで会社に出入りさせてる警備員みたいな感じ。
この挙動はfail2banではなくpfが引き起こしてるみたい。
ググってみたらこんなやりとりがあった。
https://github.com/fail2ban/fail2ban/issues/1924
攻撃的？なぜ揉めてるのかニュアンスが理解できないのだが、単純にBanしたついでに pfctl -k IPアドレス を実行するんで良くない？ってことでこれを採用。
pf用のアクションを決めているファイルは/usr/local/etc/fail2ban/action.d/pf.conf
actionban = <pfctl> -t <tablename>-<name> -T add <ip> && <pfctl> -k <ip>
黄色の部分が元のアクションから増えた部分。
いまのところ、これで期待したとおりBan後は問答無用で遮断されるという動作になっている。
つまり、長らくpfの動きを正しく理解せずに使ってたということだけど、dropルールより状態を優先させる動きがデフォルトってヘンじゃないかしら？
タイトルにはFreeBSDって付けてるが、FreeBSD以外でもpfが使えるOSでおそらく同じ？
