4
In outgoing SMTP there's too much "The smtp session has timed out." errors that lead to duplicated mail to the destinations
Problem reported by Gabriele Maoret - 10/5/2017 at 12:11 AM
Submitted
Fro time to time we are experiencing many "The smtp session has timed out." errors that lead to duplicated mail to the destinations.
 
It seems that at some point during the comunication with destination SMTP servers the delivery process freezes just after the message is delivered but before there's an "OK" from the destination.
This results in this issue: SM think that the comunication is broken and after 60s it will close the cominication with TimeOut adn retry again later, but the destinations has received the massage. So the message will be resente many times and there's diplicates in the destination mail directory.
 
Changing the timeout to 180s does not solve teh issue.
 
SmarterMail is the latest 15. version in a dedicated Windows 2012 R2 STD Server.

3 Replies

Reply to Thread
0
Gabriele Maoret Replied
No one with this issue?
0
Gabriele Maoret Replied
This is a sample LOG of an email with the described issue:

[2017.10.06] 11:25:36 [06914] Delivery started for angela@umfsrl.it at 11:25:36
[2017.10.06] 11:25:45 [06914] Skipping spam checks: No local recipients
[2017.10.06] 11:25:48 [06914] Sending remote mail for angela@umfsrl.it
[2017.10.06] 11:25:48 [06914] Spam check results: [_CUSTOMRULES: ], [_BAYESIANFILTERING: passed], [SURBL: passed], [URIBL: passed]
[2017.10.06] 11:25:48 [06914] Initiating connection to 213.205.33.63
[2017.10.06] 11:25:48 [06914] Connecting to 213.205.33.63:25 (Id: 1)
[2017.10.06] 11:25:48 [06914] Binding to local IP 192.168.1.161:0 (Id: 1)
[2017.10.06] 11:25:48 [06914] Connection to 213.205.33.63:25 from 192.168.1.161:64270 succeeded (Id: 1)
[2017.10.06] 11:26:02 [06914] RSP: 220 cmgw-3.mail.tiscali.it ESMTP service ready
[2017.10.06] 11:26:02 [06914] CMD: EHLO mail3.sersis.com
[2017.10.06] 11:26:02 [06914] RSP: 250-cmgw-3.mail.tiscali.it hello [151.80.62.161], pleased to meet you
[2017.10.06] 11:26:02 [06914] RSP: 250-SIZE 104857600
[2017.10.06] 11:26:02 [06914] RSP: 250-ENHANCEDSTATUSCODES
[2017.10.06] 11:26:02 [06914] RSP: 250-8BITMIME
[2017.10.06] 11:26:02 [06914] RSP: 250 OK
[2017.10.06] 11:26:02 [06914] CMD: MAIL FROM:<angela@umfsrl.it> SIZE=26037
[2017.10.06] 11:26:03 [06914] RSP: 250 2.1.0 <angela@umfsrl.it> sender ok
[2017.10.06] 11:26:03 [06914] CMD: RCPT TO:<mecsav@tiscali.it>
[2017.10.06] 11:26:03 [06914] RSP: 250 2.1.5 <mecsav@tiscali.it> recipient ok
[2017.10.06] 11:26:03 [06914] CMD: DATA
[2017.10.06] 11:26:03 [06914] RSP: 354 enter mail, end with "." on a line by itself
[2017.10.06] 11:29:03 [06914] The smtp session has timed out.
[2017.10.06] 11:29:03 [06914] Initiating connection to 213.205.33.64
[2017.10.06] 11:29:03 [06914] Connecting to 213.205.33.64:25 (Id: 2)
[2017.10.06] 11:29:03 [06914] Binding to local IP 192.168.1.161:0 (Id: 2)
[2017.10.06] 11:29:03 [06914] Connection to 213.205.33.64:25 from 192.168.1.161:64310 succeeded (Id: 2)
[2017.10.06] 11:29:17 [06914] RSP: 220 cmgw-2.mail.tiscali.it ESMTP service ready
[2017.10.06] 11:29:17 [06914] CMD: EHLO mail3.sersis.com
[2017.10.06] 11:29:17 [06914] RSP: 250-cmgw-2.mail.tiscali.it hello [151.80.62.161], pleased to meet you
[2017.10.06] 11:29:17 [06914] RSP: 250-SIZE 104857600
[2017.10.06] 11:29:17 [06914] RSP: 250-ENHANCEDSTATUSCODES
[2017.10.06] 11:29:17 [06914] RSP: 250-8BITMIME
[2017.10.06] 11:29:17 [06914] RSP: 250 OK
[2017.10.06] 11:29:17 [06914] CMD: MAIL FROM:<angela@umfsrl.it> SIZE=26037
[2017.10.06] 11:29:17 [06914] RSP: 250 2.1.0 <angela@umfsrl.it> sender ok
[2017.10.06] 11:29:17 [06914] CMD: RCPT TO:<mecsav@tiscali.it>
[2017.10.06] 11:29:17 [06914] RSP: 250 2.1.5 <mecsav@tiscali.it> recipient ok
[2017.10.06] 11:29:17 [06914] CMD: DATA
[2017.10.06] 11:29:17 [06914] RSP: 354 enter mail, end with "." on a line by itself
[2017.10.06] 11:32:17 [06914] The smtp session has timed out.
[2017.10.06] 11:32:17 [06914] Initiating connection to 213.205.33.61
[2017.10.06] 11:32:17 [06914] Connecting to 213.205.33.61:25 (Id: 3)
[2017.10.06] 11:32:17 [06914] Binding to local IP 192.168.1.161:0 (Id: 3)
[2017.10.06] 11:32:17 [06914] Connection to 213.205.33.61:25 from 192.168.1.161:64351 succeeded (Id: 3)
[2017.10.06] 11:32:31 [06914] RSP: 220 cmgw-2.mail.tiscali.it ESMTP service ready
[2017.10.06] 11:32:31 [06914] CMD: EHLO mail3.sersis.com
[2017.10.06] 11:32:31 [06914] RSP: 250-cmgw-2.mail.tiscali.it hello [151.80.62.161], pleased to meet you
[2017.10.06] 11:32:31 [06914] RSP: 250-SIZE 104857600
[2017.10.06] 11:32:31 [06914] RSP: 250-ENHANCEDSTATUSCODES
[2017.10.06] 11:32:31 [06914] RSP: 250-8BITMIME
[2017.10.06] 11:32:31 [06914] RSP: 250 OK
[2017.10.06] 11:32:31 [06914] CMD: MAIL FROM:<angela@umfsrl.it> SIZE=26037
[2017.10.06] 11:32:31 [06914] RSP: 250 2.1.0 <angela@umfsrl.it> sender ok
[2017.10.06] 11:32:31 [06914] CMD: RCPT TO:<mecsav@tiscali.it>
[2017.10.06] 11:32:31 [06914] RSP: 250 2.1.5 <mecsav@tiscali.it> recipient ok
[2017.10.06] 11:32:31 [06914] CMD: DATA
[2017.10.06] 11:32:31 [06914] RSP: 354 enter mail, end with "." on a line by itself
[2017.10.06] 11:35:31 [06914] The smtp session has timed out.
[2017.10.06] 11:35:31 [06914] Initiating connection to 213.205.33.62
[2017.10.06] 11:35:31 [06914] Connecting to 213.205.33.62:25 (Id: 4)
[2017.10.06] 11:35:31 [06914] Binding to local IP 192.168.1.161:0 (Id: 4)
[2017.10.06] 11:35:31 [06914] Connection to 213.205.33.62:25 from 192.168.1.161:64412 succeeded (Id: 4)
[2017.10.06] 11:35:45 [06914] RSP: 220 cmgw-3.mail.tiscali.it ESMTP service ready
[2017.10.06] 11:35:45 [06914] CMD: EHLO mail3.sersis.com
[2017.10.06] 11:35:46 [06914] RSP: 250-cmgw-3.mail.tiscali.it hello [151.80.62.161], pleased to meet you
[2017.10.06] 11:35:46 [06914] RSP: 250-SIZE 104857600
[2017.10.06] 11:35:46 [06914] RSP: 250-ENHANCEDSTATUSCODES
[2017.10.06] 11:35:46 [06914] RSP: 250-8BITMIME
[2017.10.06] 11:35:46 [06914] RSP: 250 OK
[2017.10.06] 11:35:46 [06914] CMD: MAIL FROM:<angela@umfsrl.it> SIZE=26037
[2017.10.06] 11:35:46 [06914] RSP: 250 2.1.0 <angela@umfsrl.it> sender ok
[2017.10.06] 11:35:46 [06914] CMD: RCPT TO:<mecsav@tiscali.it>
[2017.10.06] 11:35:46 [06914] RSP: 250 2.1.5 <mecsav@tiscali.it> recipient ok
[2017.10.06] 11:35:46 [06914] CMD: DATA
[2017.10.06] 11:35:46 [06914] RSP: 354 enter mail, end with "." on a line by itself
[2017.10.06] 11:38:46 [06914] The smtp session has timed out.
[2017.10.06] 11:38:46 [06914] Initiating connection to 213.205.33.62
[2017.10.06] 11:38:46 [06914] Connecting to 213.205.33.62:25 (Id: 5)
[2017.10.06] 11:38:46 [06914] Binding to local IP 192.168.1.161:0 (Id: 5)
[2017.10.06] 11:38:46 [06914] Connection to 213.205.33.62:25 from 192.168.1.161:64451 succeeded (Id: 5)
[2017.10.06] 11:39:00 [06914] RSP: 220 cmgw-3.mail.tiscali.it ESMTP service ready
[2017.10.06] 11:39:00 [06914] CMD: EHLO mail3.sersis.com
[2017.10.06] 11:39:00 [06914] RSP: 250-cmgw-3.mail.tiscali.it hello [151.80.62.161], pleased to meet you
[2017.10.06] 11:39:00 [06914] RSP: 250-SIZE 104857600
[2017.10.06] 11:39:00 [06914] RSP: 250-ENHANCEDSTATUSCODES
[2017.10.06] 11:39:00 [06914] RSP: 250-8BITMIME
[2017.10.06] 11:39:00 [06914] RSP: 250 OK
[2017.10.06] 11:39:00 [06914] CMD: MAIL FROM:<angela@umfsrl.it> SIZE=26037
[2017.10.06] 11:39:00 [06914] RSP: 250 2.1.0 <angela@umfsrl.it> sender ok
[2017.10.06] 11:39:00 [06914] CMD: RCPT TO:<mecsav@tiscali.it>
[2017.10.06] 11:39:00 [06914] RSP: 250 2.1.5 <mecsav@tiscali.it> recipient ok
[2017.10.06] 11:39:00 [06914] CMD: DATA
[2017.10.06] 11:39:00 [06914] RSP: 354 enter mail, end with "." on a line by itself
[2017.10.06] 11:42:00 [06914] The smtp session has timed out.
[2017.10.06] 11:42:00 [06914] Initiating connection to 213.205.33.63
[2017.10.06] 11:42:00 [06914] Connecting to 213.205.33.63:25 (Id: 6)
[2017.10.06] 11:42:00 [06914] Binding to local IP 192.168.1.161:0 (Id: 6)
[2017.10.06] 11:42:00 [06914] Connection to 213.205.33.63:25 from 192.168.1.161:64481 succeeded (Id: 6)
[2017.10.06] 11:42:14 [06914] RSP: 220 cmgw-4.mail.tiscali.it ESMTP service ready
[2017.10.06] 11:42:14 [06914] CMD: EHLO mail3.sersis.com
[2017.10.06] 11:42:14 [06914] RSP: 250-cmgw-4.mail.tiscali.it hello [151.80.62.161], pleased to meet you
[2017.10.06] 11:42:14 [06914] RSP: 250-SIZE 104857600
[2017.10.06] 11:42:14 [06914] RSP: 250-ENHANCEDSTATUSCODES
[2017.10.06] 11:42:14 [06914] RSP: 250-8BITMIME
[2017.10.06] 11:42:14 [06914] RSP: 250 OK
[2017.10.06] 11:42:14 [06914] CMD: MAIL FROM:<angela@umfsrl.it> SIZE=26037
[2017.10.06] 11:42:14 [06914] RSP: 250 2.1.0 <angela@umfsrl.it> sender ok
[2017.10.06] 11:42:14 [06914] CMD: RCPT TO:<mecsav@tiscali.it>
[2017.10.06] 11:42:15 [06914] RSP: 250 2.1.5 <mecsav@tiscali.it> recipient ok
[2017.10.06] 11:42:15 [06914] CMD: DATA
[2017.10.06] 11:42:15 [06914] RSP: 354 enter mail, end with "." on a line by itself
[2017.10.06] 11:45:15 [06914] The smtp session has timed out.
[2017.10.06] 11:45:15 [06914] Initiating connection to 213.205.33.64
[2017.10.06] 11:45:15 [06914] Connecting to 213.205.33.64:25 (Id: 7)
[2017.10.06] 11:45:15 [06914] Binding to local IP 192.168.1.161:0 (Id: 7)
[2017.10.06] 11:45:15 [06914] Connection to 213.205.33.64:25 from 192.168.1.161:64512 succeeded (Id: 7)
[2017.10.06] 11:45:29 [06914] RSP: 220 cmgw-2.mail.tiscali.it ESMTP service ready
[2017.10.06] 11:45:29 [06914] CMD: EHLO mail3.sersis.com
[2017.10.06] 11:45:29 [06914] RSP: 250-cmgw-2.mail.tiscali.it hello [151.80.62.161], pleased to meet you
[2017.10.06] 11:45:29 [06914] RSP: 250-SIZE 104857600
[2017.10.06] 11:45:29 [06914] RSP: 250-ENHANCEDSTATUSCODES
[2017.10.06] 11:45:29 [06914] RSP: 250-8BITMIME
[2017.10.06] 11:45:29 [06914] RSP: 250 OK
[2017.10.06] 11:45:29 [06914] CMD: MAIL FROM:<angela@umfsrl.it> SIZE=26037
[2017.10.06] 11:45:29 [06914] RSP: 250 2.1.0 <angela@umfsrl.it> sender ok
[2017.10.06] 11:45:29 [06914] CMD: RCPT TO:<mecsav@tiscali.it>
[2017.10.06] 11:45:29 [06914] RSP: 250 2.1.5 <mecsav@tiscali.it> recipient ok
[2017.10.06] 11:45:29 [06914] CMD: DATA
[2017.10.06] 11:45:29 [06914] RSP: 354 enter mail, end with "." on a line by itself
[2017.10.06] 11:48:29 [06914] The smtp session has timed out.
[2017.10.06] 11:48:29 [06914] Initiating connection to 213.205.33.61
[2017.10.06] 11:48:29 [06914] Connecting to 213.205.33.61:25 (Id: 8)
[2017.10.06] 11:48:29 [06914] Binding to local IP 192.168.1.161:0 (Id: 8)
[2017.10.06] 11:48:29 [06914] Connection to 213.205.33.61:25 from 192.168.1.161:64546 succeeded (Id: 8)
[2017.10.06] 11:48:43 [06914] RSP: 220 cmgw-4.mail.tiscali.it ESMTP service ready
[2017.10.06] 11:48:43 [06914] CMD: EHLO mail3.sersis.com
[2017.10.06] 11:48:43 [06914] RSP: 250-cmgw-4.mail.tiscali.it hello [151.80.62.161], pleased to meet you
[2017.10.06] 11:48:43 [06914] RSP: 250-SIZE 104857600
[2017.10.06] 11:48:43 [06914] RSP: 250-ENHANCEDSTATUSCODES
[2017.10.06] 11:48:43 [06914] RSP: 250-8BITMIME
[2017.10.06] 11:48:43 [06914] RSP: 250 OK
[2017.10.06] 11:48:43 [06914] CMD: MAIL FROM:<angela@umfsrl.it> SIZE=26037
[2017.10.06] 11:48:43 [06914] RSP: 250 2.1.0 <angela@umfsrl.it> sender ok
[2017.10.06] 11:48:43 [06914] CMD: RCPT TO:<mecsav@tiscali.it>
[2017.10.06] 11:48:43 [06914] RSP: 250 2.1.5 <mecsav@tiscali.it> recipient ok
[2017.10.06] 11:48:43 [06914] CMD: DATA
[2017.10.06] 11:48:43 [06914] RSP: 354 enter mail, end with "." on a line by itself
[2017.10.06] 11:51:43 [06914] The smtp session has timed out.
[2017.10.06] 11:51:43 [06914] Initiating connection to 213.205.33.62
[2017.10.06] 11:51:43 [06914] Connecting to 213.205.33.62:25 (Id: 9)
[2017.10.06] 11:51:43 [06914] Binding to local IP 192.168.1.161:0 (Id: 9)
[2017.10.06] 11:51:43 [06914] Connection to 213.205.33.62:25 from 192.168.1.161:64566 succeeded (Id: 9)
[2017.10.06] 11:51:57 [06914] RSP: 220 cmgw-4.mail.tiscali.it ESMTP service ready
[2017.10.06] 11:51:57 [06914] CMD: EHLO mail3.sersis.com
[2017.10.06] 11:51:58 [06914] RSP: 250-cmgw-4.mail.tiscali.it hello [151.80.62.161], pleased to meet you
[2017.10.06] 11:51:58 [06914] RSP: 250-SIZE 104857600
[2017.10.06] 11:51:58 [06914] RSP: 250-ENHANCEDSTATUSCODES
[2017.10.06] 11:51:58 [06914] RSP: 250-8BITMIME
[2017.10.06] 11:51:58 [06914] RSP: 250 OK
[2017.10.06] 11:51:58 [06914] CMD: MAIL FROM:<angela@umfsrl.it> SIZE=26037
[2017.10.06] 11:51:58 [06914] RSP: 250 2.1.0 <angela@umfsrl.it> sender ok
[2017.10.06] 11:51:58 [06914] CMD: RCPT TO:<mecsav@tiscali.it>
[2017.10.06] 11:51:58 [06914] RSP: 250 2.1.5 <mecsav@tiscali.it> recipient ok
[2017.10.06] 11:51:58 [06914] CMD: DATA
[2017.10.06] 11:51:58 [06914] RSP: 354 enter mail, end with "." on a line by itself
[2017.10.06] 11:54:58 [06914] The smtp session has timed out.
[2017.10.06] 11:54:58 [06914] Initiating connection to 213.205.33.61
[2017.10.06] 11:54:58 [06914] Connecting to 213.205.33.61:25 (Id: 10)
[2017.10.06] 11:54:58 [06914] Binding to local IP 192.168.1.161:0 (Id: 10)
[2017.10.06] 11:54:58 [06914] Connection to 213.205.33.61:25 from 192.168.1.161:64594 succeeded (Id: 10)
[2017.10.06] 11:55:12 [06914] RSP: 220 cmgw-1.mail.tiscali.it ESMTP service ready
[2017.10.06] 11:55:12 [06914] CMD: EHLO mail3.sersis.com
[2017.10.06] 11:55:12 [06914] RSP: 250-cmgw-1.mail.tiscali.it hello [151.80.62.161], pleased to meet you
[2017.10.06] 11:55:12 [06914] RSP: 250-SIZE 104857600
[2017.10.06] 11:55:12 [06914] RSP: 250-ENHANCEDSTATUSCODES
[2017.10.06] 11:55:12 [06914] RSP: 250-8BITMIME
[2017.10.06] 11:55:12 [06914] RSP: 250 OK
[2017.10.06] 11:55:12 [06914] CMD: MAIL FROM:<angela@umfsrl.it> SIZE=26037
[2017.10.06] 11:55:12 [06914] RSP: 250 2.1.0 <angela@umfsrl.it> sender ok
[2017.10.06] 11:55:12 [06914] CMD: RCPT TO:<mecsav@tiscali.it>
[2017.10.06] 11:55:12 [06914] RSP: 250 2.1.5 <mecsav@tiscali.it> recipient ok
[2017.10.06] 11:55:12 [06914] CMD: DATA
[2017.10.06] 11:55:12 [06914] RSP: 354 enter mail, end with "." on a line by itself
[2017.10.06] 11:55:47 [06914] RSP: 250 2.0.0 J9vL1w01g3Uk8nK019vLgB mail accepted for delivery
[2017.10.06] 11:55:47 [06914] CMD: QUIT
[2017.10.06] 11:55:47 [06914] RSP: 221 2.0.0 cmgw-1.mail.tiscali.it closing connection
[2017.10.06] 11:55:47 [06914] Delivery for angela@umfsrl.it to mecsav@tiscali.it has completed (Delivered)
[2017.10.06] 11:55:49 [06914] Delivery finished for angela@umfsrl.it at 11:55:49 [id:x86706914]
0
Gabriele Maoret Replied
It seems to be a DECLUDE error in timeout while scanning the EML files. Raising up the timeout in DECLUDE seems to fix it.

Reply to Thread