Defect #41515
closedConnection to mailserver is not properly terminated
0%
Description
Hi
Basic info first:
Environment: Redmine version 5.1.2.stable Ruby version 3.1.2-p20 (2022-04-12) [x86_64-linux-gnu] Rails version 6.1.7.7 Environment production Database adapter PostgreSQL Mailer queue ActiveJob::QueueAdapters::AsyncAdapter Mailer delivery smtp Redmine settings: Redmine theme Alternate SCM: Git 2.39.5 Filesystem Redmine plugins: no plugin installed Postgres: 15.8-0+deb12u1
The problem I’m actually seeing is that sometimes some mails don’t arrive.
I also noticed errors from my mailserver saying the following:
2024-10-21 10:01:51 [16088] 1t2pEO-0004BU-1Z SMTP connection lost after final dot H=wilhelm.netwichtig.de (localhost.localdomain) [95.216.1.126]:37214 I=[213.133.111.59]:587 P=esmtpsa
For reference:
- 95.216.1.126 is wilhelm.netwichtig.de is the server where a VM runs in which redmine runs.
- 213.133.111.59 is leonardo.netwichtig.de where the mailserver runs that redmine is configured to use with AUTH to send emails.
Exim says that the client did not properly close the SMTP connection but just abandoned it after the final dot, i.e. before exim could acknowledge that it received the message completely, and therefore exim does not accept the message and the message is lost.
At the same time I see in redmine logs:
I, [2024-10-21T10:01:48.228979 #585774] INFO -- : [ActiveJob] [ActionMailer::MailDeliveryJob] [cf534f2e-1f4a-48d5-a3d9-a60af7ed0052] Performed ActionMailer::MailDeliveryJob (Job ID: cf534f2e-1f4a-48d5-a3d9-a60af7ed0052) from Async(mailers) in 8286.05ms I, [2024-10-21T10:01:48.761573 #585774] INFO -- : [ActiveJob] [ActionMailer::MailDeliveryJob] [9eed43b3-8e56-4370-9372-468d0292c96f] Performed ActionMailer::MailDeliveryJob (Job ID: 9eed43b3-8e56-4370-9372-468d0292c96f) from Async(mailers) in 8824.51ms E, [2024-10-21T10:01:49.506526 #585774] ERROR -- : [ActiveJob] [ActionMailer::MailDeliveryJob] [4c1324f7-b5a4-4fd6-9a48-e232501b1631] Email delivery error: Net::ReadTimeout with #<Socket:(closed)> I, [2024-10-21T10:01:49.506718 #585774] INFO -- : [ActiveJob] [ActionMailer::MailDeliveryJob] [4c1324f7-b5a4-4fd6-9a48-e232501b1631] Performed ActionMailer::MailDeliveryJob (Job ID: 4c1324f7-b5a4-4fd6-9a48-e232501b1631) from Async(mailers) in 9567.16ms
In this case it tried to notify 3 recipients who are involved with the ticket that was updated, hence three MailDeliveryJobs.
The relevant part is that it seems to timeout and just close the connection.
According to my research the default `read_timeout` for the `Net` module might be 5 seconds, which is way too low for SMTP! The RFC goes up to 5 minutes AFAIR and having delays of several seconds is not uncommon, e.g. for the reason that "at-SMTP-time" spamscanning of emails can take a few seconds.
So my suggestion is to increase that timeout to at least 30s, or to be fully RFC-compliant, 5 minutes.
I am not 100% sure that I am interpreting the situation correctly, though, so feel free to correct me, request more information, etc.
My only goal here is to get the problem fixed …