2006-07-19 (Wed)
■[pc][spam]Postfix-2.3でsleep中に切断されたらすぐに終了するパッチ 
Starpitなど、遅延を使ってスパム対策などを行っている場合、すぐに処理が終了しないため、smtpdプロセスが増加します。
Starpitでは経験的に、普段起動しているプロセス数の2倍〜3倍程度になるようです。
負荷の少ないメールサーバではほとんど問題となりませんが、受信するメールが非常に多いサーバの場合、プロセスの増加がメモリ消費などの点で(増加したプロセスはsleepしているだけなのでCPU負荷的には問題にならない)問題になることがあります。
そこで、遅延している間に相手が接続を切ったら、こちらのsmtpdもすぐに終了するようになるパッチを作成しました。
Postfix-2.3.x (最新 stable)に対してのパッチです。
http://k2net.hakuba.jp/pub/postfix-sleep.patch
(追記)
Postfix-2.2.1 対してはLukeさんが下記で配布いただいています。
http://blog.dyndns.tv/~luke/archives/postfix-2.2.1-sleephack.diff
このパッチにより、Starpitによるプロセス増加が遅延60sの場合で1.5倍ほどですむようになります。
または、Starpitにより増加したプロセス数を、遅延90sで40%程度、遅延60sで70%程度に減らすことが出来るようになります。
(追記)
このパッチを当てたPostfixでStarpitを導入された方は、できればsmtpdの平均プロセス数を導入前後で測っていただき、レポートいただけないでしょうか。
「ps ax|grep smtpd|wc -l」とかをcronで定期的にとっていただければありがたいですが、気がついた時に何回か測っていただいた平均程度でもかまいません。
こちらのコメントか、プロフィールのアドレスまでメールください。
また、このパッチを当てることの副効果として、どれだけ遅延が掛かかったときに切断されたかをログに残すことが出来ます。
それにより、スパマーがどのくらいのタイムアウトに設定しているのか客観的な情報を集めて、遅延時間を決めることが出来るようになります。
先日からこの週末あけまでにかけて、2つのまったく別の環境で運用された、パッチを当てたPostfixのログを採取できました。
sleep中に切断やこちらの反応前にDATAなど送ってきた場合、下記のようにログに残ります。(新パッチ版)
Jul 28 06:37:23 misorano postfix/smtpd[28066]: NOQUEUE: sleep: RCPT from 84.95.125.108.cable.012.net .il[84.95.125.108]: lost connection after 30 sec; from=<floey@ibancapr.com> to=<*****@hakuba.ne.jp> proto=SMTP helo=<ibancapr.com> Jul 28 06:41:54 misorano postfix/smtpd[28147]: NOQUEUE: sleep: RCPT from unknown[220.90.32.5]: pipel ining after 59 sec; from=<abc620526@0451.com> to=<******@hakuba.ne.jp> proto=ESMTP helo=<vanter.korn et.net> Jul 28 06:43:11 misorano postfix/smtpd[28144]: NOQUEUE: sleep: RCPT from unknown[61.77.50.2]: lost c onnection after 10 sec; from=<chang3@atlas.cz> to=<******@hakuba.ne.jp> proto=SMTP helo=<bmiktno.com>
この「lost connection after 30 sec」などの「30」が、sleep開始してから何秒後に切断などが行われたか、という秒数になります。
下記にその結果を添付します。
秒は遅延を開始してからの時間を10秒毎に四捨五入した時間帯で、LC数が途中でlost connectionとなった数、PL数がこちらの返答前にDATAコマンドを送ってきた数、です。
切断検出率は、このパッチによりクライアントからの切断が検出できた割合です。これは、closeやshutdownが行われずに接続が切れた場合は、このパッチでは切断の検出ができないためです。
【環境A】
切断検出率 80%
秒 LC数 PL数 %
0 62 82 7%
10 131 1 7%
20 310 4 16%
30 805 101 45%
40 201 10%
50 57 2 3%
60 84 98 9%
70 1 0%
80 3 2 0%
90 70 3%
総数 2014
35秒まで 1496 74%
45秒まで 1697 84%
65秒まで 1938 96%
【環境B】
切断検出率 85%
秒 LC数 PL数 %
0 234 655 4%
10 7737 369 37%
20 2185 68 10%
30 5663 392 27%
40 113 9 1%
50 708 32 3%
60 1131 1705 13%
70 46 14 0%
80 36 5 0%
90 928 102 5%
総数 22132
35秒まで 17303 78%
45秒まで 17425 79%
65秒まで 21001 95%
【環境C】
秒 LC数 PL数 %
0 75 281 7%
10 325 46 7%
20 623 13 12%
30 2594 342 56%
40 155 8 3%
50 366 7 7%
60 163 283 8%
総数 5281
35秒まで 4299 81%
45秒まで 4462 84%
65秒まで 5281 100%
【環境D】
秒 LC数 PL数 % 0 293 1% 10 5447 24% 20 712 3% 30 15607 69% 40 351 2% 50 174 1% 60 101 0% 70 0% 80 0% 90 0% 総数 22685 35秒まで 22059 97% 45秒まで 22410 99% 65秒まで 22685 100%
【環境E】(lukeさんのブログ参照)
http://blog.dyndns.tv/~luke/blog/?date=20060731
この結果から、多くのスパマーは10秒や30秒以内の短いタイムアウトを設定して送信していることがわかります。(環境A/Bの傾向の違いは、届くスパム種類以外に、sleep以外に掛けている制限の違いによるものも考えられます。)
遅延は65秒ほど掛ければ現在のところ十分で、遅延によるプロセス数の増加などがどうしても問題になる場合には、35秒ほどでも遅延による効果の7割以上が得られる、ということがわかりました。
90秒にも山がありますが、これは特定の送信元と考えられるため、このスパム業者らしい接続要求に対してのみ、特別に長めの遅延を掛けるか、確実に特定できるならそのままRejectするようにしたほうがよいと考えられます。
(追記)
和歌山大学システム情報学センターの吉田さんより、最大3分(180秒)でのログをいただきました。
モーグルとカバとパウダーの日記 - taRgreyのtarpitting時間について
この結果から、(Starpitではなく)taRgreyでは125秒程度のtarpittingがよいのではないか、と考えられます。
このパッチ作成に際して、Postfix-MLで質問させていただき、助言やアイデアをいただきました。
また、動作確認やログの収集について、長野で働く専務のblogの高村さんと、佐世保高専でスパム対策をされている中原さん、某企業でネットワーク管理者をしている友人、に協力いただきました。
この場を借りてお礼いたします。ありがとうございます。
(関連)
モーグルとカバとパウダーの日記 - Postfix 2.3 で sleep 中に相手が切ったらこっちもすぐsmtpdが切れるパッチ
(追記)
うちのサーバで何日か安定して動いていたため、パッチを接続元IP,HELO,MAIL FROM,RCPT TOもログに表示するものに修正しました。
これで例えば、誤検出があったときに追うときにも、使いやすくなったと思います。
2.3.0と2.3.1で動くことを確認しています。
新しいパッチだと、コンパイラによってはコンパイルが通らない場合があるようで、修正予定です。情報ありましたらコメントにいただけると助かります。
- 750 http://k2net.hakuba.jp/targrey/
- 267 http://www.google.com/search?hl=ja&lr=lang_ja&ie=UTF-8&oe=UTF-8&q=Trixie+Scripts&num=50
- 132 http://www.google.co.jp/search?sourceid=navclient&hl=ja&ie=UTF-8&rls=RNWE,RNWE:2005-15,RNWE:ja&q=ストレッチエレメントジャケット
- 75 http://www.google.com/search?hl=ja&lr=&ie=UTF-8&oe=UTF-8&num=50&q=Greasemonkey+sleipnir
- 62 http://www.google.co.jp/hws/search?hl=ja&q=Sleipnir+Greasemonkey&client=fenrir&adsafe=off&safe=off&lr=lang_ja
- 57 http://k2net.hakuba.jp/targrey/index.html
- 53 http://www.google.co.jp/hws/search?hl=ja&q=Greasemonkey+Sleipnir&client=fenrir&adsafe=off&safe=off&lr=lang_ja
- 44 http://www.google.co.jp/search?hl=ja&client=firefox-a&rls=org.mozilla:en-US:official&hs=ggo&q=firefox+encoding+shift-jis&btnG=Google+検索&lr=lang_ja
- 34 http://www.google.co.jp/search?hl=ja&q=デジカメファイルRENAME&lr=
- 30 http://www.google.co.jp/hws/search?hl=ja&q=greasemonkey sleipnir&client=fenrir&adsafe=off&safe=off&lr=lang_ja
昨日は帰宅が遅くてお返事かけませんでした。
今日にでも家からメールさせていただきます。
今日は職場から書かせていただいてます。
月末のサーバのアップデート作業と一緒に、
2.3.0に入れ替え作業を予定していたので、
(素でsleepが使いたいがためですね)
patch欲しいなぁと思ってたところで
公開していただけてうれしいですね。
本家に取り込まれるような予定は無いのでしょうか？
あと、65秒程度でほぼあきらめてくれるという情報も
欲しかったですし、そこから激減して90秒に山がある
というのも意外でした。送信速度を要求するspamerは
この設定をかいくぐるためだけに、待機時間を長くする
ことは無いと思いたいですが。
贅沢を言えば、1つ程度でいので、
「どれだけ遅延が掛かかったときに切断されたか」
という部分のログの記載がどうなるのか、例をちょっと
見たかったですね。
こんな感じでmaillogに記録されます。
Jul 20 09:22:05 hostname postfix/smtpd[17349]: warning: lost connection during sleep 29
自分もパッチ当てて使いたくないため、本家に取り込んで欲しいのですが、そのためにはいろいろとやらないといけないことが多いので、一歩一歩進めようとしています。
まずは本家のPostfix-users-MLに登録するところから始めました :)
90秒の山は、どんなところからなのかを詳しく調べる予定です。
まずはそのために、ログから抽出するためのスクリプトを書くところです。
もし、この手法が非常に一般的になれば、タイムアウト時間を長くするスパマーは出てくるでしょうね。最近はgreylistingも結構抜けてきてしまうようですし。
RgreyもStarpitも所詮は根本的解決ではないため、いたちごっこになりますね。でも、じゃあDKIMやSPFが世の中じゅうに普及するまでなにもしないでおくの？というとそういうわけにもいかないので、小手先の技術のうちなるべくマシな手法でなんとか対応していくしかない、という… まあ不毛な戦いですね〜
ログの例については、追記します。ご指摘ありがとうございます。
>>manchan
なんとそうなんだ。そうなってたほうが便利だよね。少なくとも自分はそう。
Photoshop Album はどういう感じなのです？
Picasaとか使ってる人は、勝手に時間順にソートして表示するんで、フォルダにわけること自体あまり意味無い感じになるのかな、と思ってたんですが。
その前にSPAMを投げつけられるSMTPサーバの資源枯渇に注意しなければならないかも知れませんけど。
あと下のコメントにも書きましたが、ログの件ですとか、たいへん助かりました。ありがとうございます。
確かにタイムアウト時間を大きくすることで、スパマーの単位時間に送れるメール送信数を減らすことができるので、一時的にそれなりに効果あると思うのでが、一般化してきたらスパム送信側のプログラムやパラメータの最適化もできるでしょうから(つまり今僕がやってることの逆を彼らができるということですね)、結局はまた同じ状況になるんだと思います。
そうなるとやはり、根本的解決に向けてはいろいろとプロトコルレベルとか政治レベルでコツコツと進めていきつつ、小手先でのスパム対策しては対応してきたらまた違う対策を考える、みたいに進めていくと…
お陰様で安定稼働していますので、負荷分散の為にMXを振り向けるStarpitメールHUBマシンを２台にしてネームサーバでラウンドロビン設定をしてみました。
早速patchを使わせてもらってます。さて、ログの解析を簡単にするために、
msg_warn(”lost connection during sleep %d from %s[%s]”, i, state->name, state->addr);
というようにしたら、ホスト名とIPアドレスがログに記録できるようになりました。state->senderなども追加できそうです。
そうですね。お楽しみ、は当分続きそうです。
なんかだんだん本格稼動してきていますね。
ログの結果から、うちは遅延時間設定を65秒にするように変更しました。
>>deguchiさん
おお、やっぱりその要望でますよね。
実は自分も、warnのところのコードを持ってきて、接続元IPや送信元、先などが出るようにパッチ修正してました。
まだうちのサーバでしか動かしてないのですが、もうちょっと様子見て問題でなさそうならこっちのパッチに差し替えようと思います。
これですべてのlost connectionが検出できれば問題なかったのですが、そうでないのでWARNを出す設定は残しています。
でもこうなると、lost connectionのときには、WARNのときに出してる情報と同じものを出すように修正したいなあ、と思えるわけですが、そのあたりどんなもんでしょうね。
ありがたく使わせていただきます。
早速patchを利用させていただき、現在テスト環境で運用中です。
テスト環境のため既存の環境との比較は出来ませんが、ログを眺めていると効果的面です！
ありがとうございましたm(_ _)m
これをアカウント数3000程度のサイトで運用開始し、鋭意smtpdのプロセス数を30分おきに取ってみています。同一サーバ上でウィルス対策ゲートウェイが動作していてMinimum 11 proc, Max 42 procsというのが現在までの推移です。もう少しログが取れたらお送りします。
いえ〜。お役に立ってるようでうれしいです。
>>Cookieさん
おお、信州FMでメールサーバ管理されてる方でしょうか？
地元で利用していただけてるのはとてもうれしいです。
新パッチだと、誤検出検知にも使えるのでまたお試しください。
>>Lukeさん
2.2.1用パッチありがとうございます。
エントリー本文のほうにも反映させていただきますね。
あと、自分の方でも WARN と同じログを出すためのパッチ修正版に置き換えましたので、こちらもご参照ください。
ちなみに、遅延秒数と、Starpit導入以前でどのくらいのプロセス数だったか、お分かりになれば教えてください。
Lukeさんの場合、それ以前はRgrey利用されてると思うので、通常よりもsmtpd起動数は少なくなりそうに思うので、またちょっと違う環境での移行結果になりそうですが。
修正版を2.3.1に適用するとエラーが出て、makeできませんでした。
2.3.0と2.3.1でpatch対象のソースファイルはタイムスタンプ、サイズも同じで
2.3.0と2.3.1の同名ファイルでdiffを調べても違いは無いので、
他の部分の修正が影響して改訂版が使えなくなったようです。
まぁ、patchファイルに2.3.0と書いてあるのに
2.3.1に無理矢理当てるのが間違いなのですが(笑)
http://blog.dyndns.tv/~luke/blog/?date=20060731
にまとめてみました。
大半は30秒以内にあきらめてます。100秒以上のところに
山があるのは、シツコイDM業者のドメインを明示的に
tarpittingしてイジワルしているためです。
新パッチでコンパイルエラーになる件、メール差し上げた修正版で一度おためし下さい。
たぶんこれなら、通ると思います。
>>Lukeさん
レポートありがとうございます。やはり30秒が山ですね。
プロセスを増やしたくない、というのが無ければ、スパムと思われる接続は毎回遅延かけてやったほうが、向こうの送信能力が多少なりとも削減されるので、世の中全体には貢献できますよね。