Disponemos de varios servidores configurados en Debian 11 (Bullseye). Uno de los procesos que ejecutamos en todos los servidores a intervalos regulares durante el día, con cron, es un script perl que lee desde una base de datos MySQL y envía correos electrónicos con datos relevantes. La cantidad de correos electrónicos varía, pero suele estar entre 5 y 20 por lote. Excepto durante la noche, donde otro proceso recopilará información y preparará cientos de correos electrónicos. Por lo general, todos se envían con el siguiente lote. Excepto en uno de nuestros servidores.
Instalamos este servidor hace un tiempo y recientemente le agregamos un nuevo cliente. Este cliente genera un mayor volumen de correos electrónicos que otros. Notamos que esto causa problemas porque en esta máquina en particular los correos electrónicos no se envían tan rápido como en otras. Esto significa que el script Perl pondrá en cola los correos electrónicos pendientes nuevamente y comenzarán a acumularse.
El script Perl se comunica con Exim4 instalado localmente. La configuración que utilizamos es la misma en todos nuestros servidores. Aquí está el update-exim4.conf.conarchivo:
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'
Como puede ver, Exim se conectará a otro de nuestros servidores, el smarthost que ejecuta postfix, desde donde se envía cada correo electrónico a su destino final.
El problema que tenemos es que los correos electrónicos en este servidor en particular comenzarán a enviarse muy rápido (~20/s) y luego se ralentizarán, se detendrán, se congelarán y finalmente se detendrán con el siguiente error:
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
Tengo entendido que Exim primero guardará los correos electrónicos en el disco, luego los agregará a la cola y luego los enviará (en nuestro caso) a través del host inteligente. Si este es el caso, significa que puede haber algún problema de conexión entre el script Perl y Exim. He intentado muchos cambios de configuración, sin éxito hasta el momento.
Cuando ejecuto Exim desde la línea de comando con la -d+allbandera, obtengo una gran cantidad de datos. Lo interesante, para mí, está en los huecos:
[...]
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
El mensaje DNS lookup of localhost gave HOST_NOT_FOUNDregresa por cada mensaje aceptado y entregado, por lo que probablemente no sea eso lo que está causando el problema.
Los intervalos entre correos electrónicos se vuelven cada vez más frecuentes a medida que crece el número de mensajes procesados. El tiempo que dura cada intervalo también se alarga. Finalmente hay un tiempo de espera.
Aquí hay un resumen del código Perl. Tenga en cuenta que el código real es más complejo, con muchas clases y subclases, pero la esencia es la siguiente:
# 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 );
}
Qué podría estar causando este problema. ¿Cómo puedo depurar esto y descubrir de dónde viene el problema? La configuración es exactamente la misma que tenemos en nuestros otros servidores, que pueden enviar cientos de correos electrónicos en menos de un minuto, así que dudo que sea una configuración. ¿Podría ser de alguna manera una diferencia de hardware?
Usando Exim versión 4.94.2 #2 compilada el 13 de julio de 2021 16:04:57 y Postfix mail_version = 3.4.23.
Actualizar
Un bucle for simple (ver más abajo) envía mensajes a la velocidad del rayo y sin demora. Entonces el problema parece provenir de Perl.
for f in {1..111}; do mail -s TestDeCourriel [email protected] <<< "Mail content"; done
Segunda actualización
El mismo bucle con s-nail conectándose al servidor SMTP local en lugar de usar mail/sendmail puede reproducir el problema.
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