Logging: Add "D=" to more connection closure log lines. Bug 2434
[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 >>> test in helo_lookup_domains?
10 >>>  list element: @
11 >>>  list element: @[]
12 >>> test in helo_lookup_domains? no (end of list)
13 >>> using ACL "mail"
14 >>> processing "accept" (TESTSUITE/test-config 20)
15 >>> check verify = sender/callout=1s,maxwait=1s
16 >>> >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
17 >>> routing x@y
18 >>> calling r1 router
19 >>> routed by r1 router
20 >>> local host found for non-MX address
21 MUNGED: ::1 will be omitted in what follows
22 >>> get[host|ipnode]byname[2] looked up these IP addresses:
23 >>>   name=127.0.0.1 address=127.0.0.1
24 >>> Attempting full verification using callout
25 >>> ... callout omitted by default when host testing
26 >>> (Use -bhc if you want the callouts to happen.)
27 >>> ----------- end verify ------------
28 >>> accept: condition test succeeded in ACL "mail"
29 >>> end of ACL "mail": ACCEPT
30 Exim version x.yz ....
31 changed uid/gid: forcing real = effective
32   uid=uuuu gid=CALLER_GID pid=p1234
33 configuration file is TESTSUITE/test-config
34 admin user
35 changed uid/gid: privilege not needed
36   uid=EXIM_UID gid=EXIM_GID pid=p1234
37 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
38 sender address = CALLER@myhost.test.ex
39 sender_fullhost = [1.2.3.4]
40 sender_rcvhost = [1.2.3.4]
41 host in hosts_connection_nolog? no (option unset)
42 LOG: smtp_connection MAIN
43   SMTP connection from [1.2.3.4]
44 host in host_lookup? no (option unset)
45 set_process_info: pppp handling incoming connection from [1.2.3.4]
46 host in host_reject_connection? no (option unset)
47 host in sender_unqualified_hosts? no (option unset)
48 host in recipient_unqualified_hosts? no (option unset)
49 host in helo_verify_hosts? no (option unset)
50 host in helo_try_verify_hosts? no (option unset)
51 host in helo_accept_junk_hosts? no (option unset)
52 SMTP>> 220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000
53 smtp_setup_msg entered
54 SMTP<< helo test
55 test in helo_lookup_domains?
56  list element: @
57  list element: @[]
58 test in helo_lookup_domains? no (end of list)
59 sender_fullhost = (test) [1.2.3.4]
60 sender_rcvhost = [1.2.3.4] (helo=test)
61 set_process_info: pppp handling incoming connection from (test) [1.2.3.4]
62 SMTP>> 250 myhost.test.ex Hello test [1.2.3.4]
63 SMTP<< mail from:<x@y>
64 spool directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100 msg_size = 0
65 log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
66 using ACL "mail"
67 processing "accept" (TESTSUITE/test-config 20)
68 check verify = sender/callout=1s,maxwait=1s
69 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
70 Verifying x@y
71 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
72 Considering x@y
73 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
74 routing x@y
75 --------> r1 router <--------
76 local_part=x domain=y
77 calling r1 router
78 r1 router called for x@y
79   domain = y
80 set transport t1
81 queued for t1 transport: local_part = x
82 domain = y
83   errors_to=NULL
84   domain_data=NULL local_part_data=NULL
85 routed by r1 router
86   envelope to: x@y
87   transport: t1
88 using host_fake_gethostbyname for 127.0.0.1 (IPv4)
89 local host found for non-MX address
90 MUNGED: ::1 will be omitted in what follows
91 get[host|ipnode]byname[2] looked up these IP addresses:
92   name=127.0.0.1 address=127.0.0.1
93 Attempting full verification using callout
94  locking TESTSUITE/spool/db/callout.lockfile
95  locked  TESTSUITE/spool/db/callout.lockfile
96  EXIM_DBOPEN: file <TESTSUITE/spool/db/callout> dir <TESTSUITE/spool/db> flags=O_RDWR
97  returned from EXIM_DBOPEN: 0xAAAAAAAA
98  opened hints database TESTSUITE/spool/db/callout: flags=O_RDWR
99  dbfn_read: key=y
100  callout cache: no domain record found for y
101  dbfn_read: key=x@y
102  callout cache: no address record found for x@y
103  EXIM_DBCLOSE(0xAAAAAAAA)
104  closed hints database and lockfile
105 interface=NULL port=PORT_S
106 Connecting to 127.0.0.1 [127.0.0.1]:PORT_S ... 127.0.0.1 in hosts_try_fastopen?
107  list element: 
108  connected
109   SMTP<< 220 server ready
110 127.0.0.1 in hosts_avoid_esmtp? no (option unset)
111   SMTP>> EHLO myhost.test.ex
112 cmd buf flush ddd bytes
113   SMTP<< 250 OK
114 not using PIPELINING
115 not using DSN
116 127.0.0.1 in hosts_require_auth? no (option unset)
117   SMTP>> MAIL FROM:<>
118 cmd buf flush ddd bytes
119   SMTP<< 250 OK
120   SMTP>> RCPT TO:<x@y>
121 cmd buf flush ddd bytes
122 sync_responses expect rcpt for x@y
123   SMTP<< 250 OK
124   SMTP>> QUIT
125 cmd buf flush ddd bytes
126   SMTP<< 220 OK
127   SMTP(close)>>
128 cmdlog: '220:EHLO:250:MAIL:250:RCPT:250:QUIT:220'
129  locking TESTSUITE/spool/db/callout.lockfile
130  locked  TESTSUITE/spool/db/callout.lockfile
131  EXIM_DBOPEN: file <TESTSUITE/spool/db/callout> dir <TESTSUITE/spool/db> flags=O_RDWR|O_CREAT
132  returned from EXIM_DBOPEN: 0xAAAAAAAA
133  opened hints database TESTSUITE/spool/db/callout: flags=O_RDWR|O_CREAT
134  dbfn_write: key=y
135  wrote callout cache domain record for y:
136    result=1 postmaster=0 random=0
137  dbfn_write: key=x@y
138  wrote positive callout cache address record for x@y
139  EXIM_DBCLOSE(0xAAAAAAAA)
140  closed hints database and lockfile
141 ----------- end verify ------------
142 sender x@y verified ok
143 accept: condition test succeeded in ACL "mail"
144 end of ACL "mail": ACCEPT
145 SMTP>> 250 OK
146 SMTP<< quit
147 SMTP>> 221 myhost.test.ex closing connection
148 LOG: smtp_connection MAIN
149   SMTP connection from (test) [1.2.3.4] D=qqs closed by QUIT
150 search_tidyup called
151 >>>>>>>>>>>>>>>> Exim pid=p1234 (fresh-exec) terminating with rc=0 >>>>>>>>>>>>>>>>
152 Exim version x.yz ....
153 changed uid/gid: forcing real = effective
154   uid=uuuu gid=CALLER_GID pid=p1235
155 configuration file is TESTSUITE/test-config
156 admin user
157 changed uid/gid: privilege not needed
158   uid=EXIM_UID gid=EXIM_GID pid=p1235
159 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
160 sender address = CALLER@myhost.test.ex
161 sender_fullhost = [1.2.3.4]
162 sender_rcvhost = [1.2.3.4]
163 host in hosts_connection_nolog? no (option unset)
164 LOG: smtp_connection MAIN
165   SMTP connection from [1.2.3.4]
166 host in host_lookup? no (option unset)
167 set_process_info: pppp handling incoming connection from [1.2.3.4]
168 host in host_reject_connection? no (option unset)
169 host in sender_unqualified_hosts? no (option unset)
170 host in recipient_unqualified_hosts? no (option unset)
171 host in helo_verify_hosts? no (option unset)
172 host in helo_try_verify_hosts? no (option unset)
173 host in helo_accept_junk_hosts? no (option unset)
174 SMTP>> 220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000
175 smtp_setup_msg entered
176 SMTP<< helo test
177 test in helo_lookup_domains?
178  list element: @
179  list element: @[]
180 test in helo_lookup_domains? no (end of list)
181 sender_fullhost = (test) [1.2.3.4]
182 sender_rcvhost = [1.2.3.4] (helo=test)
183 set_process_info: pppp handling incoming connection from (test) [1.2.3.4]
184 SMTP>> 250 myhost.test.ex Hello test [1.2.3.4]
185 SMTP<< mail from:<x@y>
186 spool directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100 msg_size = 0
187 log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
188 using ACL "mail"
189 processing "accept" (TESTSUITE/test-config 20)
190 check verify = sender/callout=1s,maxwait=1s
191 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
192 Verifying x@y
193 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
194 Considering x@y
195 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
196 routing x@y
197 --------> r1 router <--------
198 local_part=x domain=y
199 calling r1 router
200 r1 router called for x@y
201   domain = y
202 set transport t1
203 queued for t1 transport: local_part = x
204 domain = y
205   errors_to=NULL
206   domain_data=NULL local_part_data=NULL
207 routed by r1 router
208   envelope to: x@y
209   transport: t1
210 using host_fake_gethostbyname for 127.0.0.1 (IPv4)
211 local host found for non-MX address
212 MUNGED: ::1 will be omitted in what follows
213 get[host|ipnode]byname[2] looked up these IP addresses:
214   name=127.0.0.1 address=127.0.0.1
215 Attempting full verification using callout
216  locking TESTSUITE/spool/db/callout.lockfile
217  locked  TESTSUITE/spool/db/callout.lockfile
218  EXIM_DBOPEN: file <TESTSUITE/spool/db/callout> dir <TESTSUITE/spool/db> flags=O_RDWR
219  returned from EXIM_DBOPEN: 0xAAAAAAAA
220  opened hints database TESTSUITE/spool/db/callout: flags=O_RDWR
221  dbfn_read: key=y
222  callout cache: found domain record for y
223  dbfn_read: key=x@y
224  callout cache: found address record for x@y
225  callout cache: address record is positive
226  EXIM_DBCLOSE(0xAAAAAAAA)
227  closed hints database and lockfile
228 ----------- end verify ------------
229 sender x@y verified ok
230 accept: condition test succeeded in ACL "mail"
231 end of ACL "mail": ACCEPT
232 SMTP>> 250 OK
233 SMTP<< quit
234 SMTP>> 221 myhost.test.ex closing connection
235 LOG: smtp_connection MAIN
236   SMTP connection from (test) [1.2.3.4] D=qqs closed by QUIT
237 search_tidyup called
238 >>>>>>>>>>>>>>>> Exim pid=p1235 (fresh-exec) terminating with rc=0 >>>>>>>>>>>>>>>>
239 >>> host in hosts_connection_nolog? no (option unset)
240 >>> host in host_lookup? no (option unset)
241 >>> host in host_reject_connection? no (option unset)
242 >>> host in sender_unqualified_hosts? no (option unset)
243 >>> host in recipient_unqualified_hosts? no (option unset)
244 >>> host in helo_verify_hosts? no (option unset)
245 >>> host in helo_try_verify_hosts? no (option unset)
246 >>> host in helo_accept_junk_hosts? no (option unset)
247 >>> test in helo_lookup_domains?
248 >>>  list element: @
249 >>>  list element: @[]
250 >>> test in helo_lookup_domains? no (end of list)
251 >>> using ACL "mail"
252 >>> processing "accept" (TESTSUITE/test-config 20)
253 >>> check verify = sender/callout=1s,maxwait=1s
254 >>> >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
255 >>> routing x@y
256 >>> calling r1 router
257 >>> routed by r1 router
258 >>> local host found for non-MX address
259 MUNGED: ::1 will be omitted in what follows
260 >>> get[host|ipnode]byname[2] looked up these IP addresses:
261 >>>   name=127.0.0.1 address=127.0.0.1
262 >>> Attempting full verification using callout
263 >>> callout cache: found domain record for y
264 >>> callout cache: found address record for x@y
265 >>> callout cache: address record is positive
266 >>> ----------- end verify ------------
267 >>> accept: condition test succeeded in ACL "mail"
268 >>> end of ACL "mail": ACCEPT
269 >>> host in hosts_connection_nolog? no (option unset)
270 >>> host in host_lookup? no (option unset)
271 >>> host in host_reject_connection? no (option unset)
272 >>> host in sender_unqualified_hosts? no (option unset)
273 >>> host in recipient_unqualified_hosts? no (option unset)
274 >>> host in helo_verify_hosts? no (option unset)
275 >>> host in helo_try_verify_hosts? no (option unset)
276 >>> host in helo_accept_junk_hosts? no (option unset)
277 >>> test in helo_lookup_domains?
278 >>>  list element: @
279 >>>  list element: @[]
280 >>> test in helo_lookup_domains? no (end of list)
281 >>> using ACL "mail"
282 >>> processing "accept" (TESTSUITE/test-config 20)
283 >>> check verify = sender/callout=1s,maxwait=1s
284 >>> >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
285 >>> routing a@b
286 >>> calling r1 router
287 >>> routed by r1 router
288 >>> local host found for non-MX address
289 MUNGED: ::1 will be omitted in what follows
290 >>> get[host|ipnode]byname[2] looked up these IP addresses:
291 >>>   name=127.0.0.1 address=127.0.0.1
292 >>> Attempting full verification using callout
293 >>> callout cache: no domain record found for b
294 >>> callout cache: no address record found for a@b
295 >>> interface=NULL port=PORT_S
296 >>> Connecting to 127.0.0.1 [127.0.0.1]:PORT_S ... 127.0.0.1 in hosts_try_fastopen?
297 >>>  list element: 
298 >>> >>>  connected
299 >>>   SMTP<< 220 server ready
300 >>> 127.0.0.1 in hosts_avoid_esmtp? no (option unset)
301 >>>   SMTP>> EHLO myhost.test.ex
302 >>> cmd buf flush 21 bytes
303 >>>   SMTP<< 250 OK
304 >>> 127.0.0.1 in hosts_require_auth? no (option unset)
305 >>>   SMTP>> MAIL FROM:<>
306 >>> cmd buf flush 14 bytes
307 >>>   SMTP<< 250 OK
308 >>>   SMTP>> RCPT TO:<a@b>
309 >>> cmd buf flush 15 bytes
310 >>>   SMTP<< 250 OK
311 >>>   SMTP>> QUIT
312 >>> cmd buf flush 6 bytes
313 >>>   SMTP<< 220 OK
314 >>>   SMTP(close)>>
315 >>> cmdlog: '220:EHLO:250:MAIL:250:RCPT:250:QUIT:220'
316 >>> wrote callout cache domain record for b:
317 >>>   result=1 postmaster=0 random=0
318 >>> wrote positive callout cache address record for a@b
319 >>> ----------- end verify ------------
320 >>> accept: condition test succeeded in ACL "mail"
321 >>> end of ACL "mail": ACCEPT
322 >>> host in hosts_connection_nolog? no (option unset)
323 >>> host in host_lookup? no (option unset)
324 >>> host in host_reject_connection? no (option unset)
325 >>> host in sender_unqualified_hosts? no (option unset)
326 >>> host in recipient_unqualified_hosts? no (option unset)
327 >>> host in helo_verify_hosts? no (option unset)
328 >>> host in helo_try_verify_hosts? no (option unset)
329 >>> host in helo_accept_junk_hosts? no (option unset)
330 >>> test in helo_lookup_domains?
331 >>>  list element: @
332 >>>  list element: @[]
333 >>> test in helo_lookup_domains? no (end of list)
334 >>> using ACL "mail"
335 >>> processing "accept" (TESTSUITE/test-config 20)
336 >>> check verify = sender/callout=1s,maxwait=1s
337 >>> >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
338 >>> routing p1@q
339 >>> calling r1 router
340 >>> routed by r1 router
341 >>> local host found for non-MX address
342 MUNGED: ::1 will be omitted in what follows
343 >>> get[host|ipnode]byname[2] looked up these IP addresses:
344 >>>   name=127.0.0.1 address=127.0.0.1
345 >>> Attempting full verification using callout
346 >>> callout cache: no domain record found for q
347 >>> callout cache: no address record found for p1@q
348 >>> interface=NULL port=PORT_S
349 >>> Connecting to 127.0.0.1 [127.0.0.1]:PORT_S ... 127.0.0.1 in hosts_try_fastopen?
350 >>>  list element: 
351 >>> >>>  connected
352 >>>   SMTP<< 220 server ready
353 >>> 127.0.0.1 in hosts_avoid_esmtp? no (option unset)
354 >>>   SMTP>> EHLO myhost.test.ex
355 >>> cmd buf flush 21 bytes
356 >>>   SMTP(close)>>
357 >>> cmdlog: '220:EHLO'
358 >>> SMTP timeout
359 >>> ----------- end verify ------------
360 >>> accept: condition test deferred in ACL "mail"
361 LOG: H=(test) [1.2.3.4] sender verify defer for <p1@q>: Could not complete sender verify callout: 127.0.0.1 [127.0.0.1] : SMTP timeout after EHLO myhost.test.ex
362 LOG: H=(test) [1.2.3.4] temporarily rejected MAIL <p1@q>: Could not complete sender verify callout