Project

General

Profile

Actions

Defect #41515

closed

Connection to mailserver is not properly terminated

Added by Hendrik Jaeger about 1 month ago. Updated about 1 month ago.

Status:
Closed
Priority:
Normal
Assignee:
-
Category:
Email notifications
Target version:
-
Start date:
Due date:
% Done:

0%

Estimated time:
Resolution:
Fixed
Affected version:

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 …

Actions

Also available in: Atom PDF