Transport filter timeout fix. Fixes: #898
[users/jgh/exim.git] / test / stderr / 0432
1 >>> host in hosts_connection_nolog? no (option unset)
2 >>> host in host_lookup? no (option unset)
3 >>> host in host_reject_connection? no (option unset)
4 >>> host in sender_unqualified_hosts? no (option unset)
5 >>> host in recipient_unqualified_hosts? no (option unset)
6 >>> host in helo_verify_hosts? no (option unset)
7 >>> host in helo_try_verify_hosts? no (option unset)
8 >>> host in helo_accept_junk_hosts? no (option unset)
9 >>> using ACL "mail"
10 >>> processing "accept"
11 >>> check verify = sender/callout=1s,maxwait=1s
12 >>> >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
13 >>> routing x@y
14 >>> calling r1 router
15 >>> routed by r1 router
16 >>> local host found for non-MX address
17 >>> fully qualified name = 127.0.0.1
18 MUNGED: ::1 will be omitted in what follows
19 >>> get[host|ipnode]byname[2] looked up these IP addresses:
20 >>>   name=127.0.0.1 address=127.0.0.1
21 >>> Attempting full verification using callout
22 >>> ... callout omitted by default when host testing
23 >>> (Use -bhc if you want the callouts to happen.)
24 >>> ----------- end verify ------------
25 >>> accept: condition test succeeded
26 Exim version x.yz ....
27 changed uid/gid: forcing real = effective
28   uid=uuuu gid=CALLER_GID pid=pppp
29 configuration file is TESTSUITE/test-config
30 admin user
31 changed uid/gid: privilege not needed
32   uid=EXIM_UID gid=EXIM_GID pid=pppp
33 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
34 sender address = CALLER@myhost.test.ex
35 sender_fullhost = [1.2.3.4]
36 sender_rcvhost = [1.2.3.4]
37 host in hosts_connection_nolog? no (option unset)
38 LOG: smtp_connection MAIN
39   SMTP connection from [1.2.3.4]
40 host in host_lookup? no (option unset)
41 set_process_info: pppp handling incoming connection from [1.2.3.4]
42 host in host_reject_connection? no (option unset)
43 host in sender_unqualified_hosts? no (option unset)
44 host in recipient_unqualified_hosts? no (option unset)
45 host in helo_verify_hosts? no (option unset)
46 host in helo_try_verify_hosts? no (option unset)
47 host in helo_accept_junk_hosts? no (option unset)
48 SMTP>> 220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000
49 smtp_setup_msg entered
50 SMTP<< mail from:<x@y>
51 using ACL "mail"
52 processing "accept"
53 check verify = sender/callout=1s,maxwait=1s
54 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
55 Verifying x@y
56 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
57 Considering x@y
58 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
59 routing x@y
60 --------> r1 router <--------
61 local_part=x domain=y
62 calling r1 router
63 r1 router called for x@y
64   domain = y
65 set transport t1
66 queued for t1 transport: local_part = x
67 domain = y
68   errors_to=NULL
69   domain_data=NULL localpart_data=NULL
70 routed by r1 router
71   envelope to: x@y
72   transport: t1
73 using host_fake_gethostbyname for 127.0.0.1 (IPv4)
74 local host found for non-MX address
75 fully qualified name = 127.0.0.1
76 MUNGED: ::1 will be omitted in what follows
77 get[host|ipnode]byname[2] looked up these IP addresses:
78   name=127.0.0.1 address=127.0.0.1
79 Attempting full verification using callout
80 locking TESTSUITE/spool/db/callout.lockfile
81 locked TESTSUITE/spool/db/callout.lockfile
82 EXIM_DBOPEN(TESTSUITE/spool/db/callout)
83 returned from EXIM_DBOPEN
84 opened hints database TESTSUITE/spool/db/callout: flags=O_RDWR
85 dbfn_read: key=y
86 callout cache: no domain record found
87 dbfn_read: key=x@y
88 callout cache: no address record found
89 interface=NULL port=1224
90 Connecting to 127.0.0.1 [127.0.0.1]:1224 ... connected
91   SMTP<< 220 server ready
92   SMTP>> HELO myhost.test.ex
93   SMTP<< 250 OK
94   SMTP>> MAIL FROM:<>
95   SMTP<< 250 OK
96   SMTP>> RCPT TO:<x@y>
97   SMTP<< 250 OK
98   SMTP>> QUIT
99 locking TESTSUITE/spool/db/callout.lockfile
100 locked TESTSUITE/spool/db/callout.lockfile
101 EXIM_DBOPEN(TESTSUITE/spool/db/callout)
102 returned from EXIM_DBOPEN
103 opened hints database TESTSUITE/spool/db/callout: flags=O_RDWR|O_CREAT
104 dbfn_write: key=y
105 wrote callout cache domain record:
106   result=1 postmaster=0 random=0
107 dbfn_write: key=x@y
108 wrote positive callout cache address record
109 ----------- end verify ------------
110 sender x@y verified ok
111 accept: condition test succeeded
112 SMTP>> 250 OK
113 SMTP<< quit
114 SMTP>> 221 myhost.test.ex closing connection
115 LOG: smtp_connection MAIN
116   SMTP connection from [1.2.3.4] closed by QUIT
117 search_tidyup called
118 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
119 Exim version x.yz ....
120 changed uid/gid: forcing real = effective
121   uid=uuuu gid=CALLER_GID pid=pppp
122 configuration file is TESTSUITE/test-config
123 admin user
124 changed uid/gid: privilege not needed
125   uid=EXIM_UID gid=EXIM_GID pid=pppp
126 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
127 sender address = CALLER@myhost.test.ex
128 sender_fullhost = [1.2.3.4]
129 sender_rcvhost = [1.2.3.4]
130 host in hosts_connection_nolog? no (option unset)
131 LOG: smtp_connection MAIN
132   SMTP connection from [1.2.3.4]
133 host in host_lookup? no (option unset)
134 set_process_info: pppp handling incoming connection from [1.2.3.4]
135 host in host_reject_connection? no (option unset)
136 host in sender_unqualified_hosts? no (option unset)
137 host in recipient_unqualified_hosts? no (option unset)
138 host in helo_verify_hosts? no (option unset)
139 host in helo_try_verify_hosts? no (option unset)
140 host in helo_accept_junk_hosts? no (option unset)
141 SMTP>> 220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000
142 smtp_setup_msg entered
143 SMTP<< mail from:<x@y>
144 using ACL "mail"
145 processing "accept"
146 check verify = sender/callout=1s,maxwait=1s
147 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
148 Verifying x@y
149 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
150 Considering x@y
151 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
152 routing x@y
153 --------> r1 router <--------
154 local_part=x domain=y
155 calling r1 router
156 r1 router called for x@y
157   domain = y
158 set transport t1
159 queued for t1 transport: local_part = x
160 domain = y
161   errors_to=NULL
162   domain_data=NULL localpart_data=NULL
163 routed by r1 router
164   envelope to: x@y
165   transport: t1
166 using host_fake_gethostbyname for 127.0.0.1 (IPv4)
167 local host found for non-MX address
168 fully qualified name = 127.0.0.1
169 MUNGED: ::1 will be omitted in what follows
170 get[host|ipnode]byname[2] looked up these IP addresses:
171   name=127.0.0.1 address=127.0.0.1
172 Attempting full verification using callout
173 locking TESTSUITE/spool/db/callout.lockfile
174 locked TESTSUITE/spool/db/callout.lockfile
175 EXIM_DBOPEN(TESTSUITE/spool/db/callout)
176 returned from EXIM_DBOPEN
177 opened hints database TESTSUITE/spool/db/callout: flags=O_RDWR
178 dbfn_read: key=y
179 callout cache: found domain record
180 dbfn_read: key=x@y
181 callout cache: found address record
182 callout cache: address record is positive
183 ----------- end verify ------------
184 sender x@y verified ok
185 accept: condition test succeeded
186 SMTP>> 250 OK
187 SMTP<< quit
188 SMTP>> 221 myhost.test.ex closing connection
189 LOG: smtp_connection MAIN
190   SMTP connection from [1.2.3.4] closed by QUIT
191 search_tidyup called
192 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
193 >>> host in hosts_connection_nolog? no (option unset)
194 >>> host in host_lookup? no (option unset)
195 >>> host in host_reject_connection? no (option unset)
196 >>> host in sender_unqualified_hosts? no (option unset)
197 >>> host in recipient_unqualified_hosts? no (option unset)
198 >>> host in helo_verify_hosts? no (option unset)
199 >>> host in helo_try_verify_hosts? no (option unset)
200 >>> host in helo_accept_junk_hosts? no (option unset)
201 >>> using ACL "mail"
202 >>> processing "accept"
203 >>> check verify = sender/callout=1s,maxwait=1s
204 >>> >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
205 >>> routing x@y
206 >>> calling r1 router
207 >>> routed by r1 router
208 >>> local host found for non-MX address
209 >>> fully qualified name = 127.0.0.1
210 MUNGED: ::1 will be omitted in what follows
211 >>> get[host|ipnode]byname[2] looked up these IP addresses:
212 >>>   name=127.0.0.1 address=127.0.0.1
213 >>> Attempting full verification using callout
214 >>> callout cache: found domain record
215 >>> callout cache: found address record
216 >>> callout cache: address record is positive
217 >>> ----------- end verify ------------
218 >>> accept: condition test succeeded
219 >>> host in hosts_connection_nolog? no (option unset)
220 >>> host in host_lookup? no (option unset)
221 >>> host in host_reject_connection? no (option unset)
222 >>> host in sender_unqualified_hosts? no (option unset)
223 >>> host in recipient_unqualified_hosts? no (option unset)
224 >>> host in helo_verify_hosts? no (option unset)
225 >>> host in helo_try_verify_hosts? no (option unset)
226 >>> host in helo_accept_junk_hosts? no (option unset)
227 >>> using ACL "mail"
228 >>> processing "accept"
229 >>> check verify = sender/callout=1s,maxwait=1s
230 >>> >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
231 >>> routing a@b
232 >>> calling r1 router
233 >>> routed by r1 router
234 >>> local host found for non-MX address
235 >>> fully qualified name = 127.0.0.1
236 MUNGED: ::1 will be omitted in what follows
237 >>> get[host|ipnode]byname[2] looked up these IP addresses:
238 >>>   name=127.0.0.1 address=127.0.0.1
239 >>> Attempting full verification using callout
240 >>> callout cache: no domain record found
241 >>> callout cache: no address record found
242 >>> interface=NULL port=1224
243 >>> Connecting to 127.0.0.1 [127.0.0.1]:1224 ... connected
244 >>>   SMTP<< 220 server ready
245 >>>   SMTP>> HELO myhost.test.ex
246 >>>   SMTP<< 250 OK
247 >>>   SMTP>> MAIL FROM:<>
248 >>>   SMTP<< 250 OK
249 >>>   SMTP>> RCPT TO:<a@b>
250 >>>   SMTP<< 250 OK
251 >>>   SMTP>> QUIT
252 >>> wrote callout cache domain record:
253 >>>   result=1 postmaster=0 random=0
254 >>> wrote positive callout cache address record
255 >>> ----------- end verify ------------
256 >>> accept: condition test succeeded
257 >>> host in hosts_connection_nolog? no (option unset)
258 >>> host in host_lookup? no (option unset)
259 >>> host in host_reject_connection? no (option unset)
260 >>> host in sender_unqualified_hosts? no (option unset)
261 >>> host in recipient_unqualified_hosts? no (option unset)
262 >>> host in helo_verify_hosts? no (option unset)
263 >>> host in helo_try_verify_hosts? no (option unset)
264 >>> host in helo_accept_junk_hosts? no (option unset)
265 >>> using ACL "mail"
266 >>> processing "accept"
267 >>> check verify = sender/callout=1s,maxwait=1s
268 >>> >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
269 >>> routing p1@q
270 >>> calling r1 router
271 >>> routed by r1 router
272 >>> local host found for non-MX address
273 >>> fully qualified name = 127.0.0.1
274 MUNGED: ::1 will be omitted in what follows
275 >>> get[host|ipnode]byname[2] looked up these IP addresses:
276 >>>   name=127.0.0.1 address=127.0.0.1
277 >>> Attempting full verification using callout
278 >>> callout cache: no domain record found
279 >>> callout cache: no address record found
280 >>> interface=NULL port=1224
281 >>> Connecting to 127.0.0.1 [127.0.0.1]:1224 ... connected
282 >>>   SMTP<< 220 server ready
283 >>>   SMTP>> HELO myhost.test.ex
284 >>> SMTP timeout
285 >>> ----------- end verify ------------
286 >>> accept: condition test deferred
287 LOG: H=[1.2.3.4] sender verify defer for <p1@q>: Could not complete sender verify callout
288 LOG: H=[1.2.3.4] temporarily rejected MAIL <p1@q>: Could not complete sender verify callout