Thread Info
  • State Not Answered
  • Locked Locked
  • Replies 3 replies
  • Subscribers 27 subscribers
  • Views 8840 views
  • Users 0 members are here
Options
Suggested
This discussion has been locked.
You can no longer post new replies to this discussion. If you have a question you can start a new discussion

451 4.7.0 Timeout waiting for client input on exchange server

givemecontrol

Hey there.

Situation today is that my exchange 2016 server with a sophos XG 330 doing transparent relaying (Not MTA mode) is for some reason dropping connections from certain external mail servers. It does this with no delivery notice sent to the external people. The firewall email log says that the mail goes through fine. However when you look at exchange logs, i can see that it "start(s) mail input" and waits for the '.' to end the mail reception. This character never comes and the connection times out after 5 minutes ( 451 4.7.0 Timeout waiting for client input )


I believe that the sophos is somehow interacting with the external mail server in a negative way and not allowing part of the connection to come through. Anyone see this?

If i scan my exchange logs, its not just one external host, but many. I mean some of the results could be spam timeouts or something, but i cant just blame the other party here. Still i am not able to find any logs that are helpful and i need an external party to test the mail sending which isnt ideal for troubleshooting.

exchange log follows. you can see that the mail times out.

2019-03-11T22:55:29.741Z,EX2016\Default Frontend EX2016,08D6A3A3A25BF85C,0,10.0.0.16:25,70.XXX.YYY.ZZZ:34646,+,,
2019-03-11T22:55:29.741Z,EX2016\Default Frontend EX2016,08D6A3A3A25BF85C,1,10.0.0.16:25,70.XXX.YYY.ZZZ:34646,>,220 mail.DOMAIN.ca,
2019-03-11T22:55:29.741Z,EX2016\Default Frontend EX2016,08D6A3A3A25BF85C,2,10.0.0.16:25,70.XXX.YYY.ZZZ:34646,<,EHLO zoe.EXTERNAL_DOMAIN.com,
2019-03-11T22:55:29.741Z,EX2016\Default Frontend EX2016,08D6A3A3A25BF85C,3,10.0.0.16:25,70.XXX.YYY.ZZZ:34646,>,250  Ex2016.DOMAIN.ca Hello [70.XXX.YYY.ZZZ] SIZE 37748736 PIPELINING DSN ENHANCEDSTATUSCODES STARTTLS X-ANONYMOUSTLS AUTH NTLM X-EXPS GSSAPI NTLM 8BITMIME BINARYMIME CHUNKING XRDST,
2019-03-11T22:55:29.741Z,EX2016\Default Frontend EX2016,08D6A3A3A25BF85C,4,10.0.0.16:25,70.XXX.YYY.ZZZ:34646,<,MAIL FROM:<Membership@EXTERNAL_DOMAIN.ca> SIZE=7298 BODY=8BITMIME,
2019-03-11T22:55:29.741Z,EX2016\Default Frontend EX2016,08D6A3A3A25BF85C,5,10.0.0.16:25,70.XXX.YYY.ZZZ:34646,*,08D6A3A3A25BF85C;2019-03-11T22:55:29.741Z;1,receiving message
2019-03-11T22:55:29.741Z,EX2016\Default Frontend EX2016,08D6A3A3A25BF85C,6,10.0.0.16:25,70.XXX.YYY.ZZZ:34646,>,250 2.1.0 Sender OK,
2019-03-11T22:55:29.741Z,EX2016\Default Frontend EX2016,08D6A3A3A25BF85C,7,10.0.0.16:25,70.XXX.YYY.ZZZ:34646,<,RCPT TO:<USER@DOMAIN.ca> ORCPT=rfc822;USER@DOMAIN.ca,
2019-03-11T22:55:29.741Z,EX2016\Default Frontend EX2016,08D6A3A3A25BF85C,8,10.0.0.16:25,70.XXX.YYY.ZZZ:34646,>,250 2.1.5 Recipient OK,
2019-03-11T22:55:30.398Z,EX2016\Default Frontend EX2016,08D6A3A3A25BF85C,9,10.0.0.16:25,70.XXX.YYY.ZZZ:34646,<,DATA,
2019-03-11T22:55:30.398Z,EX2016\Default Frontend EX2016,08D6A3A3A25BF85C,10,10.0.0.16:25,70.XXX.YYY.ZZZ:34646,>,354 Start mail input; end with <CRLF>.<CRLF>,

2019-03-11T23:00:30.542Z,EX2016\Default Frontend EX2016,08D6A3A3A25BF85C,11,10.0.0.16:25,70.XXX.YYY.ZZZ:34646,>,451 4.7.0 Timeout waiting for client input,
2019-03-11T23:00:30.542Z,EX2016\Default Frontend EX2016,08D6A3A3A25BF85C,12,10.0.0.16:25,70.XXX.YYY.ZZZ:34646,-,,Local

 

 

The external party sent me their logs and from their perspective, the mail was delivered fine (this is from a different test, just done a day apart):

Mar 12 10:51:23 zoe postfix/smtp[25886]: < mail.DOMAIN.ca[x.x.x.x]:25: 220 mail.DOMAIN.ca
Mar 12 10:51:23 zoe postfix/smtp[25886]: > mail.DOMAIN.ca[x.x.x.x]:25: EHLO zoe.EXTERNAL_DOMAIN.com
Mar 12 10:51:23 zoe postfix/smtp[25886]: < mail.DOMAIN.ca[x.x.x.x]:25: 250-Ex2016.DOMAIN.ca Hello [70.XXX.YYY.ZZZ]
Mar 12 10:51:23 zoe postfix/smtp[25886]: < mail.DOMAIN.ca[x.x.x.x]:25: 250-SIZE 37748736
Mar 12 10:51:23 zoe postfix/smtp[25886]: < mail.DOMAIN.ca[x.x.x.x]:25: 250-DSN
Mar 12 10:51:23 zoe postfix/smtp[25886]: < mail.DOMAIN.ca[x.x.x.x]:25: 250-ENHANCEDSTATUSCODES
Mar 12 10:51:23 zoe postfix/smtp[25886]: < mail.DOMAIN.ca[x.x.x.x]:25: 250-STARTTLS
Mar 12 10:51:23 zoe postfix/smtp[25886]: < mail.DOMAIN.ca[x.x.x.x]:25: 250-X-ANONYMOUSTLS
Mar 12 10:51:23 zoe postfix/smtp[25886]: < mail.DOMAIN.ca[x.x.x.x]:25: 250-AUTH NTLM
Mar 12 10:51:23 zoe postfix/smtp[25886]: < mail.DOMAIN.ca[x.x.x.x]:25: 250-X-EXPS GSSAPI NTLM
Mar 12 10:51:23 zoe postfix/smtp[25886]: < mail.DOMAIN.ca[x.x.x.x]:25: 250-8BITMIME
Mar 12 10:51:23 zoe postfix/smtp[25886]: < mail.DOMAIN.ca[x.x.x.x]:25: 250 XRDST
Mar 12 10:51:23 zoe postfix/smtp[25886]: > mail.DOMAIN.ca[x.x.x.x]:25: MAIL FROM:<EXTERNAL_USER@EXTERNAL_DOMAIN.com> SIZE=7323 BODY=8BITMIME
Mar 12 10:51:23 zoe postfix/smtp[25886]: < mail.DOMAIN.ca[x.x.x.x]:25: 250 2.1.0 Sender OK
Mar 12 10:51:23 zoe postfix/smtp[25886]: > mail.DOMAIN.ca[x.x.x.x]:25: RCPT TO:<humanresources@DOMAIN.ca> ORCPT=rfc822;humanresources@DOMAIN.ca
Mar 12 10:51:23 zoe postfix/smtp[25886]: < mail.DOMAIN.ca[x.x.x.x]:25: 250 2.1.5 Recipient OK
Mar 12 10:51:23 zoe postfix/smtp[25886]: > mail.DOMAIN.ca[x.x.x.x]:25: DATA
Mar 12 10:51:23 zoe postfix/smtp[25886]: < mail.DOMAIN.ca[x.x.x.x]:25: 354
Mar 12 10:51:24 zoe postfix/smtp[25886]: > mail.DOMAIN.ca[x.x.x.x]:25: .
Mar 12 10:51:24 zoe postfix/smtp[25886]: < mail.DOMAIN.ca[x.x.x.x]:25: 250 Queued id=0x20012baa
Mar 12 10:51:24 zoe postfix/smtp[25886]: > mail.DOMAIN.ca[x.x.x.x]:25: QUIT



This thread was automatically locked due to age.
Parents
  • 0

    Howdy,

    This is expected behaviour in Legacy mode (transparent proxy) when the RBL lookups don't work as expected.

    Go through the RBL lists and remove the entries one by one until mail flow works again. A more time consuming way is getting Advanced Shell access to the XG and wading through /var/tslog/awarrensmtp.log (from memory, could be wrong filename) to see where it's failing.

    If you want to persist with Legacy mode get used to this lack of transparency on failure mode and keep a regular eye on the health status of the RBL services you're using.

Reply
  • 0

    Howdy,

    This is expected behaviour in Legacy mode (transparent proxy) when the RBL lookups don't work as expected.

    Go through the RBL lists and remove the entries one by one until mail flow works again. A more time consuming way is getting Advanced Shell access to the XG and wading through /var/tslog/awarrensmtp.log (from memory, could be wrong filename) to see where it's failing.

    If you want to persist with Legacy mode get used to this lack of transparency on failure mode and keep a regular eye on the health status of the RBL services you're using.

Children
  • 0 in reply to ChrisKnight

    I have several problems with your answer, but lets just basically state that the external mailserver is NOT on any RBLs.

    Usually it would say something like "blocked by RBL" or something obvious like that.

     

     

    i changed the "standard RBL services" to reject instead of drop, and i can see if i get a different error now.

    I also whitelisted the domain a long time ago, which takes precedence in the rule order.

     

    in short, i dont think you are correct about the cause.

     

    And lets just revisit WHY someone is using it in "legacy" mode. Because all other modes break SPF and DKIM. That has been an active bug for YEARS.

  • 0 in reply to givemecontrol

    Howdy,

    The failure scenario you provided was identical to the issues I faced when using Legacy mode.

    After much digging through the firewall logs via the Advanced Shell I found that the timeout was due to certain RBL providers either not returning a result or taking an exceptionally long time to return a result, resulting in the SMTP conversation with the internal Exchange server timing out with no traffic passed. The issue was the RBL provider, not whether or not the inbound SMTP server was on the RBL or not. Whitelisting the domain didn't work for me as this occurs after RBL checks.

    With the exception of 17.5 breaking the message body of mails passing through the MTA such that message body signature checks fail, I've not had a problem with either SPF or DKIM with an XG in MTA mode. My current workaround is by having a rule before the auto-generated rule for MTA mode, and this rule allows the internal mail servers performing DKIM signing to send direct to the smarthost/destination mail server so that the MTA doesn't get a chance to screw up the message body. Not doing inbound DKIM verification because the XG doesn't support it yet. And don't have a problem with SPF - I'd be interested what problems you have with it.