テックブログ

2022.12.19

メール

Linux MSP SPAM サーバサーバ保守サーバ管理サーバ運用メール

メールが送れない時の調査と確認方法、サンプル7例

はじめに

こんにちは、T.Uです。

メールが送れない時の「原因・対処方法」は見かけるのですが、「調査・確認方法」は、あまり記事が無い様だった為、簡単ですが記事を作ってみました。

全てのパターンを網羅している訳ではありませんが、一例の参考としていただけますと幸いです。

Windows端末からメールサーバーへの接続可否確認

早速ですが、まずは手元のWindows端末から「メールサーバー自体に繋がるかどうか」、PoweShellを利用して確認してみましょう。(Macの方は申し訳ございません)

「mail.example.com」「ポート587」がメールサーバーの設定となる際は、以下の手順で確認出来ます。

・PowerShell起動方法
スタートメニュー -> Windows PowerShell -> Windows PowerShell

・PoweShellで入力する調査用コマンド

Test-NetConnection mail.example.com -Port 587

応答サンプル (成功)

以下の様に「TcpTestSucceeded : True」が出た際は、メールサーバーにはアクセス出来ています。

ComputerName : mail.example.com
RemoteAddress : 203.0.113.111
RemotePort : 587
InterfaceAlias : イーサネット
SourceAddress : 192.168.0.106
TcpTestSucceeded : True

応答サンプル (失敗 – ドメイン名の間違い)

Name resolution ～ failedと出た際は、メールサーバーのドメイン名が間違っている可能性があります。

警告: Name resolution of mail.example.com failed
ComputerName : mail.example.com
RemoteAddress :
InterfaceAlias :
SourceAddress :
PingSucceeded : False

応答サンプル (失敗 – ポートに接続が出来ない)

TCP connect to ～ failedと出た際は、メールサーバーの指定のポートにアクセスが出来ない状態です。

警告: TCP connect to (203.0.113.111 : 587) failed
ComputerName : mail.example.com
RemoteAddress : 203.0.113.111
RemotePort : 587
InterfaceAlias : イーサネット
SourceAddress : 192.168.0.106
PingSucceeded : True
PingReplyDetails (RTT) : 117 ms
TcpTestSucceeded : False

よくあるパターンとしては、以下の様な状況が考えられます。

加入している回線でポートが閉じられている
セキュリティソフトで制限が設定されている
サーバー側でアクセスが許可されていない
指定されたポート番号が間違っている

メールサーバー上のログ確認

端末からメールサーバーにアクセスが出来ている様なら、サーバー側の問題の可能性があります。
Postfixで稼働しているメールサーバーを例として、ログ(/var/log/maillog)から調査・確認をしてみます。

調査に必要な情報

調査にあたり、状況が特定のアドレスだけなのか、特定の日時だけなのか、なども調査・確認には必要な為、以下の3点が最低限必要な情報になります。

送信元アドレス
送信先アドレス
送信エラーが発生した日時

という訳で、以下の情報を貰ったとして調査を進めます。

送信元アドレス　→　tu@example.com
送信先アドレス　→　tu@example.net
送信エラーが発生した日時　→　2022年12月5日18時38分頃

それではlessコマンドでログを読み込んで行きましょう。

・メールログ調査コマンド (rootユーザで実行してください)

less /var/log/maillog

ログサンプル (成功)

以下のログは、「送り元メールサーバーでは送信が成功した例」のサンプルになります。
最終的に「status=sent」となり、送信が成功した記録があります。

Dec 5 18:38:12 tu8 postfix/smtpd[84475]: 8B84D8D1CF: client=example.org[198.51.100.100], sasl_method=CRAM-MD5, sasl_username=tu@example.com
Dec 5 18:38:12 tu8 postfix/cleanup[84478]: 8B84D8D1CF: message-id=20221205183811.8983.30194A77@example.com
Dec 5 18:38:12 tu8 postfix/qmgr[61182]: 8B84D8D1CF: from=tu@example.com, size=1284, nrcpt=1 (queue active)
Dec 5 18:38:12 tu8 postfix/smtpd[84475]: disconnect from example.org[198.51.100.100] ehlo=1 auth=1 mail=1 rcpt=1 data=1 rset=1 quit=1 commands=7
Dec 5 18:38:12 tu8 postfix/smtp[84479]: Anonymous TLS connection established to mail.example.net[203.0.113.112]:25: TLSv1.2 with cipher ADH-AES256-GCM-
SHA384 (256/256 bits)
Dec 5 18:38:12 tu8 postfix/smtp[84479]: 8B84D8D1CF: to=tu@example.net, relay=mail.example.net[203.0.113.112]:25, delay=0.47, delays=0.16/0.05
/0.09/0.17, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as EEC702AAC0E)
Dec 5 18:38:12 tu8 postfix/qmgr[61182]: 8B84D8D1CF: removed

もしこの状況でメールが届いていない際は、以下の様な理由で、送り先のメールサーバー側や、送り先のメールソフト側で、配送を止められている可能性があります。

配送されたが、迷惑メールに振り分けられている
セキュリティソフトで、何らかの判定を行い削除された

ログサンプル (失敗 – タイムアウト)

以下のログは、「送り先メールサーバーへの接続に時間がかかりすぎた」際のサンプルになります。
最終的に「status=deferred」となり、送信が失敗した記録があります。

この場合、以下の様な要因が考えられます。

送り先メールサーバーがダウンしている
送信元のメールサーバーからの接続を拒否している
送信元のメールサーバーで外向きのアクセス(アウトバウンド通信)に制限がある

特定ベンダーのサーバーでは、申請をしない限り25番ポートからの送信が出来ない時や、一定期間は25番ポートが利用出来ない場合があるので、注意が必要となります。

ログサンプル (失敗 – SPAMデータベースに登録された)

以下のログは、「送り元サーバーがSPAMデータベースに登録された」際のサンプルになります。
最終的に「status=deferred」となり、送信が失敗した記録があります。
またログの末尾に、SPAMデータベースの確認用URLが出力されています。

Dec 5 18:38:12 tu8 postfix/smtpd[84475]: 8B84D8D1CF: client=example.org[198.51.100.100], sasl_method=CRAM-MD5, sasl_username=tu@example.com
Dec 5 18:38:12 tu8 postfix/cleanup[84478]: 8B84D8D1CF: message-id=20221205183811.8983.30194A77@example.com
Dec 5 18:38:12 tu8 postfix/qmgr[61182]: 8B84D8D1CF: from=tu@example.com, size=1284, nrcpt=1 (queue active)
～略
Dec 5 18:38:12 tu8 postfix/smtp[84479]: 8B84D8D1CF: to=tu@example.net, relay=mail.example.net[203.0.113.112]:25, delay=248122, delays=248120/0.02/2.2/0, dsn=4.7.0, status=deferred (host mail.example.net[203.0.113.112] refused to talk to me: 554 5.7.0 Blocked – see https://dnsbl.example.net/dnsbl-lookup.cgi?ip=203.0.113.111)

この場合、以下の様な要因が考えられます。

以前メールサーバーでSPAMを配送していた
過去に同一のIPアドレスのサーバーから、SPAMが配送されていた

解消には、メールサーバーからSPAMが配送されていない事を確認した上、SPAMデータベースのサイトから、SPAMデータベースからの登録解除を行う必要があります。

ログサンプル (失敗 – WEBサーバーから送信した際にエンベロープFrom指定が無い)

特殊な例としては、「WEBサーバーからエンベロープFrom(Return-Path:)のアドレスを空白にした際」に、FromのアドレスとエンベロープFromのアドレスが別のアドレスとなり、配送が拒否される事があります。

ログ上では、送り元が「tu@example.com」のはずが「apache@example.com」と記録されており、送信が失敗しています。

Dec 5 18:38:12 tu8 postfix/pickup[22765]: 8B84D8D1CF: uid=48 from=<apache>
Dec 5 18:38:12 tu8 postfix/cleanup[21711]: 8B84D8D1CF: message-id=20221205183811.8983.30194A77@example.com
Dec 5 18:38:12 tu8 postfix/qmgr[1208]: 8B84D8D1CF: from=apache@example.com, size=1597, nrcpt=1 (queue active)
Dec 5 18:38:12 tu8 postfix/smtp[22294]: 8B84D8D1CF: host mail.example.net[203.0.113.112] refused to talk to me: 554 Local Policy Violation – see https://ipcheck.example.net/dnsbl-lookup.cgi?ip=203.0.113.111
Dec 5 18:38:12 tu8 postfix/smtp[22294]: 8B84D8D1CF: to=tu@example.net, relay=mail.example.net[203.0.113.112]:25, delay=1.6, delays=0/0/1.6/0, dsn=4.0.0, status=deferred (host mail.example.net[203.0.113.112]: refused to talk to me: 554 Local Policy Violation – see https://ipcheck.example.net/dnsbl-lookup.cgi?ip=203.0.113.111)

Return-Path:を指定せずにWEBサーバー(Apache)からメールを送ると、「Apacheの実行ユーザ@ドメイン名」としてメールが送られる為、一部のメールサーバーでは配送が拒否されます。

この場合、プログラム側で「Return-Path:」「From:」のアドレスを同一に指定する必要があります。