メールサーバ Postfix トラブル

isao,

FreeBSD のパッケージを pkg と portupgrade でメンテナンスしていると，たまに，エラーが起きてパッケージをうまくアップグレードできない場合があり，いつのまにか必要なライブラリが消去されて，動かなくなるソフトウェアが出ることがある。portupgrade -rf で依存関係にあるソフトウェアを一括してアップグレードするとき，出力されるメッセージを注意深くチェックすべきである。

先日，あるパッケージを portupgrade -rf でアップグレードしたら，依存関係にあるパッケージでエラーが出た。なのに私は，これを放置してしまっていた。すると，妻が「ここのところメールが来ないんだけど」と言う。私は泡食ってメールの試験を行ったら，果たして自分に送信したメールが届かない。メールサーバ Postfix 関係の設定変更などここのところまったく行っていないので，何が起きているのかさっぱりわからなかった。

まず，メールログ /var/log/maillog をチェックすると，たしかにエラーとなっていた。ポート番号 10024 で “Connection refused” となっているのが問題のようである。

Jun 15 00:11:21 beatrice postfix/smtp[82275]: DFB02484112: to=,
relay=none, delay=1.2, delays=1.2/0.01/0/0, dsn=4.4.1, status=deferred (connect to 127.
0.0.1[127.0.0.1]:10024: Connection refused)

Postfix を再起動してみる。

# service postfix restart
...
/usr/local/sbin/postconf: warning: /usr/local/etc/postfix/master.cf: undefined parameter:
mua_helo_restrictions
/usr/local/sbin/postconf: warning: /usr/local/etc/postfix/master.cf: undefined parameter:
mua_sender_restrictions
/usr/local/sbin/postconf: warning: /usr/local/etc/postfix/master.cf: undefined parameter:
mua_client_restrictions
...
postfix/postfix-script: starting the Postfix mail system

あれ，こんなワーニングが出ていたっけかな？ /usr/local/etc/postfix/master.cf の記述のうち，ここで undefined と出たパラメータの行をコメントアウトすれば，ワーニングは消えた。

submission inet n       -       n       -       -       smtpd
...
#  -o smtpd_client_restrictions=$mua_client_restrictions
#  -o smtpd_helo_restrictions=$mua_helo_restrictions
#  -o smtpd_sender_restrictions=$mua_sender_restrictions
 
smtps     inet  n       -       n       -       -       smtpd
...
#  -o smtpd_client_restrictions=$mua_client_restrictions
#  -o smtpd_helo_restrictions=$mua_helo_restrictions
#  -o smtpd_sender_restrictions=$mua_sender_restrictions

でも，これはメール受信不可とは無関係である。saslauthd（SASL 認証），imapd（IMAP），amavisd（ウイルスチェック，スパムチェックと Postfix との間の仲介），clamav-clamd（AntiVirus），clamav-freshclam（AntiVirus データベース更新），sa-spamd（SpamAssassin AntiSpam）といったメール関係のプログラムをひとつひとつ再起動してみたら原因が判明した。amavisd の起動が失敗し，これが問題の出所であった。

Jun 16 23:14:23 beatrice amavis[23212]: (!)Net::Server: 2015/06/16-23:14:23 Unresolveable
host [::1]:10024 - could not load IO::Socket::INET6: Can't locate Socket6.pm in @INC (you
may need to install the Socket6 module) (@INC contains: /usr/local/lib/perl5/site_perl/
mach/5.18 /usr/local/lib/perl5/site_perl /usr/local/lib/perl5/5.18/mach /usr/local/lib/
perl5/5.18 /usr/local/lib/perl5/site_perl/5.18 /usr/local/lib/perl5/site_perl/5.18/mach)
at /usr/local/lib/perl5/site_perl/Net/Server/Proto.pm line 122.\n\n  at line 82 in file
/usr/local/lib/perl5/site_perl/Net/Server/Proto.pm

たしかに，ポート番号 10024 で通信している amavisd が Perl モジュールのロードでエラーになり起動に失敗していた。その結果，Postfix が 10024 ポート通信で弾かれ，“Connection refused” のエラーを出力したわけである。

どうも，portupgrade -rf の失敗で amavisd の前提 Perl モジュールが消えてしまっていたようで，必要なモジュールを再度インストールしたら，きちんと試験メールが受信できるようになった。

Jun 17 00:03:44 beatrice amavis[27051]: (27051-07) Passed CLEAN {RelayedInbound}, [127.0.
0.1] <root@yasuda.homeip.net> -> <isao@yasuda.homeip.net>, Message-ID: <20150616090546.95
93D4842D2@yasuda.homeip.net>, mail_id: ifPm2qEAEiA4, Hits: -, size: 473, queued_as: C4BD9
4840E8, 158 ms
Jun 17 00:03:44 beatrice postfix/smtp[33856]: 9593D4842D2: to=<isao@yasuda.homeip.net>, r
elay=127.0.0.1[127.0.0.1]:10024, delay=21478, delays=21478/0.01/0/0.16, dsn=2.0.0, status
=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as C4BD94840E8)
Jun 17 00:03:44 beatrice postfix/qmgr[25350]: 9593D4842D2: removed
Jun 17 00:03:45 beatrice postfix/local[33880]: C4BD94840E8: to=<isao@yasuda.homeip.net>,
relay=local, delay=0.91, delays=0.01/0.01/0/0.89, dsn=2.0.0, status=sent (delivered to c
ommand: IFS=' ' && p=/usr/local/bin/procmail && test -f $p && exec $p -Yf- || exit 75 #is
ao)
Jun 17 00:03:45 beatrice postfix/qmgr[25350]: C4BD94840E8: removed

Category: