Random lmtp Timeout and Long Message Processing times

2 Jan 2025


      Hello-
We’re seeing a seemingly random issue with message acceptance on our mailman instance where some messages sent from postfix to the lmtp listener timeout. It’s not consistent to any specific list or time of day, and messages are accepted on the next attempt by postfix to deliver the message to the lmtp.
Additionally, there seems to be a similarly random delay in accepting and processing messages before they are sent to the list moderators or list members.
The mailman smtp log snippet shows it stop receiving data prior to the DATA portion of the message after a 15min timeout:
Jan 02 07:56:36 2025 (3601529) Available AUTH mechanisms: LOGIN(builtin) PLAIN(builtin)
Jan 02 07:56:36 2025 (3601529) Peer: ('127.0.0.1', 45574)
Jan 02 07:56:36 2025 (3601529) ('127.0.0.1', 45574) handling connection
Jan 02 07:56:36 2025 (3601529) ('127.0.0.1', 45574) << b'220 lists.renci.org GNU Mailman LMTP runner 2.0'
Jan 02 07:56:36 2025 (3601529) _handle_client readline: b'LHLO lists.renci.org\r\n'
Jan 02 07:56:36 2025 (3601529) ('127.0.0.1', 45574) >> b'LHLO lists.renci.org'
Jan 02 07:56:36 2025 (3601529) ('127.0.0.1', 45574) << b'250-lists.renci.org'
Jan 02 07:56:36 2025 (3601529) ('127.0.0.1', 45574) << b'250-SIZE 33554432'
Jan 02 07:56:36 2025 (3601529) ('127.0.0.1', 45574) << b'250-8BITMIME'
Jan 02 07:56:36 2025 (3601529) ('127.0.0.1', 45574) << b'250 HELP'
Jan 02 07:56:36 2025 (3601529) _handle_client readline: b'MAIL FROM:010001942716aa05-637d21f8-9794-473f-9e8b-06ca08025ef1-000000@mail.verify.signin.aws<mailto:010001942716aa05-637d21f8-9794-473f-9e8b-06ca08025ef1-000000@mail.verify.signin.aws> SIZE=20254\r\n'
Jan 02 07:56:36 2025 (3601529) ('127.0.0.1', 45574) >> b'MAIL FROM:010001942716aa05-637d21f8-9794-473f-9e8b-06ca08025ef1-000000@mail.verify.signin.aws<mailto:010001942716aa05-637d21f8-9794-473f-9e8b-06ca08025ef1-000000@mail.verify.signin.aws> SIZE=20254'
Jan 02 07:56:36 2025 (3601529) ('127.0.0.1', 45574) sender: 010001942716aa05-637d21f8-9794-473f-9e8b-06ca08025ef1-000000@mail.verify.signin.aws<mailto:010001942716aa05-637d21f8-9794-473f-9e8b-06ca08025ef1-000000@mail.verify.signin.aws>
Jan 02 07:56:36 2025 (3601529) ('127.0.0.1', 45574) << b'250 OK'
Jan 02 07:56:36 2025 (3601529) _handle_client readline: b'RCPT TO:adcircaws@lists.RENCI.org<mailto:adcircaws@lists.RENCI.org>\r\n'
Jan 02 07:56:36 2025 (3601529) ('127.0.0.1', 45574) >> b'RCPT TO:adcircaws@lists.RENCI.org<mailto:adcircaws@lists.RENCI.org>'
Jan 02 08:12:26 2025 (3601529) ('127.0.0.1', 45574) recip: adcircaws@lists.RENCI.org<mailto:adcircaws@lists.RENCI.org>
Jan 02 08:12:26 2025 (3601529) ('127.0.0.1', 45574) << b'250 Ok'
Jan 02 08:12:26 2025 (3601529) ('127.0.0.1', 45574) EOF received
Jan 02 08:12:26 2025 (3601529) ('127.0.0.1', 45574) connection timeout
Jan 02 08:12:26 2025 (3601529) ('127.0.0.1', 45574) Connection lost during _handle_client()
Jan 02 08:12:26 2025 (3601529) Available AUTH mechanisms: LOGIN(builtin) PLAIN(builtin)
Jan 02 08:12:26 2025 (3601529) ('127.0.0.1', 45574) connection lost
Jan 02 08:12:26 2025 (3601529) Peer: ('127.0.0.1', 33138)
Jan 02 08:12:26 2025 (3601529) ('127.0.0.1', 33138) handling connection
Jan 02 08:12:26 2025 (3601529) ('127.0.0.1', 33138) << b'220 lists.renci.org GNU Mailman LMTP runner 2.0'
Jan 02 08:12:26 2025 (3601529) _handle_client readline: b'LHLO lists.renci.org\r\n'
Jan 02 08:12:26 2025 (3601529) ('127.0.0.1', 33138) >> b'LHLO lists.renci.org'
Jan 02 08:12:26 2025 (3601529) ('127.0.0.1', 33138) << b'250-lists.renci.org'
Jan 02 08:12:26 2025 (3601529) ('127.0.0.1', 33138) << b'250-SIZE 33554432'
Jan 02 08:12:26 2025 (3601529) ('127.0.0.1', 33138) << b'250-8BITMIME'
Jan 02 08:12:26 2025 (3601529) ('127.0.0.1', 33138) << b'250 HELP'
Jan 02 08:12:26 2025 (3601529) _handle_client readline: b'MAIL FROM:010001942716aa05-637d21f8-9794-473f-9e8b-06ca08025ef1-000000@mail.verify.signin.aws<mailto:010001942716aa05-637d21f8-9794-473f-9e8b-06ca08025ef1-000000@mail.verify.signin.aws> SIZE=20254\r\n'
Jan 02 08:12:26 2025 (3601529) ('127.0.0.1', 33138) >> b'MAIL FROM:010001942716aa05-637d21f8-9794-473f-9e8b-06ca08025ef1-000000@mail.verify.signin.aws<mailto:010001942716aa05-637d21f8-9794-473f-9e8b-06ca08025ef1-000000@mail.verify.signin.aws> SIZE=20254'
Jan 02 08:12:26 2025 (3601529) ('127.0.0.1', 33138) sender: 010001942716aa05-637d21f8-9794-473f-9e8b-06ca08025ef1-000000@mail.verify.signin.aws<mailto:010001942716aa05-637d21f8-9794-473f-9e8b-06ca08025ef1-000000@mail.verify.signin.aws>
Jan 02 08:12:26 2025 (3601529) ('127.0.0.1', 33138) << b'250 OK'
Jan 02 08:12:26 2025 (3601529) _handle_client readline: b'RCPT TO:adcircaws@lists.RENCI.org<mailto:adcircaws@lists.RENCI.org>\r\n'
Jan 02 08:12:26 2025 (3601529) ('127.0.0.1', 33138) >> b'RCPT TO:adcircaws@lists.RENCI.org<mailto:adcircaws@lists.RENCI.org>'
Jan 02 08:12:26 2025 (3601529) ('127.0.0.1', 33138) recip: adcircaws@lists.RENCI.org<mailto:adcircaws@lists.RENCI.org>
Jan 02 08:12:26 2025 (3601529) ('127.0.0.1', 33138) << b'250 Ok'
Jan 02 08:12:26 2025 (3601529) _handle_client readline: b'DATA\r\n'
Jan 02 08:12:26 2025 (3601529) ('127.0.0.1', 33138) >> b'DATA'
Jan 02 08:12:26 2025 (3601529) ('127.0.0.1', 33138) << b'354 End data with <CR><LF>.<CR><LF>'
Anyone have any thoughts on next troubleshooting steps on this one?
Thanks

Taber, Douglas R

tags

participants (1)