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
