Thread Info
  • State Not Answered
  • Replies 6 replies
  • Subscribers 0 subscribers
  • Views 5197 views
  • Users 0 members are here
Options
Suggested

[9.065][ANSWERED] SMTP Failed To Expand ACL String on DNS ptr failure

Billybob
Hi, I have a few emails that are getting temporarily rejected due to ACL string error. Here are a few log snippets...
/var/log/smtp/2013/02/smtp-2013-02-10.log.gz:2013:02:10-06:15:54 gatekeeper exim-in[4648]: 2013-02-10 06:15:54 H=([36.73.64.11]) [36.73.64.11]:18546 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=36.73.64.11" gave DEFER:


gatekeeper exim-in[24914]: 2013-02-13 03:11:53 H=([180.245.209.110]) [180.245.209.110]:15930 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=180.245.209.110" gave DEFER:


gatekeeper exim-in[20166]: 2013-02-14 10:16:33 H=(mta27.agedpr.com) [192.69.94.222]:37556 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=192.69.94.222" gave DEFER:

and DNS query......... 
gatekeeper:/var/log # dig ptr 222.94.69.192.in-addr.arpa



; <>> DiG 9.6-ESV-R7-P4 <>> ptr 222.94.69.192.in-addr.arpa

;; global options: +cmd

;; Got answer:

;; ->>HEADER

and DNS log... 
2013:02:18-21:10:40 gatekeeper named[4207]: error (unexpected RCODE SERVFAIL) resolving '222.94.69.192.in-addr.arpa/PTR/IN': 199.19.111.7#53

2013:02:18-21:10:40 gatekeeper named[4207]: error (unexpected RCODE SERVFAIL) resolving '222.94.69.192.in-addr.arpa/PTR/IN': 204.124.182.253#53

Regards
Bill
  • 0
    For me this looks like a problem with the reverse zone hosting 192.69.94.222. With "dig ptr 222.94.69.192.in-addr.arpa @z.arin.net" i get "dns4.volumedrive.com" and "dns3.volumedrive.com" in authority section. Doing a "dig ptr 222.94.69.192.in-addr.arpa @dns4.volumedrive.com" then gets me a "SERVFAIL". I also get a fail for the other two ips.

    Do you have "Reject invalid HELO / missing RDNS" activated on your UTM? I assume the UTM is checking the RDNS on incoming mail. In case of 192.69.94.222 the reverse lookup results in a "SERVFAIL" and the UTM rejects the mails temporarily. Looks like the desired behaviour for me.

    Then, one option would be to disable RDNS checking, maybe on a exception basis just for these ips. Or wait until volumedrive.com gets its dns servers up and running the reverse zone...
  • 0 in reply to bulirich_01
    Hi, I do have RDNS/ Strict RDNS checking enabled. However the mail should get a permanent deny after some retries and not a temporary defer like in my case. On a heavy loaded smtp server, this can become a huge problem... 

    /var/log/smtp/2013/02/smtp-2013-02-18.log.gz:2013:02:18-22:21:52 gatekeeper exim-in[15360]: 2013-02-18 22:21:52 H=(mta36.agedpr.com) [192.69.94.231]:34375 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=192.69.94.231" gave DEFER:

    /var/log/smtp/2013/02/smtp-2013-02-18.log.gz:2013:02:18-22:22:56 gatekeeper exim-in[15376]: 2013-02-18 22:22:56 H=(mta36.agedpr.com) [192.69.94.231]:34458 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=192.69.94.231" gave DEFER:

    /var/log/smtp/2013/02/smtp-2013-02-18.log.gz:2013:02:18-22:24:13 gatekeeper exim-in[15393]: 2013-02-18 22:24:13 H=(mta36.agedpr.com) [192.69.94.231]:47885 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=192.69.94.231" gave DEFER:

    /var/log/smtp/2013/02/smtp-2013-02-18.log.gz:2013:02:18-22:25:17 gatekeeper exim-in[15442]: 2013-02-18 22:25:17 H=(mta36.agedpr.com) [192.69.94.231]:51251 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=192.69.94.231" gave DEFER:

    /var/log/smtp/2013/02/smtp-2013-02-18.log.gz:2013:02:18-22:26:39 gatekeeper exim-in[15607]: 2013-02-18 22:26:39 H=(mta36.agedpr.com) [192.69.94.231]:41406 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=192.69.94.231" gave DEFER:

    /var/log/smtp/2013/02/smtp-2013-02-18.log.gz:2013:02:18-22:27:49 gatekeeper exim-in[15623]: 2013-02-18 22:27:49 H=(mta36.agedpr.com) [192.69.94.231]:43204 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=192.69.94.231" gave DEFER:

    /var/log/smtp/2013/02/smtp-2013-02-18.log.gz:2013:02:18-22:29:11 gatekeeper exim-in[15637]: 2013-02-18 22:29:11 H=(mta36.agedpr.com) [192.69.94.231]:35567 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=192.69.94.231" gave DEFER:

    /var/log/smtp/2013/02/smtp-2013-02-18.log.gz:2013:02:18-22:30:21 gatekeeper exim-in[15804]: 2013-02-18 22:30:21 H=(mta36.agedpr.com) [192.69.94.231]:54103 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=192.69.94.231" gave DEFER:

    /var/log/smtp/2013/02/smtp-2013-02-18.log.gz:2013:02:18-22:31:33 gatekeeper exim-in[16187]: 2013-02-18 22:31:33 H=(mta36.agedpr.com) [192.69.94.231]:34956 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=192.69.94.231" gave DEFER:

    /var/log/smtp/2013/02/smtp-2013-02-18.log.gz:2013:02:18-22:32:50 gatekeeper exim-in[16242]: 2013-02-18 22:32:50 H=(mta36.agedpr.com) [192.69.94.231]:48851 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=192.69.94.231" gave DEFER:

    /var/log/smtp/2013/02/smtp-2013-02-18.log.gz:2013:02:18-22:33:54 gatekeeper exim-in[16258]: 2013-02-18 22:33:54 H=(mta36.agedpr.com) [192.69.94.231]:38429 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=192.69.94.231" gave DEFER:

    /var/log/smtp/2013/02/smtp-2013-02-18.log.gz:2013:02:18-22:35:04 gatekeeper exim-in[16276]: 2013-02-18 22:35:04 H=(mta36.agedpr.com) [192.69.94.231]:35687 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=192.69.94.231" gave DEFER:

    /var/log/smtp/2013/02/smtp-2013-02-18.log.gz:2013:02:18-22:36:13 gatekeeper exim-in[16323]: 2013-02-18 22:36:13 H=(mta36.agedpr.com) [192.69.94.231]:39333 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=192.69.94.231" gave DEFER:

    /var/log/smtp/2013/02/smtp-2013-02-18.log.gz:2013:02:18-22:37:17 gatekeeper exim-in[16339]: 2013-02-18 22:37:17 H=(mta36.agedpr.com) [192.69.94.231]:40656 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=192.69.94.231" gave DEFER:

    /var/log/smtp/2013/02/smtp-2013-02-18.log.gz:2013:02:18-22:38:22 gatekeeper exim-in[16349]: 2013-02-18 22:38:22 H=(mta36.agedpr.com) [192.69.94.231]:45241 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=192.69.94.231" gave DEFER:

    /var/log/smtp/2013/02/smtp-2013-02-18.log.gz:2013:02:18-22:39:29 gatekeeper exim-in[16367]: 2013-02-18 22:39:29 H=(mta36.agedpr.com) [192.69.94.231]:49944 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=192.69.94.231" gave DEFER:

    /var/log/smtp/2013/02/smtp-2013-02-18.log.gz:2013:02:18-22:40:41 gatekeeper exim-in[16567]: 2013-02-18 22:40:41 H=(mta36.agedpr.com) [192.69.94.231]:34738 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=192.69.94.231" gave DEFER:

    /var/log/smtp/2013/02/smtp-2013-02-18.log.gz:2013:02:18-22:41:45 gatekeeper exim-in[16582]: 2013-02-18 22:41:45 H=(mta36.agedpr.com) [192.69.94.231]:54034 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=192.69.94.231" gave DEFER:

    /var/log/smtp/2013/02/smtp-2013-02-18.log.gz:2013:02:18-22:42:55 gatekeeper exim-in[16597]: 2013-02-18 22:42:55 H=(mta36.agedpr.com) [192.69.94.231]:49892 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=192.69.94.231" gave DEFER:

    /var/log/smtp/2013/02/smtp-2013-02-18.log.gz:2013:02:18-22:44:11 gatekeeper exim-in[16610]: 2013-02-18 22:44:11 H=(mta36.agedpr.com) [192.69.94.231]:43812 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=192.69.94.231" gave DEFER:

    /var/log/smtp/2013/02/smtp-2013-02-18.log.gz:2013:02:18-22:45:23 gatekeeper exim-in[16807]: 2013-02-18 22:45:23 H=(mta36.agedpr.com) [192.69.94.231]:57350 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=192.69.94.231" gave DEFER:

    /var/log/smtp/2013/02/smtp-2013-02-18.log.gz:2013:02:18-22:46:27 gatekeeper exim-in[17154]: 2013-02-18 22:46:27 H=(mta36.agedpr.com) [192.69.94.231]:39320 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=192.69.94.231" gave DEFER:

    /var/log/smtp/2013/02/smtp-2013-02-18.log.gz:2013:02:18-22:47:31 gatekeeper exim-in[17213]: 2013-02-18 22:47:31 H=(mta36.agedpr.com) [192.69.94.231]:55202 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=192.69.94.231" gave DEFER:

    /var/log/smtp/2013/02/smtp-2013-02-18.log.gz:2013:02:18-22:48:56 gatekeeper exim-in[17231]: 2013-02-18 22:48:56 H=(mta36.agedpr.com) [192.69.94.231]:32983 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=192.69.94.231" gave DEFER:

    /var/log/smtp/2013/02/smtp-2013-02-18.log.gz:2013:02:18-22:50:12 gatekeeper exim-in[17281]: 2013-02-18 22:50:12 H=(mta36.agedpr.com) [192.69.94.231]:45740 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=192.69.94.231" gave DEFER:

    /var/log/smtp/2013/02/smtp-2013-02-18.log.gz:2013:02:18-22:51:20 gatekeeper exim-in[17297]: 2013-02-18 22:51:20 H=(mta36.agedpr.com) [192.69.94.231]:55957 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=192.69.94.231" gave DEFER:

    /var/log/smtp/2013/02/smtp-2013-02-18.log.gz:2013:02:18-22:54:06 gatekeeper exim-in[17332]: 2013-02-18 22:54:06 H=(mta36.agedpr.com) [192.69.94.231]:60802 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=192.69.94.231" gave DEFER:

    /var/log/smtp/2013/02/smtp-2013-02-18.log.gz:2013:02:18-22:58:22 gatekeeper exim-in[17562]: 2013-02-18 22:58:22 H=(mta36.agedpr.com) [192.69.94.231]:60625 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=192.69.94.231" gave DEFER:

    Regards
    Bill
  • 0
    Hi, i got your point. What i don't see is that "this can become a huge problem...". What else can happen besides the log getting filled?

    As i understand it, a servfail indicates a temporary failure at the dns server, a situation which the provider wants to resolve as soon as possible. Said that i don't see a bug here, nor why the behaviour of the UTM should be changed in this case.

    Regards,
    bulirich
  • 0 in reply to bulirich_01
    Hi, I think the mail mentioned in my logs is probably spam. From what I remember in older versions, RDNS failure in all situations (PTR problem or non matching PTR etc) would immediately give a deny. If this was a legitimate email, there is no way for the admin to know the situation unless he looks at the logs. I am assuming here but I don't believe that the sender is getting any notifications of email not getting through.

    If my hunch is correct, then that is extra logging, communication, mail queue, and DNS queries that a UTM can do without.

    I think the RDNS feature should go back to the way it was and get a deny immediately. That is all my point is in all this. I don't see any reason to play around for the authoritative DNS to come back online. That is the sender's problem not the receiver's.

    Regards
    Bill
  • 0
    Hi,
    i managed to check this with v9.003 and v8.306 and found the same behaviour: the UTM rejects the mails temporarily.
    If these emails were legitimate, i'm sure the provider would fix his DNS. Though I could not build a suitable setup yet I'm pretty sure that a properly configured mailserver would give up after a while and send a notification to the sender.
    You're right, it's extra logging, communication and DNS queries for the UTM, but no mailqueue (mails are rejected before even queued). Even a heavy loaded system should handle this without problems.

    For now there won't be any changes concerning this issue.
    Thanks anyway for your input!

    Regards,
    bulirich
  • 0 in reply to bulirich_01
    Though I could not build a suitable setup yet I'm pretty sure that a properly configured mailserver would give up after a while and send a notification to the sender.

    gatekeeper:/var/log # grep -c "failed to expand" smtp.log
    140

    /var/log/smtp/2013/02/smtp-2013-02-21.log.gz:2013:02:21-19:21:40 gatekeeper exim-in[15948]: 2013-02-21 19:21:40 H=(mta16.agedpr.com) [192.69.94.211]:33787 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=192.69.94.211" gave DEFER:
    /var/log/smtp/2013/02/smtp-2013-02-21.log.gz:2013:02:21-19:22:45 gatekeeper exim-in[15963]: 2013-02-21 19:22:45 H=(mta16.agedpr.com) [192.69.94.211]:37330 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=192.69.94.211" gave DEFER:

    SNIP............

    /var/log/smtp.log:2013:02:28-08:50:15 gatekeeper exim-in[21735]: 2013-02-28 08:50:15 H=(mta16.agedpr.com) [192.69.94.211]:33475 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=192.69.94.211" gave DEFER:
    /var/log/smtp.log:2013:02:28-08:52:55 gatekeeper exim-in[21770]: 2013-02-28 08:52:55 H=(mta16.agedpr.com) [192.69.94.211]:36294 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=192.69.94.211" gave DEFER:
    /var/log/smtp.log:2013:02:28-08:54:07 gatekeeper exim-in[21790]: 2013-02-28 08:54:07 H=(mta16.agedpr.com) [192.69.94.211]:54721 F= temporarily rejected RCPT : failed to expand ACL string "${lookup dnsdb{ptr=$sender_host_address}{0}{1}}": lookup of "ptr=192.69.94.211" gave DEFER:
    The same mails are in my original post from the 14th but I don't have any logging since I rebuilt my box. I have been temporarily rejecting the same mail since the 21st of Feb on my rebuilt system and still waiting for someone to fix the PTR on the authoritative DNS to this day[8-)] and this is on my home system with
    SMTP Proxy is active, 39 emails processed, 33 emails blocked

    You're right, it's extra logging, communication and DNS queries for the UTM, but no mailqueue (mails are rejected before even queued). Even a heavy loaded system should handle this without problems.
    You think so.... obviously you haven't followed threads like http://www.astaro.org/gateway-products/hardware-installation-up2date-licensing/45221-9-0044-33-spikes-high-cpu-memory.html which surely don't need additional load from bogus emails.
    And by the way if the behavior was the same in earilier versions, that doesn't make it right. In any case, I am just beta testing and stating my opinion and if you think this doesn't need fixing, then the final decision is yours. 

    Regards
    Bill