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

Recipient Verification: Verify recipients: With callout not working as expected

Helo world,

I am trying to use the Email Protection of a Sophos UTM as a replacement for an aging Barracuda Spam Firewall on which the license will go dark on Jan. 30 and will not be renewed. Sophos Email Protection is my first choice as the company desires migrating to all Sophos UTM hardware in the near future and is working with a Partner. My backup solution is a VM from mailcleaner.org but I really want the Sophos UTM to work. I would love to open a support ticket, but alas I am only using a trail version until...I can prove it actually works so I can get the PO approved for the Sophos hardware.

In my testing it is working except for one important thing. When setting up the SMTP Proxy, I of course wish to use the Recipient Verification With Callout to prevent the huge amount of spam sent to invalid recipients from ever being sent to the destination mail server as this is one of the main reasons to use an SMTP Proxy (a.k.a. Spam Firewall), but it is not working as expected. The Sophos UTM and the destination mail server are both on public static IPs resolvable with reverse DNS, and there is currently no way to move the hosted cPanel that runs the destination mail server behind the Sophos UTM. I am not sure if this is part of my problem or not since mail is flowing. UTM Version I am using is latest 9.306-6 and cPanel Exim is 4.82

The User Guide States:
Recipient Verification
Verify Recipients: Here you can specify whether and how email recipients are to be verified.
With Callout: A request is sent to the server to verify the recipient.

User Guide never states which server but the assumption is that it would get verification from the actual destination mail server as the sending server and the UTM would have no knowledge of if a recipient is valid or not.

Can someone please clarify if my assumption is correct and if so, I can confirm that is not what actually seems to be happening. Instead, the Live Log would seem to indicate that the verification is done by the sending server and it succeeds and then proceeds to Greylisting and then delivers the email to the work queue and sends it to the destination server even if the user does not exist. This makes no sense. How can an address that does not exist on the destination mail server get verified and from whom???

Additionally, a tail of the Exim mainlog on the destination server shows no evidence of ever being asked to perform a recipient verification and only shows the mail being received after it leaves the UTM. For non-existent mail accounts, the destination mail server log shows "Unrouteable address" and bounces a permanent error message to sender which sender receives. For mail accounts that exist, the message is delivered as expected.

I will post some of the logs in a moment, but I sure would appreciate some help. Thanks!


This thread was automatically locked due to age.
  • Logs are shown, but names and numbers are changed for security reasons.

    UTM SMTP Proxy Live Log from a valid mail account:
    2015:01:27-23:14:09 7552-5 exim-in[4684]: 2015-01-27 23:14:09 SMTP connection from [216.109.115.45]:42512 (TCP/IP connection count = 1)
    
    2015:01:27-23:14:09 7552-5 exim-in[7898]: 2015-01-27 23:14:09 [216.109.115.45] F= R= Verifying recipient address with callout
    2015:01:27-23:14:10 7552-5 exim-in[7898]: 2015-01-27 23:14:10 1YGK13-00023O-2y DKIM: d=yahoo.com s=s2048 c=relaxed/relaxed a=rsa-sha256 t=1422418307 [verification succeeded]
    2015:01:27-23:14:10 7552-5 exim-in[7898]: 2015-01-27 23:14:10 1YGK13-00023O-2y ctasd reports 'Unknown' RefID:str=0001.0A020206.54C86212.002A,ss=1,re=0.000,recu=0.000,reip=0.000,cl=1,cld=1,fgs=0
    2015:01:27-23:14:10 7552-5 exim-in[7898]: 2015-01-27 23:14:10 1YGK13-00023O-2y Greylisting: Greylisted 216.109.115.45
    2015:01:27-23:14:10 7552-5 exim-in[7898]: [1\34] 2015-01-27 23:14:10 1YGK13-00023O-2y H=nm44-vm9.bullet.mail.bf1.yahoo.com [216.109.115.45]:42512 F= temporarily rejected after DATA: Temporary local problem, please try again!
    Repeats a minute later, and then finally:
    2015:01:27-23:17:54 7552-5 exim-in[4684]: 2015-01-27 23:17:54 SMTP connection from [216.109.115.45]:58297 (TCP/IP connection count = 1)
    2015:01:27-23:17:55 7552-5 exim-in[8386]: 2015-01-27 23:17:55 [216.109.115.45] F= R= Verifying recipient address with callout
    2015:01:27-23:17:55 7552-5 exim-in[8386]: 2015-01-27 23:17:55 1YGK4h-0002BG-0X DKIM: d=yahoo.com s=s2048 c=relaxed/relaxed a=rsa-sha256 t=1422418307 [verification succeeded]
    2015:01:27-23:17:55 7552-5 exim-in[8386]: 2015-01-27 23:17:55 1YGK4h-0002BG-0X ctasd reports 'Unknown' RefID:str=0001.0A020206.54C862F3.0096,ss=1,re=0.000,recu=0.000,reip=0.000,cl=1,cld=1,fgs=0
    2015:01:27-23:17:55 7552-5 exim-in[8386]: 2015-01-27 23:17:55 1YGK4h-0002BG-0X Greylisting: Successful greylist retry from 216.109.115.45 (original host was 216.109.115.45/32)
    2015:01:27-23:17:55 7552-5 exim-in[8386]: 2015-01-27 23:17:55 1YGK4h-0002BG-0X  work R=SCANNER T=SCANNER
    2015:01:27-23:18:00 7552-5 smtpd[8391]: SCANNER[8391]: 1YGK4h-0002BG-0X Completed
    2015:01:27-23:18:01 7552-5 exim-out[8394]: 2015-01-27 23:18:01 1YGK4m-0002BL-84 => valid-user@test-domain.com P= R=static_route_hostlist T=static_smtp H=68.166.142.198 [68.166.142.198]:25 X=TLSv1[[[[:D]]]]HE-RSA-AES256-SHA:256 C="250 OK id=1YGK4m-0002Js-Vp"
    2015:01:27-23:18:01 7552-5 exim-out[8394]: 2015-01-27 23:18:01 1YGK4m-0002BL-84 Completed


    UTM SMTP Proxy Live Log from a non-existent mail account:
    2015:01:27-22:59:01 7552-5 exim-in[4684]: 2015-01-27 22:59:01 SMTP connection from [72.30.238.197]:59824 (TCP/IP connection count = 1)
    
    2015:01:27-22:59:03 7552-5 exim-in[6625]: 2015-01-27 22:59:03 [72.30.238.197] F= R= Verifying recipient address with callout
    2015:01:27-22:59:03 7552-5 exim-in[6625]: 2015-01-27 22:59:03 1YGJmR-0001ir-0Z DKIM: d=yahoo.com s=s2048 c=relaxed/relaxed a=rsa-sha256 t=1422417541 [verification succeeded]
    2015:01:27-22:59:03 7552-5 exim-in[6625]: 2015-01-27 22:59:03 1YGJmR-0001ir-0Z ctasd reports 'Unknown' RefID:str=0001.0A020201.54C85E87.00CD,ss=1,re=0.000,recu=0.000,reip=0.000,cl=1,cld=1,fgs=0
    2015:01:27-22:59:03 7552-5 exim-in[6625]: 2015-01-27 22:59:03 1YGJmR-0001ir-0Z Greylisting: Greylisted 72.30.238.197
    2015:01:27-22:59:03 7552-5 exim-in[6625]: [1\34] 2015-01-27 22:59:03 1YGJmR-0001ir-0Z H=nm35.bullet.mail.bf1.yahoo.com [72.30.238.197]:59824 F= temporarily rejected after DATA: Temporary local problem, please try again!
    Repeats a minute later, and then finally:
    2015:01:27-23:05:10 7552-5 exim-in[4684]: 2015-01-27 23:05:10 SMTP connection from [72.30.238.197]:44096 (TCP/IP connection count = 1)
    2015:01:27-23:05:10 7552-5 exim-in[7289]: 2015-01-27 23:05:10 [72.30.238.197] F= R= Verifying recipient address with callout
    2015:01:27-23:05:10 7552-5 exim-in[7289]: 2015-01-27 23:05:10 1YGJsM-0001tZ-23 DKIM: d=yahoo.com s=s2048 c=relaxed/relaxed a=rsa-sha256 t=1422417541 [verification succeeded]
    2015:01:27-23:05:10 7552-5 exim-in[7289]: 2015-01-27 23:05:10 1YGJsM-0001tZ-23 ctasd reports 'Unknown' RefID:str=0001.0A020204.54C85FF6.0141,ss=1,re=0.000,recu=0.000,reip=0.000,cl=1,cld=1,fgs=0
    2015:01:27-23:05:10 7552-5 exim-in[7289]: 2015-01-27 23:05:10 1YGJsM-0001tZ-23 Greylisting: Successful greylist retry from 72.30.238.197 (original host was 72.30.238.197/32)
    2015:01:27-23:05:10 7552-5 exim-in[7289]: 2015-01-27 23:05:10 1YGJsM-0001tZ-23  work R=SCANNER T=SCANNER
    2015:01:27-23:05:20 7552-5 smtpd[7295]: SCANNER[7295]: 1YGJsM-0001tZ-23 Completed
    2015:01:27-23:05:21 7552-5 exim-out[7298]: 2015-01-27 23:05:21 1YGJsW-0001tf-7Y => non-existent@test-domain.com P= R=static_route_hostlist T=static_smtp H=68.166.142.198 [68.166.142.198]:25 X=TLSv1[[[[:D]]]]HE-RSA-AES256-SHA:256 C="250 OK id=1YGJsW-00026N-Ue"
    2015:01:27-23:05:21 7552-5 exim-out[7298]: 2015-01-27 23:05:21 1YGJsW-0001tf-7Y Completed


    Both Live Logs are basically exactly the same even though one mail account exists on the destination mail server and the other does not. Yet they both pass Recipient Verification. How can this be?

    On the receiving end the Exim Logs are as follows:

    cPanel Exim log from a valid mail account:
    2015-01-27 23:18:00 [21032] SMTP connection from [96.253.126.67]:45340 I=[68.166.142.198]:25 (TCP/IP connection count = 1)
    
    2015-01-27 23:18:00 [8920] H=7552-5.UTM-server.com [96.253.126.67]:45340 I=[68.166.142.198]:25 Warning: Sender rate 1.7 / 1h
    2015-01-27 23:18:01 [8920] 1YGK4m-0002Js-Vp H=7552-5.UTM-server.com [96.253.126.67]:45340 I=[68.166.142.198]:25 Warning: Message has been scanned: no virus or other harmful content was found
    2015-01-27 23:18:01 [8920] 1YGK4m-0002Js-Vp  for valid-user@test-domain.com
    2015-01-27 23:18:01 [8922] cwd=/var/spool/exim 3 args: /usr/sbin/exim -Mc 1YGK4m-0002Js-Vp
    2015-01-27 23:18:01 [8920] SMTP connection from 7552-5.UTM-server.com [96.253.126.67]:45340 I=[68.166.142.198]:25 closed by QUIT
    2015-01-27 23:18:01 [8922] 1YGK4m-0002Js-Vp => test-sender (vaild-forwarder@test-domain.com, vaild-forwarder@test-domain.com, valid-user@test-domain.com)  F= P= R=virtual_user T=virtual_userdelivery S=3181 QT=1s DT=0s
    2015-01-27 23:18:01 [8922] 1YGK4m-0002Js-Vp => test-sender  F= P= R=virtual_user T=virtual_userdelivery S=3181 QT=1s DT=0s
    2015-01-27 23:18:01 [8922] 1YGK4m-0002Js-Vp Completed QT=1s


    cPanel Exim log from a non-existent mail account:
    2015-01-27 23:05:20 [21032] SMTP connection from [96.253.126.67]:45332 I=[68.166.142.198]:25 (TCP/IP connection count = 2)
    
    2015-01-27 23:05:20 [8083] H=7552-5.UTM-server.com [96.253.126.67]:45332 I=[68.166.142.198]:25 Warning: Sender rate 1.0 / 1h
    2015-01-27 23:05:21 [8083] 1YGJsW-00026N-Ue H=7552-5.UTM-server.com [96.253.126.67]:45332 I=[68.166.142.198]:25 Warning: Message has been scanned: no virus or other harmful content was found
    2015-01-27 23:05:21 [8083] 1YGJsW-00026N-Ue  for non-existent@test-domain.com
    2015-01-27 23:05:21 [8085] cwd=/var/spool/exim 3 args: /usr/sbin/exim -Mc 1YGJsW-00026N-Ue
    2015-01-27 23:05:21 [8083] SMTP connection from 7552-5.UTM-server.com [96.253.126.67]:45332 I=[68.166.142.198]:25 closed by QUIT
    2015-01-27 23:05:21 [8085] 1YGJsW-00026N-Ue ** non-existent@test-domain.com F=: Unrouteable address
    2015-01-27 23:05:21 [8088] cwd=/var/spool/exim 7 args: /usr/sbin/exim -t -oem -oi -f <> -E1YGJsW-00026N-Ue
    2015-01-27 23:05:21 [8088] 1YGJsX-00026S-57 <> R=1YGJsW-00026N-Ue U=mailnull P=local S=3930 M8S=0 T="Mail delivery failed: returning message to sender" from <> for test-sender@yahoo.com
    2015-01-27 23:05:21 [8090] cwd=/var/spool/exim 3 args: /usr/sbin/exim -Mc 1YGJsX-00026S-57
    2015-01-27 23:05:21 [8085] 1YGJsW-00026N-Ue Completed QT=1s
    2015-01-27 23:05:23 [8090] 1YGJsX-00026S-57 => test-sender@yahoo.com F=<> P=<> R=dkim_lookuphost T=dkim_remote_smtp S=4356 H=mta7.am0.yahoodns.net [98.136.216.26]:25 X=TLSv1:RC4-SHA:128 CV=no DN="/C=US/ST=California/L=Sunnyvale/O=Yahoo Inc./OU=Information Technology/CN=*.am0.yahoodns.net" C="250 ok dirdel" QT=2s DT=2s
    2015-01-27 23:05:23 [8090] 1YGJsX-00026S-57 Completed QT=2s


    Once again, thanks in advance for any help.

    Best Regards - HTG
    Frustrated Sophos Partner seeing all the things
    that brought me to Sophos slowly slip away.
    RIP astaro.org

  • Hi htguru,

    UTM verification with callout will not work if your internal mail server doesn't have some kind of spam agent that checks if the receipient exist in the organization (after "RCPT TO" SMTP command).

    Look at my example in the screenshot. Exchange server behind UTM will accept mail for non-existent user (it doesn't have any spam agent installed on it). It will later fail to deliver it, of course, and reply from the postmaster will be generated for the sender.

    You can test it from UTM shell with your mail server.
  • Just to add this....the goal of this company was to collect all wrong e-mails in postmaster mailbox (just in case that outside user misspelled e-mail address).

    You can see the screenshot from another production Exchange server where that check is enabled.
  • Hi htguru,

    UTM verification with callout will not work if your internal mail server doesn't have some kind of spam agent that checks if the receipient exist in the organization (after "RCPT TO" SMTP command).

    Look at my example in the screenshot. Exchange server behind UTM will accept mail for non-existent user (it doesn't have any spam agent installed on it). It will later fail to deliver it, of course, and reply from the postmaster will be generated for the sender.

    You can test it from UTM shell with your mail server.


    Thanks for your reply.

    My internal server is actually external as it is not behind the UTM. I don't know if this makes a difference. Also it is not an Exchange server but a cPanel server running the same Exim mail server that runs on the UTM. To the best of my knowledge I have verified the settings and the cPanel's mail server is set to both verify recipients and detect spam with SpamAssassin.

    My problem is as far as I can tell the UTM is never asking my mail server to verify the recipient and it is somehow verifying it elsewhere like on the sending server which makes no sense. There is no trace in the logs on either the UTM or the mail server that the UTM is actually asking the cPanel to verify anything yet it succeeds to verify somehow and then passes the mail.

    So in your instance as I understand it your Exchange server needs to perform certain actions it is not currently configured for in order for it to succeed in verifying only valid recipients so you are relying on the internal server to bounce the message. My cPanel however is configured to verify recipients and yet it does not appear that it is ever being asked to do so. It also will bounce a message sent to a nonexistent recipient but I do not want this to occur on the internal server. This should be the work of the SMTP proxy through recipient verification and the actual mail messages should never reach the internal server, rather only the brief request for recipient validation so as to not waste all the bandwidth of moving the message to the internal server and then bouncing it out to the sender again.

    I will definitely take you up on verifying recipient verification works by telnetting to the mail server from the UTM shell but if the UTM is not asking to verify the recipient when it is supposed to then it will not matter whether or not the cPanel answers correctly because it is never asked anything until the actual message arrives.

    Regards,
    Htguru

    Best Regards - HTG
    Frustrated Sophos Partner seeing all the things
    that brought me to Sophos slowly slip away.
    RIP astaro.org

  • Just to add this....the goal of this company was to collect all wrong e-mails in postmaster mailbox (just in case that outside user misspelled e-mail address).

    You can see the screenshot from another production Exchange server where that check is enabled.


    In your additional reply where that is checked does that Exchange server respond to a request for recipient validation and cause the UTM to discard invalid recipients rather then pass the mail and make Exchange do it?

    Best Regards - HTG
    Frustrated Sophos Partner seeing all the things
    that brought me to Sophos slowly slip away.
    RIP astaro.org

  • I will test all scenarios in my lab (rather than in production..[;)]) with UTM/Exchange combination after working hours and will post the results back.

    But I remember that conclusion from my early days with UTM, while learning and testing the product in the virtual lab.
  • Yep, I was right...[:)]...callout verification depends on how protected mail server responds to RCPT TO command. It doesn't matter if the protected mail server is internal or external, as long as UTM is listed in DNS MX record for the domain and can communicate with the mail server.

    I did a quick install of MailEnable free e-mail server, which obviously has that spam filter enabled by default. 

    Here are the results:

    1. Case One - mail sent to an existing user

    a) UTM is doing callout verification test. Notice that MAIL FROM address is blank, there is no message size specified and that immediately after "recipient OK" message UTM quits the connection:

    MAIL FROM:<>
    250 Requested mail action okay, completed
    RCPT TO:
    250 Requested mail action okay, completed
    QUIT 221 Service closing transmission channel

    b) UTM forwards a real message after a few seconds, this time with included sender e-mail address, message size and data:
    MAIL FROM: SIZE=4049
    250 Requested mail action okay, completed
    RCPT TO:
    250 Requested mail action okay, completed
    DATA 354 Start mail input; end with 
    QUIT 221 Service closing transmission channel


    2. Case Two - mail sent to non-existing user

    a) UTM is doing callout test verification, but this time mail server denies further communication after RCPT TO command:
    MAIL FROM:<>
    250 Requested mail action okay, completed
    RCPT TO:
    550 Requested action not taken: mailbox unavailable or not local
    QUIT 221 Service closing transmission channel

    b) UTM sends back "550 Address unknown" to the originating mail server which then notifies originating sender about the problem. UTM SMPT log lines:
    2015:01:28-17:18:58 utm exim-in[32401]: 2015-01-28 17:18:58 [209.85.218.53] F= R= Verifying recipient address with callout
    2015:01:28-17:18:58 utm exim-in[32401]: 2015-01-28 17:18:58 id="1003" severity="info" sys="SecureMail" sub="smtp" name="email rejected" srcip="209.85.218.53" from="vilic@externaldomain.rs" to="jsmith2@internaldomain.com" size="2829" reason="address_verification" extra="Address unknown"



    UTM verification with callout functionality finally demystified ..[;)]
  • Hi, and welcome to the User BB!

    First, there are excellent pre-sales engineers available to help those in a trial.  You access these folks via your reseller, so your first step should be to find a strong reseller and then get them involved.

    Having said that, I can tell you that vilic is 100% correct.  I just checked two domains with external servers, one of which is cPanel (Bluehost) and the other not.  Both use "With callout" and both work fine.  From a test email to the one using cPanel:

    H=mail-oi0-f54.google.com [209.85.218.54]:47734 F= rejected RCPT : Address unknown


    The [verification succeeded] you're seeing in your logs is related to DKIM, not recipient verification.

    Cheers - Bob

     
    Sophos UTM Community Moderator
    Sophos Certified Architect - UTM
    Sophos Certified Engineer - XG
    Gold Solution Partner since 2005
    MediaSoft, Inc. USA
  • Vilic and Bob,

    You have helped me to figure out a few things.

    1. I can now see that the verification in my logs was DKIM so not relevant. Thanks Bob.

    2. I have have performed the same tests as both of you by telneting to my destination mail server on port 25 and I do not receive a 550 after RCPT TO: . I get the 250 OK. If I may conclude correctly, this means that the cPanel is not properly configured for recipient callouts, unlike your server(s) that are.

    3. When I send test mails from my Yahoo account they get greylisted by the UTM SMTP Proxy no matter if they are sent to a valid or invalid recipient on the destination cPanel mail server and nothing is ever shown in the UTM SMTP Proxy Live Log that shows communication with the destination mail server at time of sending. Eventually (about 7 min) Greylisting succeeds for both valid and invalid recipients and the message is delivered to the destination mail server and is correctly bounced back to Yahoo for invalid recipents or delivered for valid ones.

    4. Out of desperation I looked at the tail of the Exim main log on the cPanel and discovered at least the UTM does it fact establish communication with the destination mail server at time of sending from Yahoo. I would guess this is in fact the elusive callout to verify the recipient. Yeah! This is some progress; at least the UTM appears to be doing the callout, it is just not working.

    These are the the logs entries I get and I assume that after this fails, the UTM goes go Greylisting since the bad response from the destination mail server is not able to verify the recipient.

    Exim Main Log Entry for callout from UTM for valid-user@test-domain.com:
    2015-01-28 17:49:19 [21032] SMTP connection from [96.253.126.67]:45739 I=[68.166.142.198]:25 (TCP/IP connection count = 1)
    
    2015-01-28 17:49:19 [7330] H=7552-5.UTM-server.com [96.253.126.67]:45739 I=[68.166.142.198]:25 Warning: Sender rate 1.9 / 1h
    2015-01-28 17:49:19 [7330] H=7552-5.UTM-server.com [96.253.126.67]:45739 I=[68.166.142.198]:25 incomplete transaction (QUIT) from <> for valid-user@test-domain.com
    2015-01-28 17:49:19 [7330] SMTP connection from 7552-5.UTM-server.com [96.253.126.67]:45739 I=[68.166.142.198]:25 closed by QUIT


    Exim Main Log Entry for callout from UTM for invalid-user@test-domain.com:
    2015-01-28 17:11:56 [21032] SMTP connection from [96.253.126.67]:45726 I=[68.166.142.198]:25 (TCP/IP connection count = 1)
    
    2015-01-28 17:11:56 [3953] H=7552-5.UTM-server.com [96.253.126.67]:45726 I=[68.166.142.198]:25 Warning: Sender rate 1.0 / 1h
    2015-01-28 17:11:56 [3953] H=7552-5.UTM-server.com [96.253.126.67]:45726 I=[68.166.142.198]:25 incomplete transaction (QUIT) from <> for invalid-user@test-domain.com
    2015-01-28 17:11:56 [3953] SMTP connection from 7552-5.UTM-server.com [96.253.126.67]:45726 I=[68.166.142.198]:25 closed by QUIT


    As you can see, both log entries are identical except for the RCPT TO addresses. Additionally, on line 3 of each, you can see the response form cPanel is "incomplete transaction (Quit)."

    In conclusion, I have documented that it is broken. I do hope one of you superguru gentleman can tell me what to fix and how.

    P.S. Is there a way to enable the callout to be logged in the SMTP Proxy Live Log? What about another log where communication from the UTM to to destination mail server for the callout can be seen on the UTM side? Even a log only accessible from SSH loginuser that I could tail for troubleshooting would be ok. Would "tail -f /var/log/exim_mainlog" work from a UTM SSH session like in does in cPanel since both servers use Exim?

    Best Regards - HTG
    Frustrated Sophos Partner seeing all the things
    that brought me to Sophos slowly slip away.
    RIP astaro.org

  • All of the exim lines are in the SMTP log. You can watch the SMTP Live Log, put exim in the filter box, hit enter and watch just those lines.

    To get more detail, you would need to use tcpdump at the command line.  However, my guess is that the setting that needs to changed is something your email provider needs to change as their configuration of exim doesn't seem to respond correctly to the RCPT TO command. 

    Cheers - Bob

    Sorry for any short responses.  Posted from my iPhone.
     
    Sophos UTM Community Moderator
    Sophos Certified Architect - UTM
    Sophos Certified Engineer - XG
    Gold Solution Partner since 2005
    MediaSoft, Inc. USA