Defect #41515
Updated by Holger Just about 1 month ago
Hi Basic info first: <pre> 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 </pre> The problem I’m actually seeing is that sometimes some mails don’t arrive. I also noticed errors from my mailserver saying the following: <pre> ``` 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 </pre> ``` 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: <pre> ``` 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 </pre> ``` 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 …