ソースコード・リテラシーのススメ

第10回 続・ログファイル・リテラシー

この記事を読むのに必要な時間:およそ 3 分

次に送信側の状況を調べるためにsmtpのログを調べてみました。postfixで送信側の機能を果たすsmtpでは,正しく接続先に送れたメールは'status=sent'(送信済み)と記録され,何らかの理由で送信できなかったメールは'status=deferred'(送信延期)と記録されます。そこで,smtpdのログ同様,1日ごとにそれぞれのキーワードの出現回数をカウントしました。

図3 smtpが送信できたメール(sent)と送信できなかったメール(deferred)のカウント数変化

図3 smtpが送信できたメール(sent)と送信できなかったメール(deferred)のカウント数変化

この結果を見ると,12月の中旬くらいまでは多少の変動はあるものの,送信済みメールも送信延期されたメールも2,000件から5,000件前後で推移しているのに対し,12/26から送信延期(deferred)されたメールが急激に増加していることが見てとれます。

前回述べたように,当初,この送信延期の原因は,Plamo LinuxのメンテナMLがrejectポリシーになっていたために,SPAMの送り主に「メンバー外メール」の通知を返そうとしたことによるものと考えていましたが,smtpdのログを元に,メンテナML宛に届いたメールの数を調べると,かなりバラツキはあるものの,この2ヵ月間はおよそ1日あたり200から500通で推移していて,特に12/26以降に急増した気配はありません。前回見たようにrejectポリシーによる詐称アドレスへのリプライメールは確かに発生しているものの,それだけで送信延期がこのように大量発生することは考えにくいところです。

頻出キーワードを絞り込む

そこで改めて送信延期が大量発生している時期のsmtpのログを眺めていると,いくつか特定のドメインが繰り返し現われていることに気がつきました。そこで,頻出しているac.jpドメイン2つ(A大学とB大学)と某大手プロバイダ(Cプロバイダ)の出現頻度をカウントしてみたところ,図4のような結果となりました。

図4 特定ドメインがログに出現した頻度の変化

図4 特定ドメインがログに出現した頻度の変化

このうちB大学の例は,12/27から送信延期が発生し始めたものの1/4には収束しています。この例はおそらく「年末年始の休暇でマシンが止まってしまった」といった類のトラブルでしょう。一方,A大学の場合はもう少し収束に時間がかかり,1/10くらいまで送信延期が発生していたようです。こちらも引き金は年末の休暇のようですが,休暇が終わってマシンが復旧して解消したのか,1/6の深夜にメールキューの保持期間を短かくしたため,送信されないままキューにたまったメールが削除されたのかはよくわかりません。

一方,Cプロバイダの例は多少傾向が異なっていて,A,B大学のように"Connection timed out"による送信延期ではなく,相手のメールサーバから451というエラーコードが返ったことによる送信延期のようです。

 Dec 31 00:06:49 sv postfix/smtp[23229]: 66B72C9D18A: host XXXX said: 451 4.3.2 Please try again later (in reply to RCPT TO command)

SMTPの応答コード451はローカルエラーの発生(local error in progress)」によると定義されており,具体的にどういうエラーが発生したかは不明ですが,おそらく「ユーザのメール使用量が制限値を越えた」といったエラーのように思われます。Cプロバイダの場合は,年末年始もサーバは問題なく動いていたものの,ユーザが休暇でメールのチェックを怠り,その結果メールの使用量が制限値を越えてしまったため送信延期が発生した,と考えるのがよさそうです。ただし,12月の中旬から延期が発生し始め,年末年始を越えた1月の中旬以降も同程度の送信延期が残っているところを見ると,ユーザの休暇以外の要因も疑われるところです。

以上のようにメールサーバのログを詳しく分析してみると,今回のトラブルにはメーリングリストの運用ポリシーだけではなく,年末年始休暇の影響もかなり大きいことが見えてきました。その意味では,今回の問題は特に対策を講じなくても,休暇が終われば解決した問題かも知れません。しかしながら,年末年始の時期に再度同じような問題が発生する可能性を未然に防ぐ意味でも,今回の対策は価値があったように思います。

従来,メールサーバでは「メールは可能な限り届ける」ために,キューの保持期間などは安全側に振るように設定されてきました。しかし,最近のようにSPAMが猖獗を極めている状態では正しくないメールは積極的に除去するようなルールも必要になることが,今回の調査からも見えてきました。この経験を踏まえて,より適切なメールサーバの設定を詰めていきたいと考えています。

著者プロフィール

こじまみつひろ

Plamo Linuxとりまとめ役。もともとは人類学的にハッカー文化を研究しようとしていたのが,いつの間にかミイラ取りがミイラになってOSSを仕事にするようになってしまいました。最近はスペシャリスト養成を目的とした専門職大学院で教壇に立ったりもしています。

URLhttp://www.linet.gr.jp/~kojima/Plamo/index.html