☰

Exim을 통해 Perl NET::SMTP로 보낸 이메일과 Postfix가 특정 서버에서 오는 경우 속도가 느려집니다.

tag-icon • tag-icon email postfix exim perl debian-bullseye
Exim을 통해 Perl NET::SMTP로 보낸 이메일과 Postfix가 특정 서버에서 오는 경우 속도가 느려집니다.

Debian 11(Bullseye)에는 여러 서버가 설정되어 있습니다. 우리가 cron을 사용하여 하루 동안 일정한 간격으로 모든 서버에서 실행하는 프로세스 중 하나는 MySQL 데이터베이스에서 읽고 관련 데이터가 포함된 이메일을 보내는 Perl 스크립트입니다. 이메일 수는 다양하지만 일반적으로 배치당 5~20개입니다. 또 다른 프로세스가 정보를 수집하고 수백 개의 이메일을 준비하는 밤 시간을 제외하고. 일반적으로 모두 다음 배치와 함께 전송됩니다. 우리 서버 중 하나를 제외하고.

우리는 이 서버를 얼마 전에 설치했고 최근에 새 클라이언트를 추가했습니다. 이 클라이언트는 다른 클라이언트보다 더 많은 양의 이메일을 생성합니다. 이 특정 컴퓨터에서는 이메일이 다른 컴퓨터만큼 빨리 전송되지 않기 때문에 이로 인해 문제가 발생한다는 것을 알았습니다. 이는 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분 이내에 수백 통의 이메일을 보낼 수 있으므로 구성 설정인지 의심스럽습니다. 하드웨어 차이일 수도 있나요?

2021년 7월 13일 16:04:57에 빌드된 Exim 버전 4.94.2 #2 및 Postfix mail_version = 3.4.23을 사용합니다.

업데이트

간단한 for 루프(아래 참조)는 지연 없이 매우 빠른 속도로 메시지를 보냅니다. 따라서 문제는 Perl에서 발생하는 것 같습니다.

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

두 번째 업데이트

메일/sendmail을 사용하는 대신 로컬 SMTP 서버에 연결하는 s-nail과 동일한 루프를 사용하면 문제를 재현할 수 있습니다.

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

관련 정보