Hi Volker,
Dr. Volker Jaenisch via Exim-users <exim-users@???> (Fr 07 Jul 2017 08:54:02 CEST):
> There were two problems. First the defer_ok Flag should be used twice as
> Lena mentioned.
>
> verify = recipient/defer_ok/callout=10s,defer_ok,use_sender
>
> Second the callout timeout was 2m and therefore to long for the
> SMTP-Clients which run into SMTP/TCP-timeout
> before completing the Callout.
SMTP client? If you're talking about a MUA, you are right. They often
cancel the connection quite soon. If your client is another MTA, it
should have a bit more patiency.
> Additionally the target system has (maybe intentional) one dysfunctional
> (time at each connect) mailserver prioritized above the others. Maybe
> this is to scare away SPAMMERS. Nevertheless it contributes to the
> problem negatively.
I think it is called MX sandwiching, and some people like it. I'm not
sure if it interoperates well with all mail systems. I got reports about
problems receiving messages from G*. Maybe the admins at HTW put there
some whitelists.
But… I still believe, the defer_ok having twice isn't part of the
solution (one defer_ok is for the callout, the 2nd is for "normal"
recipient verification.)
I've used a small test scenario:
| keep_environment =
| tls_advertise_hosts =
| spool_directory = /tmp/exim
|
| acl_smtp_rcpt = acl_check_rcpt
|
| begin acl
|
|
| acl_check_rcpt:
|
| require message = REJECTED: $acl_verify_message
| verify = recipient/callout=10s,use_sender,defer_ok
| logwrite = verification succeeded for $sender_address $local_part@$domain
|
| accept
|
| begin routers
|
| dns:
| driver = dnslookup
| transport = smtp
|
|
| begin transports
|
| smtp:
| driver = smtp
And for testing I used:
swaks -f '<hs@???>' -t '<***@htw-dresden.de>' \
--pipe 'exim -C /tmp/exim.test -bhc 8.8.4.4'
In line 204 of the following log you can see, that the message gets
accepted, even all our callout attempts got a 4xx or even a connection
timeout (line 51)
Here the log:
1 === Trying pipe to /usr/local/exim/bin/exim -C /tmp/exim.test -bhc 8.8.8.8...
2 === Connected to /usr/local/exim/bin/exim -C /tmp/exim.test -bhc 8.8.8.8.
3 >>> host in hosts_connection_nolog? no (option unset)
4 >>> host in host_lookup? no (option unset)
5 >>> host in host_reject_connection? no (option unset)
6 >>> host in sender_unqualified_hosts? no (option unset)
7 >>> host in recipient_unqualified_hosts? no (option unset)
8 >>> host in helo_verify_hosts? no (option unset)
9 >>> host in helo_try_verify_hosts? no (option unset)
10 >>> host in helo_accept_junk_hosts? no (option unset)
11 <-
12 <- **** SMTP testing session as if from host 8.8.8.8
13 <- **** but without any ident (RFC 1413) callback.
14 <- **** This is not for real!
15 <-
16 <- 220 pop.net.schlittermann.de ESMTP Exim 4.89_8-aa105ab-XX Fri, 07 Jul 2017 12:42:22 +0200
17 -> EHLO pop.net.schlittermann.de
18 >>> pop.net.schlittermann.de in helo_lookup_domains? yes (matched "@")
19 >>> looking up host name for 8.8.8.8
20 >>> IP address lookup yielded "google-public-dns-a.google.com"
21 >>> checking addresses for google-public-dns-a.google.com
22 >>> 2001:4860:4860::8888
23 >>> 8.8.8.8 OK
24 >>> host in dsn_advertise_hosts? no (option unset)
25 >>> host in pipelining_advertise_hosts? yes (matched "*")
26 >>> host in chunking_advertise_hosts? yes (matched "*")
27 >>> host in tls_advertise_hosts? no (end of list)
28 <- 250-pop.net.schlittermann.de Hello google-public-dns-a.google.com [8.8.8.8]
29 <- 250-SIZE 52428800
30 <- 250-8BITMIME
31 <- 250-PIPELINING
32 <- 250-CHUNKING
33 <- 250 HELP
34 -> MAIL FROM:<hs@???>
35 <- 250 OK
36 -> RCPT TO:<***@htw-dresden.de>
37 >>> using ACL "acl_check_rcpt"
38 >>> processing "require"
39 >>> message: REJECTED: $acl_verify_message
40 >>> check verify = recipient/callout=10s,use_sender,defer_ok
41 >>> >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
42 >>> routing ***@htw-dresden.de
43 >>> calling dns router
44 >>> routed by dns router
45 >>> Attempting full verification using callout
46 >>> callout cache: no domain record found for htw-dresden.de
47 >>> callout cache: no address record found for ***@htw-dresden.de/<hs@???>
48 >>> 141.56.16.45 in hosts_require_dane? no (option unset)
49 >>> interface=NULL port=25
50 >>> Connecting to rlux45.rz.htw-dresden.de [141.56.16.45]:25 ... failed: Connection timed out (timeout=10s)
51 >>> connect: Connection timed out
52 >>> SMTP timeout
53 >>> 141.56.16.134 in hosts_require_dane? no (option unset)
54 >>> interface=NULL port=25
55 >>> Connecting to rmx4.rz.htw-dresden.de [141.56.16.134]:25 ... connected
56 >>> SMTP<< 220 rmx4.rz.htw-dresden.de ESMTP Postfix (Debian/GNU)
57 >>> 141.56.16.134 in hosts_avoid_esmtp? no (option unset)
58 >>> SMTP>> EHLO pop.net.schlittermann.de
59 >>> cmd buf flush 31 bytes
60 >>> SMTP<< 250-rmx4.rz.htw-dresden.de
61 >>> 250-PIPELINING
62 >>> 250-SIZE 30720000
63 >>> 250-VRFY
64 >>> 250-ETRN
65 >>> 250-STARTTLS
66 >>> 250-ENHANCEDSTATUSCODES
67 >>> 250-8BITMIME
68 >>> 250 DSN
69 >>> 141.56.16.134 in hosts_avoid_tls? no (option unset)
70 >>> 141.56.16.134 in hosts_verify_avoid_tls? no (option unset)
71 >>> SMTP>> STARTTLS
72 >>> cmd buf flush 10 bytes
73 >>> SMTP<< 220 2.0.0 Ready to start TLS
74 >>> 141.56.16.134 in hosts_require_ocsp? no (option unset)
75 >>> 141.56.16.134 in hosts_request_ocsp? yes (matched "*")
76 >>> 141.56.16.134 in tls_verify_hosts? no (option unset)
77 >>> 141.56.16.134 in tls_try_verify_hosts? yes (matched "*")
78 >>> 141.56.16.134 in tls_verify_cert_hostnames? yes (matched "*")
79 LOG: [141.56.16.134] SSL verify error: depth=0 error=self signed certificate cert=/CN=rmx4.rz.htw-dresden.de
80 >>> SMTP>> EHLO pop.net.schlittermann.de
81 >>> cmd buf flush 31 bytes
82 >>> SMTP<< 250-rmx4.rz.htw-dresden.de
83 >>> 250-PIPELINING
84 >>> 250-SIZE 30720000
85 >>> 250-VRFY
86 >>> 250-ETRN
87 >>> 250-ENHANCEDSTATUSCODES
88 >>> 250-8BITMIME
89 >>> 250 DSN
90 >>> 141.56.16.134 in hosts_avoid_pipelining? no (option unset)
91 >>> 141.56.16.134 in hosts_require_auth? no (option unset)
92 >>> SMTP>> MAIL FROM:<hs@???> SIZE=1023
93 >>> SMTP>> RCPT TO:<***@htw-dresden.de>
94 >>> cmd buf flush 85 bytes
95 >>> SMTP<< 250 2.1.0 Ok
96 >>> SMTP<< 450 4.2.0 <***@htw-dresden.de>: Recipient address rejected: Greylisted, see http://postgrey.schweikert.ch/help/htw-dresden.de.html
97 >>> SMTP>> QUIT
98 >>> cmd buf flush 6 bytes
99 >>> SMTP<< 221 2.0.0 Bye
100 >>> SMTP(close)>>
101 >>> 141.56.16.135 in hosts_require_dane? no (option unset)
102 >>> interface=NULL port=25
103 >>> Connecting to rmx5.rz.htw-dresden.de [141.56.16.135]:25 ... connected
104 >>> SMTP<< 220 rmx5.rz.htw-dresden.de ESMTP Postfix (Debian/GNU)
105 >>> 141.56.16.135 in hosts_avoid_esmtp? no (option unset)
106 >>> SMTP>> EHLO pop.net.schlittermann.de
107 >>> cmd buf flush 31 bytes
108 >>> SMTP<< 250-rmx5.rz.htw-dresden.de
109 >>> 250-PIPELINING
110 >>> 250-SIZE 30720000
111 >>> 250-VRFY
112 >>> 250-ETRN
113 >>> 250-STARTTLS
114 >>> 250-ENHANCEDSTATUSCODES
115 >>> 250-8BITMIME
116 >>> 250 DSN
117 >>> 141.56.16.135 in hosts_avoid_tls? no (option unset)
118 >>> 141.56.16.135 in hosts_verify_avoid_tls? no (option unset)
119 >>> SMTP>> STARTTLS
120 >>> cmd buf flush 10 bytes
121 >>> SMTP<< 220 2.0.0 Ready to start TLS
122 >>> 141.56.16.135 in hosts_require_ocsp? no (option unset)
123 >>> 141.56.16.135 in hosts_request_ocsp? yes (matched "*")
124 >>> 141.56.16.135 in tls_verify_hosts? no (option unset)
125 >>> 141.56.16.135 in tls_try_verify_hosts? yes (matched "*")
126 >>> 141.56.16.135 in tls_verify_cert_hostnames? yes (matched "*")
127 LOG: [141.56.16.135] SSL verify error: depth=0 error=self signed certificate cert=/CN=rts2.rz.htw-dresden.de
128 LOG: [141.56.16.135] SSL verify error: certificate name mismatch: DN="/CN=rts2.rz.htw-dresden.de" H="rmx5.rz.htw-dresden.de"
129 >>> SMTP>> EHLO pop.net.schlittermann.de
130 >>> cmd buf flush 31 bytes
131 >>> SMTP<< 250-rmx5.rz.htw-dresden.de
132 >>> 250-PIPELINING
133 >>> 250-SIZE 30720000
134 >>> 250-VRFY
135 >>> 250-ETRN
136 >>> 250-ENHANCEDSTATUSCODES
137 >>> 250-8BITMIME
138 >>> 250 DSN
139 >>> 141.56.16.135 in hosts_avoid_pipelining? no (option unset)
140 >>> 141.56.16.135 in hosts_require_auth? no (option unset)
141 >>> SMTP>> MAIL FROM:<hs@???> SIZE=1023
142 >>> SMTP>> RCPT TO:<***@htw-dresden.de>
143 >>> cmd buf flush 85 bytes
144 >>> SMTP<< 250 2.1.0 Ok
145 >>> SMTP<< 450 4.2.0 <***@htw-dresden.de>: Recipient address rejected: Greylisted, see http://postgrey.schweikert.ch/help/htw-dresden.de.html
146 >>> SMTP>> QUIT
147 >>> cmd buf flush 6 bytes
148 >>> SMTP<< 221 2.0.0 Bye
149 >>> SMTP(close)>>
150 >>> 141.56.16.136 in hosts_require_dane? no (option unset)
151 >>> interface=NULL port=25
152 >>> Connecting to rmx6.rz.htw-dresden.de [141.56.16.136]:25 ... connected
153 >>> SMTP<< 220 rmx6.rz.htw-dresden.de ESMTP Postfix (Debian/GNU)
154 >>> 141.56.16.136 in hosts_avoid_esmtp? no (option unset)
155 >>> SMTP>> EHLO pop.net.schlittermann.de
156 >>> cmd buf flush 31 bytes
157 >>> SMTP<< 250-rmx6.rz.htw-dresden.de
158 >>> 250-PIPELINING
159 >>> 250-SIZE 30720000
160 >>> 250-VRFY
161 >>> 250-ETRN
162 >>> 250-STARTTLS
163 >>> 250-ENHANCEDSTATUSCODES
164 >>> 250-8BITMIME
165 >>> 250 DSN
166 >>> 141.56.16.136 in hosts_avoid_tls? no (option unset)
167 >>> 141.56.16.136 in hosts_verify_avoid_tls? no (option unset)
168 >>> SMTP>> STARTTLS
169 >>> cmd buf flush 10 bytes
170 >>> SMTP<< 220 2.0.0 Ready to start TLS
171 >>> 141.56.16.136 in hosts_require_ocsp? no (option unset)
172 >>> 141.56.16.136 in hosts_request_ocsp? yes (matched "*")
173 >>> 141.56.16.136 in tls_verify_hosts? no (option unset)
174 >>> 141.56.16.136 in tls_try_verify_hosts? yes (matched "*")
175 >>> 141.56.16.136 in tls_verify_cert_hostnames? yes (matched "*")
176 LOG: [141.56.16.136] SSL verify error: depth=0 error=self signed certificate cert=/CN=rmx6.rz.htw-dresden.de
177 >>> SMTP>> EHLO pop.net.schlittermann.de
178 >>> cmd buf flush 31 bytes
179 >>> SMTP<< 250-rmx6.rz.htw-dresden.de
180 >>> 250-PIPELINING
181 >>> 250-SIZE 30720000
182 >>> 250-VRFY
183 >>> 250-ETRN
184 >>> 250-ENHANCEDSTATUSCODES
185 >>> 250-8BITMIME
186 >>> 250 DSN
187 >>> 141.56.16.136 in hosts_avoid_pipelining? no (option unset)
188 >>> 141.56.16.136 in hosts_require_auth? no (option unset)
189 >>> SMTP>> MAIL FROM:<hs@???> SIZE=1023
190 >>> SMTP>> RCPT TO:<***@htw-dresden.de>
191 >>> cmd buf flush 85 bytes
192 >>> SMTP<< 250 2.1.0 Ok
193 >>> SMTP<< 450 4.2.0 <***@htw-dresden.de>: Recipient address rejected: Greylisted, see http://postgrey.schweikert.ch/help/htw-dresden.de.html
194 >>> SMTP>> QUIT
195 >>> cmd buf flush 6 bytes
196 >>> SMTP<< 221 2.0.0 Bye
197 >>> SMTP(close)>>
198 >>> wrote callout cache domain record for htw-dresden.de:
199 >>> result=1 postmaster=0 random=0
200 >>> ----------- end verify ------------
201 >>> verify defer overridden by callout_defer_ok
202 >>> check logwrite = verification succeeded for $sender_address $local_part@$domain
203 >>> = verification succeeded for hs@??? ***@htw-dresden.de
204 LOG: verification succeeded for hs@??? ***@htw-dresden.de
205 >>> require: condition test succeeded in ACL "acl_check_rcpt"
206 >>> processing "accept"
207 >>> accept: condition test succeeded in ACL "acl_check_rcpt"
208 >>> end of ACL "acl_check_rcpt": ACCEPT
209 <- 250 Accepted
210 -> DATA
211 <- 354 Enter message, ending with "." on a line by itself
212 -> Date: Fri, 07 Jul 2017 12:42:22 +0200
213 -> To: ***@htw-dresden.de
214 -> From: hs@???
215 -> Subject: test Fri, 07 Jul 2017 12:42:22 +0200
216 -> X-Mailer: swaks v20120320.0 jetmore.org/john/code/swaks/
217 ->
218 -> This is a test mailing
219 ->
220 -> .
221 >>> host in ignore_fromline_hosts? no (option unset)
222 LOG: 1dTQiX-0006zS-D3 <= hs@??? H=google-public-dns-a.google.com (pop.net.schlittermann.de) [8.8.8.8] P=esmtp S=509
223 <- 250 OK id=1dTQiX-0006zS-D3
224 -> QUIT
225 <-
226 <- **** SMTP testing: that is not a real message id!
227 <-
228 <- 221 pop.net.schlittermann.de closing connection
229 === Connection closed with child process.
