We ran in to this
error few weeks back. with our Backup email relay and spooling system.
We have a Watchguard
firewall with a "SMTP proxy" filtering spam on all inbound traffic to
the relay servers
We noticed that we
are having a lot log entries where the email delivery failed with the following
entry in the SMTP log
[2014.03.05]
09:45:46 [89.249.234.3][18261257] cmd: DATA
[2014.03.05]
09:45:51 [89.249.234.3][18261257] rsp: 354 Start mail input; end with
<CRLF>.<CRLF>
[2014.03.05]
09:47:49 [89.249.234.3][18261257] rsp: 421 Command timeout, closing
transmission channel
[2014.03.05]
09:47:49 [89.249.234.3][18261257] data transfer failed.
[2014.03.05]
09:47:49 [89.249.234.3][18261257] disconnected at 05/03/2014 09:47:49
Cause:
The emails that are
dropped with the "data transfer failed." error are emails that were
quarantined or blocked by the WG Spam firewall
Details:
What's interesting
was we were not able to reproduce the issue. it seems to be happening for
random emails. then we checked the firewall logs to see if something was
happening to the email from the WG firewall
Firewall log for the effected email
ProxyMatch
ProxyQuarantine:
SMTP Classified as confirmed SPAM
pri=6
disp=Allow
policy=VPS072-SMRelay1_SMTP_Proxy_IN-00
protocol=smtp/tcp
src_ip=89.249.234.3
src_port=56029
dst_ip=185.17.174.55
dst_port=25
src_intf=1-WAN1
dst_intf=104-INBAY_SYSTEMS
rc=600
proxy_act=SMTP
incoming SM-Relay Proxy
Smartermail log
Initial handshake
and the SM server creates the connection
-----------------------------------------------------------------------------------------------------
[2014.03.05]
09:44:37 [89.249.234.3][18261257] rsp: 220 relay1.inbaysystems.com
[2014.03.05]
09:44:37 [89.249.234.3][18261257] connected at 05/03/2014 09:44:37
[2014.03.05]
09:44:41 [89.249.234.3][18261257] cmd: EHLO [89.249.234.3]
[2014.03.05]
09:44:41 [89.249.234.3][18261257] rsp: 250-relay1.inbaysystems.com Hello
[89.249.234.3]250-SIZE 52428800250-AUTH LOGIN CRAM-MD5250-STARTTLS250 OK
[2014.03.05]
09:44:44 [89.249.234.3][18261257] cmd: MAIL FROM:<[email protected]>
[2014.03.05]
09:44:49 [89.249.234.3][18261257] rsp: 250 OK <[email protected]>
Sender ok
[2014.03.05]
09:45:20 [89.249.234.3][18261257] cmd: RCPT TO:<[email protected]>
[2014.03.05]
09:45:20 [89.249.234.3][18261257] rsp: 250 OK <[email protected]>
Recipient ok
The email data
transfer starts and during this time the email is scanned and quarantined by
the WG firewall
causing the "data transfer failed." error
----------------------------------------------------------------------------------------------------------------------------
[2014.03.05]
09:45:46 [89.249.234.3][18261257] cmd: DATA
[2014.03.05]
09:45:51 [89.249.234.3][18261257] rsp: 354 Start mail input; end with
<CRLF>.<CRLF>
[2014.03.05]
09:47:49 [89.249.234.3][18261257] rsp: 421 Command timeout, closing
transmission channel
[2014.03.05]
09:47:49 [89.249.234.3][18261257] data transfer failed.
[2014.03.05]
09:47:49 [89.249.234.3][18261257] disconnected at 05/03/2014 09:47:49
----------------------------------------------------------------------------------------------------------------------------
I did a lot of
research online looking for an explanation for this stumbled upon a few other
things that may cause similar issues
MTU value issues
with ISP's and the local network
http://www.tweakservers.com/421-command-timeout/
Hope this will help
save some time for you guys, since there are no proper explanations or fixes
for this issue on the internet
