☰

Perl NET::SMTP で Exim 経由で送信され、その後 Postfix で送信されるメールは、特定のサーバーから送信されると遅くなります。

tag-icon • tag-icon email postfix exim perl debian-bullseye
Perl NET::SMTP で Exim 経由で送信され、その後 Postfix で送信されるメールは、特定のサーバーから送信されると遅くなります。

Debian 11 (Bullseye) 上に複数のサーバーをセットアップしています。日中に cron を使用してすべてのサーバーで定期的に実行するプロセスの 1 つは、MySQL データベースから読み取り、関連データを含む電子メールを送信する Perl スクリプトです。電子メールの数はさまざまですが、通常はバッチごとに 5 ～ 20 です。夜間は別のプロセスが情報をコンパイルし、数百の電子メールを準備します。通常、それらはすべて次のバッチで送信されます。ただし、当社のサーバーの 1 つでは例外です。

このサーバーをしばらく前にインストールし、最近新しいクライアントを追加しました。このクライアントは他のクライアントよりも大量の電子メールを生成します。この特定のマシンでは電子メールが他のマシンほど速く送信されないため、問題が発生することがわかりました。つまり、Perl スクリプトが保留中の電子メールを再びキューに入れ、メールが蓄積され始めます。

Perl スクリプトは、ローカルにインストールされた Exim4 と通信します。使用する設定は、すべてのサーバーで同じです。update-exim4.conf.conファイルは次のとおりです。

dc_eximconfig_configtype='smarthost'
dc_other_hostnames=''
dc_local_interfaces='127.0.0.1 ; ::1'
dc_readhost='******.com'
dc_relay_domains=''
dc_minimaldns='false'
dc_relay_nets=''
dc_smarthost='1**.***.***.**6'
CFILEMODE='644'
dc_use_split_config='true'
dc_hide_mailname='true'
dc_mailname_in_oh='true'
dc_localdelivery='mail_spool'

ご覧のとおり、Exim は別のサーバー、つまり postfix を実行しているスマートホストに接続し、すべての電子メールが最終的な宛先に送信されます。

私たちが抱えている問題は、この特定のサーバー上の電子メールの送信が非常に高速 (約 20/秒) で開始され、その後速度が低下し、停止し、フリーズし、最終的に次のエラーで停止することです。

unable to establish SMTP connection to (localhost) port 25

Trace begun at /usr/share/perl5/Email/Sender/Transport/SMTP.pm line 224
Email::Sender::Transport::SMTP::_throw('Email::Sender::Transport::SMTP=HASH(0x55d021f74620)', 'unable to establish SMTP connection to (localhost) port 25') called at /usr/share/perl5/Email/Sender/Transport/SMTP.pm line 174
Email::Sender::Transport::SMTP::_smtp_client('Email::Sender::Transport::SMTP=HASH(0x55d021f74620)') called at /usr/share/perl5/Email/Sender/Transport/SMTP.pm line 233

私の理解では、Exim はまず電子メールをディスクに保存し、次にそれらをキューに追加し、(この場合は) スマートホスト経由で送信します。これが当てはまる場合、Perl スクリプトと Exim の間に何らかの接続の問題がある可能性があります。私は多くの構成変更を試みましたが、これまでのところ効果がありません。

フラグを付けてコマンド ラインから Exim を実行すると-d+all、大量のデータが得られます。私にとって興味深いのは、ギャップの部分です。

[...]
12:33:00.959 394267 postfork: daemon-accept-delivery
12:33:00.959 394266 SMTP>>(close on process exit)
12:33:00.959 394266 >>>>>>>>>>>>>>>> Exim pid=394266 (daemon-accept) terminating with rc=0 >>>>>>>>>>>>>>>>
12:33:00.959 394267 exec /usr/sbin/exim4 -d=0xfff9ffff -MCd daemon-accept-delivery -Mc 1pY9HA-001eZ8-TG
12:33:00.960 394250 child 394266 ended: status=0x0
12:33:00.960 394250   normal exit, 0
12:33:00.960 394250 0 SMTP accept processes now running
12:33:00.960 394250 Listening...
[...]
12:33:02.998 394360 search_tidyup called
12:33:02.998 394360 search_tidyup called
12:33:02.998 394360 >>>>>>>>>>>>>>>> Exim pid=394360 (daemon-accept-delivery) terminating with rc=0 >>>>>>>>>>>
12:33:03.063 394365 read response data: size=75
12:33:03.063 394365   SMTP<< 250 2.1.0 Ok
12:33:03.063 394365 sync_responses expect rcpt
12:33:03.063 394365   SMTP<< 250 2.1.5 Ok
12:33:03.063 394365   SMTP<< 250 2.0.0 Ok: 1376 bytes queued as EDDF2F5F5E
[...]
12:33:03.087 394364 DSN: Remote SMTP server supports DSN: 1
12:33:03.087 394364 DSN: not sending DSN success message
12:33:03.087 394364 LOG: MAIN
12:33:03.087 394364   Completed QT=0.385s
12:33:03.087 394364 end delivery of 1pY9HC-001eag-Me
12:33:03.087 394364 search_tidyup called
12:33:03.087 394364 search_tidyup called
12:33:03.088 394364 >>>>>>>>>>>>>>>> Exim pid=394364 (daemon-accept-delivery) terminating with rc=0 >>>>>>>>>>>
**Why a 4 seconds gap here?**
12:33:07.772 394366 DNS lookup of localhost (AAAA) gave HOST_NOT_FOUND
12:33:07.772 394366 returning DNS_NOMATCH
12:33:07.772 394366 faking res_search(AAAA) response length as 65535
12:33:07.772 394366  writing neg-cache entry for localhost-AAAA-800043, ttl 86400
12:33:07.773 394366 DNS lookup of localhost (A) gave HOST_NOT_FOUND
[...]
12:33:08.417 394438 DSN: Remote SMTP server supports DSN: 1
12:33:08.417 394438 DSN: not sending DSN success message
12:33:08.417 394438 LOG: MAIN
12:33:08.417 394438   Completed QT=0.343s
12:33:08.417 394438 end delivery of 1pY9HI-001ebt-2N
12:33:08.417 394438 search_tidyup called
12:33:08.417 394438 search_tidyup called
12:33:08.417 394438 >>>>>>>>>>>>>>>> Exim pid=394438 (daemon-accept-delivery) terminating with rc=0 >>>>>>>>>>>
**Another 4-5 seconds gap**
12:33:13.146 394440 DNS lookup of ip6-localhost (AAAA) gave HOST_NOT_FOUND
12:33:13.146 394440 returning DNS_NOMATCH

メッセージが受信され配信されるたびにこのエラーDNS lookup of localhost gave HOST_NOT_FOUNDが返されるので、これが問題の原因ではない可能性があります。

処理されるメッセージの数が増えるにつれて、電子メール間のギャップはますます頻繁になります。各ギャップにかかる時間も長くなります。最終的にはタイムアウトが発生します。

以下は Perl コードの概要です。実際のコードはより複雑で、多くのクラスとサブクラスがありますが、要点は次のとおりです。

# Create SMTP server
$smtp_transport = Email::Sender::Transport::SMTP->new( $params );
my $unsent_messages = get_unsent_messages( $messages_args );

foreach my $message ( @$unsent_messages ) {
    # Create email and assign args
    my $email = Email::Stuffer->new();
    $email->to( $message->{to} );
    # [...] other arguments, headers, etc.
    $email->send_or_die( transport => $smtp_transport );
}

この問題の原因は何でしょうか。どうすればデバッグして問題の原因を突き止めることができるでしょうか。構成は他のサーバーとまったく同じで、1 分以内に数百の電子メールを送信できるため、構成設定の問題ではないと思います。ハードウェアの違いでしょうか。

Exim バージョン 4.94.2 #2 (2021 年 7 月 13 日 16:04:57 にビルド) と Postfix mail_version = 3.4.23 を使用しています。

アップデート

単純な for ループ (下記参照) は、メッセージを非常に高速かつ遅延なく送信します。したがって、問題は Perl に起因しているようです。

for f in {1..111}; do mail -s TestDeCourriel [email protected] <<< "Mail content"; done

2回目の更新

mail / sendmail を使用する代わりに s-nail をローカル SMTP サーバーに接続して同じループを実行すると、問題が再現される可能性があります。

for i in {1..111}; do echo "This is a test message. $(date)" | s-nail -S mta=smtp://localhost:25 -s "Some s-nail mail" [email protected]; done

関連情報