Re: [exim] Exim not obeying "delay = " in acl_smtp_connect
On 27/12/17 16:49, Jeremy Harris wrote: On 27/12/17 15:21, Sebastian Arcus via Exim-users wrote: Yes, a way to turn a defer into a hard fail is what I would need in this case. Am I correct in thinking that when the defer happens and the ACL processing is aborted, the DELAY gets skipped? 1) Please trim your included text Will do . 2) Yes. If that is the case, is there any way to still process the DELAY? Do the lookup manually, with a ${lookup dnsdb ...} expansion; you then have more control. Treat the ACL flow as a programming > language. That's a good pointer - I will investigate that avenue - thank you. -- ## List details at https://lists.exim.org/mailman/listinfo/exim-users ## Exim details at http://www.exim.org/ ## Please use the Wiki with this list - http://wiki.exim.org/
Re: [exim] Possibly unclear logging after connection is closed by the far end during DELAY
On 27/12/17 17:00, Jeremy Harris wrote: On 27/12/17 16:24, Sebastian Arcus via Exim-users wrote: I've spotted this while investigating issues with DELAY in in acl's, in my other recent thread. It would seem that if a DROP acl has a long DELAY set, and if during that DELAY the remote end just gets fed up and closes the connection, Exim somehow still treats this as the ACL processing has succeed and writes appropriate messages to the log and claims the ACL worked. This can be somewhat confusing. You're effectively asking the delay= to be handled as an ACL condition, the result being whether it reaches the end of its defined time without being preempted by external forces. Currently is is not a condition, it is an ACL _modifier_. I don't think we care enough to change it, really. Actually spotting that the SMTP connection went away was a bonus added long after the genesis of the delay= modifier... and the result is the same; you had decided to drop the connection, the connection is dropped. The success of the ACL verb is not really relevant. The handling process goes away a bit quicker now, which I assume is preferred. Ok - bear with me if you will. According to the documentation, DELAY = "causes Exim to wait for the time interval before proceeding". Now, unless, I misunderstand things (which is perfectly possible), this means the following: 1. Exim evaluates the conditions 2. Exim waits for 3. Exim acts on the action of the acl, which in this case is DROP. But if while waiting for , the connection went away because the far end dropped it, how could Exim possibly do a DROP on a non-existent connection? I think that's where the confusion arises. I would have thought the logical thing to do would be to check the connection is still there before proceeding, and if it isn't, to abort the whole thing and output to the log relevant information (and not output the message = or log_message = any more). In other words, the connection going away should be treated as some sort of disrupting event - instead of Exim carrying on with the action of the acl like nothing happened. Maybe looking at things from the programming end things makes sense the way they are now, but from the perspective of someone trying to configure and work with Exim, it is illogical and unexpected behaviour. And a little explanation, which might throw a bit of light on how I got here. I've inserted this particular acl to wait for a long time on connections which are blatantly spam bots, in order to make them go away. However, I find it very hard to work out when the bots go away by themselves, and when they are dropped by Exim - as Exim always claims "connection dropped by ACL" - which is plainly not true when the remote end actually disconnected first. Again, I'm not an Exim expert, so I welcome the enlightened comments of others who are :-) -- ## List details at https://lists.exim.org/mailman/listinfo/exim-users ## Exim details at http://www.exim.org/ ## Please use the Wiki with this list - http://wiki.exim.org/
Re: [exim] Possibly unclear logging after connection is closed by the far end during DELAY
On 27/12/17 16:24, Sebastian Arcus via Exim-users wrote: > I've spotted this while investigating issues with DELAY in in acl's, in > my other recent thread. It would seem that if a DROP acl has a long > DELAY set, and if during that DELAY the remote end just gets fed up and > closes the connection, Exim somehow still treats this as the ACL > processing has succeed and writes appropriate messages to the log and > claims the ACL worked. This can be somewhat confusing. You're effectively asking the delay= to be handled as an ACL condition, the result being whether it reaches the end of its defined time without being preempted by external forces. Currently is is not a condition, it is an ACL _modifier_. I don't think we care enough to change it, really. Actually spotting that the SMTP connection went away was a bonus added long after the genesis of the delay= modifier... and the result is the same; you had decided to drop the connection, the connection is dropped. The success of the ACL verb is not really relevant. The handling process goes away a bit quicker now, which I assume is preferred. -- Cheers, Jeremy -- ## List details at https://lists.exim.org/mailman/listinfo/exim-users ## Exim details at http://www.exim.org/ ## Please use the Wiki with this list - http://wiki.exim.org/
Re: [exim] Exim not obeying "delay = " in acl_smtp_connect
On 27/12/17 15:21, Sebastian Arcus via Exim-users wrote: > Yes, a way to turn a defer into a hard fail is what I would need in this > case. Am I correct in thinking that when the defer happens and the ACL > processing is aborted, the DELAY gets skipped? 1) Please trim your included text 2) Yes. > If that is the case, is > there any way to still process the DELAY? Do the lookup manually, with a ${lookup dnsdb ...} expansion; you then have more control. Treat the ACL flow as a programming language. -- Cheers, Jeremy -- ## List details at https://lists.exim.org/mailman/listinfo/exim-users ## Exim details at http://www.exim.org/ ## Please use the Wiki with this list - http://wiki.exim.org/
Re: [exim] Exim not obeying "delay = " in acl_smtp_connect
On 27/12/17 16:13, Sebastian Arcus via Exim-users wrote: > Ok - no sooner did I send my last email to the list, that a series of > spurious connections attempts started on another email server I > administer. I have below the log extract with exim -bd > -d-all+resolver+dns+verify > > > 18213 drop: condition test failed in ACL "acl_check_connect" > 18213 processing "drop" > 18213 message: Reverse DNS record incorrect or missing > 18213 check !condition = ${if eq{$received_port}{587}} > 18213 = > 18213 check !verify = reverse_host_lookup > 18213 looking up host name to force name/address consistency check > 18213 looking up host name for 182.48.94.184 > 18213 DNS lookup of 184.94.48.182.in-addr.arpa-PTR: using cached value > DNS_AGAIN Exim has cached a value from a previous lookup; which must have been in this process or a parent of it. That lookup apparently got "DNS_AGAIN" from the resolver, which is its version of "temporary error". -- Cheers, Jeremy -- ## List details at https://lists.exim.org/mailman/listinfo/exim-users ## Exim details at http://www.exim.org/ ## Please use the Wiki with this list - http://wiki.exim.org/
[exim] Possibly unclear logging after connection is closed by the far end during DELAY
I've spotted this while investigating issues with DELAY in in acl's, in my other recent thread. It would seem that if a DROP acl has a long DELAY set, and if during that DELAY the remote end just gets fed up and closes the connection, Exim somehow still treats this as the ACL processing has succeed and writes appropriate messages to the log and claims the ACL worked. This can be somewhat confusing. Here is the debug output with -d-all+dns+resolver+verify+acl: 18692 processing "drop" 18692 message: Reverse DNS record incorrect or missing 18692 l_message: "Reject: no PTR record for sender IP ($sender_host_address)" 18692 check !verify = reverse_host_lookup 18692 check delay = 20m 18692 delay modifier requests 1200-second delay 18692 delay cancelled by peer close 18692 drop: condition test succeeded in ACL "acl_check_connect" 18692 end of ACL "acl_check_connect": DROP 18692 LOG: connection_reject MAIN REJECT 18692 H=[14.163.3.5]:59673 I=[192.168.60.2]:25 rejected connection in "connect" ACL: "Reject: no PTR record for sender IP (14.163.3.5)": host lookup failed (14.163.3.5 does not match any IP address for static.vnpt.vn) 18692 LOG: smtp_connection MAIN 18692 SMTP connection from [14.163.3.5]:59673 I=[192.168.60.2]:25 closed by DROP in ACL 18652 child 18692 ended: status=0x0 18652 normal exit, 0 The output above seems to imply that the processing got aborted as the peer closed the connection. Isn't it confusing to keep on processing the ACL after that, and still write the message and log_message to the log anyway, and even claim connection "closed by DROP in ACL" - when it was actually closed by the far end? Or am I misreading the log output? And here is the ACL used: drop message = Reverse DNS record incorrect or missing log_message = "Reject: no PTR record for sender IP \ ($sender_host_address)" ! verify= reverse_host_lookup delay = 20m -- ## List details at https://lists.exim.org/mailman/listinfo/exim-users ## Exim details at http://www.exim.org/ ## Please use the Wiki with this list - http://wiki.exim.org/
Re: [exim] Exim not obeying "delay = " in acl_smtp_connect
On 27/12/17 12:58, Jeremy Harris wrote: On 27/12/17 12:39, Sebastian Arcus via Exim-users wrote: processing "drop" 5976 message: Reverse DNS record incorrect or missing 5976 check !condition = ${if eq{$received_port}{587}} 5976 = 5976 check !verify = reverse_host_lookup 5976 looking up host name to force name/address consistency check 5976 drop: condition test deferred in ACL "acl_check_connect" 5976 LOG: connection_reject MAIN REJECT 5976 H=[196.207.181.208]:57629 I=[192.168.15.2]:25 temporarily rejected connection in "connect" ACL: host lookup deferred for reverse lookup check 5888 child 5976 ended: status=0x0 5888 normal exit, 0 I'm not quite following the above - does it mean that the reverse dns lookup fails somewhere, That's how I read it. Add more debug classes to that cmdline option for more info - I expect there's a dns-specfic one. Docs are at http://exim.org/exim-html-current/doc/html/spec_html/ch-the_exim_command_line.html#SECID39 You could also look into options on the verify= ACL condition, if it does turn out to be a DNS issue. See the ACL chapter. Ok - no sooner did I send my last email to the list, that a series of spurious connections attempts started on another email server I administer. I have below the log extract with exim -bd -d-all+resolver+dns+verify 18213 drop: condition test failed in ACL "acl_check_connect" 18213 processing "drop" 18213 message: Reverse DNS record incorrect or missing 18213 check !condition = ${if eq{$received_port}{587}} 18213 = 18213 check !verify = reverse_host_lookup 18213 looking up host name to force name/address consistency check 18213 looking up host name for 182.48.94.184 18213 DNS lookup of 184.94.48.182.in-addr.arpa-PTR: using cached value DNS_AGAIN 18213 IP address PTR lookup gave temporary error 18213 drop: condition test deferred in ACL "acl_check_connect" 18213 SMTP>> 451 Temporary local problem - please try later 18213 LOG: connection_reject MAIN REJECT 18213 H=[182.48.94.184]:52523 I=[192.168.60.2]:25 temporarily rejected connection in "connect" ACL: host lookup deferred for reverse lookup check 18213 search_tidyup called 18141 child 18213 ended: status=0x0 18141 normal exit, 0 I didn't think a PTR lookup should get a defer? If I look it up on the command line: # host 182.48.94.184 Host 184.94.48.182.in-addr.arpa not found: 2(SERVFAIL) I tried the PTR lookup from another machine, on a completely different network and DNS server, and I get the same SERVFAIL - so I can only suppose it is not my DNS setup or server. I've just spotted another issue, but I'll post a separate message to the list, to try and keep things tidy -- ## List details at https://lists.exim.org/mailman/listinfo/exim-users ## Exim details at http://www.exim.org/ ## Please use the Wiki with this list - http://wiki.exim.org/
Re: [exim] Exim not obeying "delay = " in acl_smtp_connect
On 27/12/17 12:58, Jeremy Harris wrote: On 27/12/17 12:39, Sebastian Arcus via Exim-users wrote: processing "drop" 5976 message: Reverse DNS record incorrect or missing 5976 check !condition = ${if eq{$received_port}{587}} 5976 = 5976 check !verify = reverse_host_lookup 5976 looking up host name to force name/address consistency check 5976 drop: condition test deferred in ACL "acl_check_connect" 5976 LOG: connection_reject MAIN REJECT 5976 H=[196.207.181.208]:57629 I=[192.168.15.2]:25 temporarily rejected connection in "connect" ACL: host lookup deferred for reverse lookup check 5888 child 5976 ended: status=0x0 5888 normal exit, 0 I'm not quite following the above - does it mean that the reverse dns lookup fails somewhere, That's how I read it. Add more debug classes to that cmdline option for more info - I expect there's a dns-specfic one. There is -d-dns and -d-resolver. I now have to wait until I get hit again by a wave of connections from that particular trojan or whatever it is - to debug things - as it seems to come for a few hours every few days, then go away. -- ## List details at https://lists.exim.org/mailman/listinfo/exim-users ## Exim details at http://www.exim.org/ ## Please use the Wiki with this list - http://wiki.exim.org/
Re: [exim] Exim not obeying "delay = " in acl_smtp_connect
On 27/12/17 13:57, Heiko Schlittermann via Exim-users wrote: Sebastian Arcus via Exim-users (Mi 27 Dez 2017 13:39:26 CET): …. Thank you for the suggestion. I think the following are the relevant lines of output: processing "drop" 5976 message: Reverse DNS record incorrect or missing 5976 check !condition = ${if eq{$received_port}{587}} 5976 = 5976 check !verify = reverse_host_lookup 5976 looking up host name to force name/address consistency check 5976 drop: condition test deferred in ACL "acl_check_connect" 5976 LOG: connection_reject MAIN REJECT 5976 H=[196.207.181.208]:57629 I=[192.168.15.2]:25 temporarily rejected connection in "connect" ACL: host lookup deferred for reverse lookup check 5888 child 5976 ended: status=0x0 5888 normal exit, 0 I'm not quite following the above - does it mean that the reverse dns lookup fails somewhere, or is it deferred for some reason by the remote end? No mention of the DELAY anywhere, though The PTR *or* the A lookup seem to be deferred for some reason (I'm not sure, if I could tell, which of these two queries fails). A deferral is no final decision. So the ACL condition doesn't know if it should return failure or success. It helps itself by returning the deferral (4xx), which in turn aborts the ACL processing and returns 4xx to the client drop message = … ! verify = reverse_host_lookup/defer_ok delay = 600s … would change it, but probably it is not your intention. I think, we do not have a /defer_fail option, do we? And I'm not sure if this wouldn't induce another source of trouble… Yes, a way to turn a defer into a hard fail is what I would need in this case. Am I correct in thinking that when the defer happens and the ACL processing is aborted, the DELAY gets skipped? If that is the case, is there any way to still process the DELAY? -- ## List details at https://lists.exim.org/mailman/listinfo/exim-users ## Exim details at http://www.exim.org/ ## Please use the Wiki with this list - http://wiki.exim.org/
Re: [exim] Some mails are queued, other are sent immediately
> From: Jeremy Harris > Could you do that with debug enabled? Using csh, I redirected debug output (-bd -q10m -d+all) to a file with >& (both stdout and stderr to the same file, some log lines might be broken and interspersed because of buffering). The file (compressed with bzip2) can be downloaded from drive.google.com/file/d/1wWbpVZ_4ob4KvMu57Y-oBS3A3xgyfbSi/view That debug log is about several messages, only the last one was queued, then a bounce/DSN. I deleted all files from /var/spool/exim/db just before sending the queued message. I see: 15:08:34 6101 already connected to mta7.am0.yahoodns.net [98.137.159.27] (on fd 0) 15:08:34 6101 all IP addresses skipped or deferred at least one address But I don't understand why. Recipient callout verification was successful (OK reply to RCPT), connection was held (use_sender,hold), why the message was queued? During subsequent queue run, the message was rejected after end of data (recipient email address inactive). -- ## List details at https://lists.exim.org/mailman/listinfo/exim-users ## Exim details at http://www.exim.org/ ## Please use the Wiki with this list - http://wiki.exim.org/
Re: [exim] Exim not obeying "delay = " in acl_smtp_connect
Sebastian Arcus via Exim-users (Mi 27 Dez 2017 13:39:26 CET): …. > Thank you for the suggestion. I think the following are the relevant lines > of output: > > > > processing "drop" > 5976 message: Reverse DNS record incorrect or missing > 5976 check !condition = ${if eq{$received_port}{587}} > 5976 = > 5976 check !verify = reverse_host_lookup > 5976 looking up host name to force name/address consistency check > 5976 drop: condition test deferred in ACL "acl_check_connect" > 5976 LOG: connection_reject MAIN REJECT > 5976 H=[196.207.181.208]:57629 I=[192.168.15.2]:25 temporarily rejected > connection in "connect" ACL: host lookup deferred for reverse lookup check > 5888 child 5976 ended: status=0x0 > 5888 normal exit, 0 > > > > I'm not quite following the above - does it mean that the reverse dns lookup > fails somewhere, or is it deferred for some reason by the remote end? No > mention of the DELAY anywhere, though The PTR *or* the A lookup seem to be deferred for some reason (I'm not sure, if I could tell, which of these two queries fails). A deferral is no final decision. So the ACL condition doesn't know if it should return failure or success. It helps itself by returning the deferral (4xx), which in turn aborts the ACL processing and returns 4xx to the client drop message = … ! verify = reverse_host_lookup/defer_ok delay = 600s … would change it, but probably it is not your intention. I think, we do not have a /defer_fail option, do we? And I'm not sure if this wouldn't induce another source of trouble… Just my guesswork. Best regards from Dresden/Germany Viele Grüße aus Dresden Heiko Schlittermann -- SCHLITTERMANN.de internet & unix support - Heiko Schlittermann, Dipl.-Ing. (TU) - {fon,fax}: +49.351.802998{1,3} - gnupg encrypted messages are welcome --- key ID: F69376CE - ! key id 7CBF764A and 972EAC9F are revoked since 2015-01 - signature.asc Description: PGP signature -- ## List details at https://lists.exim.org/mailman/listinfo/exim-users ## Exim details at http://www.exim.org/ ## Please use the Wiki with this list - http://wiki.exim.org/
Re: [exim] Exim not obeying "delay = " in acl_smtp_connect
On 27/12/17 12:39, Sebastian Arcus via Exim-users wrote: > processing "drop" > 5976 message: Reverse DNS record incorrect or missing > 5976 check !condition = ${if eq{$received_port}{587}} > 5976 = > 5976 check !verify = reverse_host_lookup > 5976 looking up host name to force name/address consistency check > 5976 drop: condition test deferred in ACL "acl_check_connect" > 5976 LOG: connection_reject MAIN REJECT > 5976 H=[196.207.181.208]:57629 I=[192.168.15.2]:25 temporarily > rejected connection in "connect" ACL: host lookup deferred for reverse > lookup check > 5888 child 5976 ended: status=0x0 > 5888 normal exit, 0 > > > > > I'm not quite following the above - does it mean that the reverse dns > lookup fails somewhere, That's how I read it. Add more debug classes to that cmdline option for more info - I expect there's a dns-specfic one. Docs are at http://exim.org/exim-html-current/doc/html/spec_html/ch-the_exim_command_line.html#SECID39 You could also look into options on the verify= ACL condition, if it does turn out to be a DNS issue. See the ACL chapter. -- Cheers, Jeremy -- ## List details at https://lists.exim.org/mailman/listinfo/exim-users ## Exim details at http://www.exim.org/ ## Please use the Wiki with this list - http://wiki.exim.org/
Re: [exim] Exim not obeying "delay = " in acl_smtp_connect
On 27/12/17 11:01, Jeremy Harris wrote: On 27/12/17 10:19, Sebastian Arcus via Exim-users wrote: Apologies for posting for the third time in three days. I have the following acl in acl_smtp_connect, which appears to be ignoring completely the "delay =" setting: drop message = Reverse DNS record incorrect or missing ! condition = ${if eq{$received_port}{587}} ! verify = reverse_host_lookup delay = 600s The acl is working, I can see the messages in the logs, but the connections get dropped almost instantly - maybe 1-2 seconds max. I've tried DENY instead of DROP, I tried 3m instead of 600s. I've even tried moving it to acl_smtp_helo, and it does the same thing. I've googled, but all the results refer to the standard use of DELAY =, nobody seems to complain that theirs is not working. I am on Exim 4.89 Edit: in fact, I just realised that none of the acl's in acl_smtp_helo obey the delay either. Run your daemon with the debug option "-d-all+acl". It'll run in foreground, and output debug info on the ACL flow to stderr. Check that it is indeed that ACL verb that is executing (and failing to delay) and not some other one. Thank you for the suggestion. I think the following are the relevant lines of output: processing "drop" 5976 message: Reverse DNS record incorrect or missing 5976 check !condition = ${if eq{$received_port}{587}} 5976 = 5976 check !verify = reverse_host_lookup 5976 looking up host name to force name/address consistency check 5976 drop: condition test deferred in ACL "acl_check_connect" 5976 LOG: connection_reject MAIN REJECT 5976 H=[196.207.181.208]:57629 I=[192.168.15.2]:25 temporarily rejected connection in "connect" ACL: host lookup deferred for reverse lookup check 5888 child 5976 ended: status=0x0 5888 normal exit, 0 I'm not quite following the above - does it mean that the reverse dns lookup fails somewhere, or is it deferred for some reason by the remote end? No mention of the DELAY anywhere, though -- ## List details at https://lists.exim.org/mailman/listinfo/exim-users ## Exim details at http://www.exim.org/ ## Please use the Wiki with this list - http://wiki.exim.org/
Re: [exim] Exim not obeying "delay = " in acl_smtp_connect
Sebastian Arcus via Exim-users (Mi 27 Dez 2017 11:19:11 CET): > Apologies for posting for the third time in three days. I have the following > acl in acl_smtp_connect, which appears to be ignoring completely the "delay > =" setting: You're welcome :) > drop message = Reverse DNS record incorrect or missing >! condition = ${if eq{$received_port}{587}} >! verify= reverse_host_lookup >delay = 600s I tested this in a simplified setup: acl_smtp_connect = acl_check_connect begin acl: acl_check_connect: drop message = Reverse DNS record incorrect or missing delay = 600s And then start working towards your setup. For me the above ACL worked as expected, with 4.89 and 4.90. Please not, in case you use 'swaks' with --pipe 'exim -bh …', the delays won't be executed, but shown in the log. -- Heiko signature.asc Description: PGP signature -- ## List details at https://lists.exim.org/mailman/listinfo/exim-users ## Exim details at http://www.exim.org/ ## Please use the Wiki with this list - http://wiki.exim.org/
Re: [exim] Exim not obeying "delay = " in acl_smtp_connect
On 27/12/17 10:19, Sebastian Arcus via Exim-users wrote: > Apologies for posting for the third time in three days. I have the > following acl in acl_smtp_connect, which appears to be ignoring > completely the "delay =" setting: > > drop message = Reverse DNS record incorrect or missing > ! condition = ${if eq{$received_port}{587}} > ! verify = reverse_host_lookup > delay = 600s > > The acl is working, I can see the messages in the logs, but the > connections get dropped almost instantly - maybe 1-2 seconds max. I've > tried DENY instead of DROP, I tried 3m instead of 600s. I've even tried > moving it to acl_smtp_helo, and it does the same thing. I've googled, > but all the results refer to the standard use of DELAY =, nobody seems > to complain that theirs is not working. I am on Exim 4.89 > > Edit: in fact, I just realised that none of the acl's in acl_smtp_helo > obey the delay either. > Run your daemon with the debug option "-d-all+acl". It'll run in foreground, and output debug info on the ACL flow to stderr. Check that it is indeed that ACL verb that is executing (and failing to delay) and not some other one. -- Cheers, Jeremy -- ## List details at https://lists.exim.org/mailman/listinfo/exim-users ## Exim details at http://www.exim.org/ ## Please use the Wiki with this list - http://wiki.exim.org/
[exim] Exim not obeying "delay = " in acl_smtp_connect
Apologies for posting for the third time in three days. I have the following acl in acl_smtp_connect, which appears to be ignoring completely the "delay =" setting: drop message = Reverse DNS record incorrect or missing ! condition = ${if eq{$received_port}{587}} ! verify= reverse_host_lookup delay = 600s The acl is working, I can see the messages in the logs, but the connections get dropped almost instantly - maybe 1-2 seconds max. I've tried DENY instead of DROP, I tried 3m instead of 600s. I've even tried moving it to acl_smtp_helo, and it does the same thing. I've googled, but all the results refer to the standard use of DELAY =, nobody seems to complain that theirs is not working. I am on Exim 4.89 Edit: in fact, I just realised that none of the acl's in acl_smtp_helo obey the delay either. -- ## List details at https://lists.exim.org/mailman/listinfo/exim-users ## Exim details at http://www.exim.org/ ## Please use the Wiki with this list - http://wiki.exim.org/