Fix logging of drop-after-EHLO-reject.
[exim.git] / test / stderr / 9100
1 Exim version x.yz ....
2 configuration file is TESTSUITE/test-config
3 admin user
4 search_open: mysql "NULL"
5 search_find: file="NULL"
6   key="select name from them where id='CALLER';" partial=-1 affix=NULL starflags=0
7 LRU list:
8 internal_search_find: file="NULL"
9   type=mysql key="select name from them where id='CALLER';"
10 database lookup required for select name from them where id='CALLER';
11 MySQL query: select name from them where id='CALLER';
12 MYSQL new connection: host=localhost port=0 socket=NULL database=test user=root
13 lookup yielded: Philip Hazel
14 search_open: mysql "NULL"
15   cached open
16 search_find: file="NULL"
17   key="select name from them where id='CALLER';" partial=-1 affix=NULL starflags=0
18 LRU list:
19 internal_search_find: file="NULL"
20   type=mysql key="select name from them where id='CALLER';"
21 cached data used for lookup of select name from them where id='CALLER';
22 lookup yielded: Philip Hazel
23 search_open: mysql "NULL"
24   cached open
25 search_find: file="NULL"
26   key="select name from them where id='xxxx';" partial=-1 affix=NULL starflags=0
27 LRU list:
28 internal_search_find: file="NULL"
29   type=mysql key="select name from them where id='xxxx';"
30 database lookup required for select name from them where id='xxxx';
31 MySQL query: select name from them where id='xxxx';
32 MYSQL using cached connection for localhost/test/root
33 MYSQL: no data found
34 lookup failed
35 search_open: mysql "NULL"
36   cached open
37 search_find: file="NULL"
38   key="select name from them where id='nothing';" partial=-1 affix=NULL starflags=0
39 LRU list:
40 internal_search_find: file="NULL"
41   type=mysql key="select name from them where id='nothing';"
42 database lookup required for select name from them where id='nothing';
43 MySQL query: select name from them where id='nothing';
44 MYSQL using cached connection for localhost/test/root
45 MYSQL: no data found
46 lookup failed
47 search_open: mysql "NULL"
48   cached open
49 search_find: file="NULL"
50   key="select id,name from them where id='nothing';" partial=-1 affix=NULL starflags=0
51 LRU list:
52 internal_search_find: file="NULL"
53   type=mysql key="select id,name from them where id='nothing';"
54 database lookup required for select id,name from them where id='nothing';
55 MySQL query: select id,name from them where id='nothing';
56 MYSQL using cached connection for localhost/test/root
57 lookup yielded: id=nothing name="" 
58 search_open: mysql "NULL"
59   cached open
60 search_find: file="NULL"
61   key="delete from them where id='nonexist';" partial=-1 affix=NULL starflags=0
62 LRU list:
63 internal_search_find: file="NULL"
64   type=mysql key="delete from them where id='nonexist';"
65 database lookup required for delete from them where id='nonexist';
66 MySQL query: delete from them where id='nonexist';
67 MYSQL using cached connection for localhost/test/root
68 MYSQL: query was not one that returns data
69 lookup forced cache cleanup
70 lookup yielded: 0
71 search_open: mysql "NULL"
72   cached open
73 search_find: file="NULL"
74   key="select * from them where id='quote';" partial=-1 affix=NULL starflags=0
75 LRU list:
76 internal_search_find: file="NULL"
77   type=mysql key="select * from them where id='quote';"
78 database lookup required for select * from them where id='quote';
79 MySQL query: select * from them where id='quote';
80 MYSQL using cached connection for localhost/test/root
81 lookup yielded: id=quote name="\"Q\" Oted" home=/home/quoted mail=quoted@xxx 
82 search_open: mysql "NULL"
83   cached open
84 search_find: file="NULL"
85   key="select * from them where id='filter';" partial=-1 affix=NULL starflags=0
86 LRU list:
87 internal_search_find: file="NULL"
88   type=mysql key="select * from them where id='filter';"
89 database lookup required for select * from them where id='filter';
90 MySQL query: select * from them where id='filter';
91 MYSQL using cached connection for localhost/test/root
92 lookup yielded: id=filter name=filter home=filter mail="#Exim filter
93 deliver postmaster" 
94 search_open: mysql "NULL"
95   cached open
96 search_find: file="NULL"
97   key="select * from them where id='quote2';" partial=-1 affix=NULL starflags=0
98 LRU list:
99 internal_search_find: file="NULL"
100   type=mysql key="select * from them where id='quote2';"
101 database lookup required for select * from them where id='quote2';
102 MySQL query: select * from them where id='quote2';
103 MYSQL using cached connection for localhost/test/root
104 lookup yielded: id=quote2 name="\"qnosp" home=/home/q2 mail="" 
105 search_open: mysql "NULL"
106   cached open
107 search_find: file="NULL"
108   key="select * from them where id='nlonly';" partial=-1 affix=NULL starflags=0
109 LRU list:
110 internal_search_find: file="NULL"
111   type=mysql key="select * from them where id='nlonly';"
112 database lookup required for select * from them where id='nlonly';
113 MySQL query: select * from them where id='nlonly';
114 MYSQL using cached connection for localhost/test/root
115 lookup yielded: id=nlonly name=filter home=filter mail="Before
116 After" 
117 search_open: mysql "NULL"
118   cached open
119 search_find: file="NULL"
120   key="servers=x:localhost; select name from them where id='CALLER';" partial=-1 affix=NULL starflags=0
121 LRU list:
122 internal_search_find: file="NULL"
123   type=mysql key="servers=x:localhost; select name from them where id='CALLER';"
124 database lookup required for servers=x:localhost; select name from them where id='CALLER';
125 MySQL query: servers=x:localhost; select name from them where id='CALLER';
126 lookup deferred: MySQL server "x" not found in mysql_servers
127 search_open: mysql "NULL"
128   cached open
129 search_find: file="NULL"
130   key="servers=localhost:x; select name from them where id='CALLER';" partial=-1 affix=NULL starflags=0
131 LRU list:
132 internal_search_find: file="NULL"
133   type=mysql key="servers=localhost:x; select name from them where id='CALLER';"
134 database lookup required for servers=localhost:x; select name from them where id='CALLER';
135 MySQL query: servers=localhost:x; select name from them where id='CALLER';
136 MYSQL using cached connection for localhost/test/root
137 lookup yielded: Philip Hazel
138 search_open: mysql "NULL"
139   cached open
140 search_find: file="NULL"
141   key="servers=localhost/test/root/:x; select name from them where id='CALLER';" partial=-1 affix=NULL starflags=0
142 LRU list:
143 internal_search_find: file="NULL"
144   type=mysql key="servers=localhost/test/root/:x; select name from them where id='CALLER';"
145 database lookup required for servers=localhost/test/root/:x; select name from them where id='CALLER';
146 MySQL query: servers=localhost/test/root/:x; select name from them where id='CALLER';
147 MYSQL using cached connection for localhost/test/root
148 lookup yielded: Philip Hazel
149 search_open: mysql "NULL"
150   cached open
151 search_find: file="NULL"
152   key="servers=HOST_IPV4/test/root/:localhost; select name from them where id='CALLER';" partial=-1 affix=NULL starflags=0
153 LRU list:
154 internal_search_find: file="NULL"
155   type=mysql key="servers=HOST_IPV4/test/root/:localhost; select name from them where id='CALLER';"
156 database lookup required for servers=HOST_IPV4/test/root/:localhost; select name from them where id='CALLER';
157 MySQL query: servers=HOST_IPV4/test/root/:localhost; select name from them where id='CALLER';
158 MYSQL new connection: host=HOST_IPV4 port=0 socket=NULL database=test user=root
159 MYSQL connection failed: Unknown MySQL server host 'HOST_IPV4' (1)
160 MYSQL using cached connection for localhost/test/root
161 lookup yielded: Philip Hazel
162 search_tidyup called
163 close MYSQL connection: localhost/test/root
164 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
165 Exim version x.yz ....
166 changed uid/gid: forcing real = effective
167   uid=uuuu gid=CALLER_GID pid=pppp
168 configuration file is TESTSUITE/test-config
169 admin user
170 changed uid/gid: privilege not needed
171   uid=EXIM_UID gid=EXIM_GID pid=pppp
172 seeking password data for user "CALLER": cache not available
173 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
174 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
175 sender address = CALLER@myhost.test.ex
176 sender_fullhost = [10.0.0.0]
177 sender_rcvhost = [10.0.0.0]
178 host in hosts_connection_nolog? no (option unset)
179 LOG: smtp_connection MAIN
180   SMTP connection from [10.0.0.0]
181 host in host_lookup? no (option unset)
182 set_process_info: pppp handling incoming connection from [10.0.0.0]
183 host in host_reject_connection? no (option unset)
184 host in sender_unqualified_hosts? no (option unset)
185 host in recipient_unqualified_hosts? no (option unset)
186 host in helo_verify_hosts? no (option unset)
187 host in helo_try_verify_hosts? no (option unset)
188 host in helo_accept_junk_hosts? no (option unset)
189 SMTP>> 220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000
190 smtp_setup_msg entered
191 SMTP<< mail from:<a@b>
192 SMTP>> 250 OK
193 SMTP<< rcpt to:<c@d>
194 using ACL "check_recipient"
195 processing "accept"
196 check domains = +local_domains
197 d in "@"? no (end of list)
198 d in "+local_domains"? no (end of list)
199 accept: condition test failed
200 processing "accept"
201 check hosts = +relay_hosts
202 search_open: mysql "NULL"
203 search_find: file="NULL"
204   key="select * from them where id='10.0.0.0'" partial=-1 affix=NULL starflags=0
205 LRU list:
206 internal_search_find: file="NULL"
207   type=mysql key="select * from them where id='10.0.0.0'"
208 database lookup required for select * from them where id='10.0.0.0'
209 MySQL query: select * from them where id='10.0.0.0'
210 MYSQL new connection: host=localhost port=0 socket=NULL database=test user=root
211 MYSQL: no data found
212 lookup failed
213 host in "net-mysql;select * from them where id='10.0.0.0'"? no (end of list)
214 host in "+relay_hosts"? no (end of list)
215 accept: condition test failed
216 processing "deny"
217 deny: condition test succeeded
218 SMTP>> 550 relay not permitted
219 LOG: MAIN REJECT
220   H=[10.0.0.0] F=<a@b> rejected RCPT <c@d>: relay not permitted
221 SMTP<< quit
222 SMTP>> 221 myhost.test.ex closing connection
223 LOG: smtp_connection MAIN
224   SMTP connection from [10.0.0.0] closed by QUIT
225 search_tidyup called
226 close MYSQL connection: localhost/test/root
227 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
228 Exim version x.yz ....
229 changed uid/gid: forcing real = effective
230   uid=uuuu gid=CALLER_GID pid=pppp
231 configuration file is TESTSUITE/test-config
232 admin user
233 changed uid/gid: privilege not needed
234   uid=EXIM_UID gid=EXIM_GID pid=pppp
235 seeking password data for user "CALLER": cache not available
236 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
237 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
238 sender address = CALLER@myhost.test.ex
239 set_process_info: pppp accepting a local non-SMTP message from <CALLER@myhost.test.ex>
240 Sender: CALLER@myhost.test.ex
241 Recipients:
242   CALLER
243 search_tidyup called
244 >>Headers received:
245
246 rewrite_one_header: type=F:
247   From: CALLER_NAME <CALLER@myhost.test.ex>
248 search_tidyup called
249 >>Headers after rewriting and local additions:
250 I Message-Id: <E10HmaX-0005vi-00@myhost.test.ex>
251 F From: CALLER_NAME <CALLER@myhost.test.ex>
252   Date: Tue, 2 Mar 1999 09:44:33 +0000
253
254 Data file written for message 10HmaX-0005vi-00
255 >>Generated Received: header line
256 P Received: from CALLER by myhost.test.ex with local (Exim x.yz)
257         (envelope-from <CALLER@myhost.test.ex>)
258         id 10HmaX-0005vi-00
259         for CALLER@myhost.test.ex; Tue, 2 Mar 1999 09:44:33 +0000
260 calling local_scan(); timeout=300
261 local_scan() returned 0 NULL
262 Writing spool header file
263 Size of headers = sss
264 LOG: MAIN
265   <= CALLER@myhost.test.ex U=CALLER P=local S=sss
266 created log directory TESTSUITE/spool/log
267 search_tidyup called
268 exec TESTSUITE/eximdir/exim -DEXIM_PATH=TESTSUITE/eximdir/exim -C TESTSUITE/test-config -d=0xfbb95cfd -odi -Mc 10HmaX-0005vi-00
269 Exim version x.yz ....
270 changed uid/gid: forcing real = effective
271   uid=uuuu gid=EXIM_GID pid=pppp
272 configuration file is TESTSUITE/test-config
273 trusted user
274 admin user
275 skipping ACL configuration - not needed
276 seeking password data for user "CALLER": cache not available
277 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
278 set_process_info: pppp delivering specified messages
279 set_process_info: pppp delivering 10HmaX-0005vi-00
280 reading spool file 10HmaX-0005vi-00-H
281 user=CALLER uid=CALLER_UID gid=CALLER_GID sender=CALLER@myhost.test.ex
282 sender_local=1 ident=CALLER
283 Non-recipients:
284 Empty Tree
285 ---- End of tree ----
286 recipients_count=1
287 body_linecount=1 message_linecount=7
288 Delivery address list:
289   CALLER@myhost.test.ex 
290 locking TESTSUITE/spool/db/retry.lockfile
291 locked TESTSUITE/spool/db/retry.lockfile
292 EXIM_DBOPEN(TESTSUITE/spool/db/retry)
293 returned from EXIM_DBOPEN
294 ensuring TESTSUITE/spool/db/retry.lockfile is owned by exim
295 no retry data available
296 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
297 Considering: CALLER@myhost.test.ex
298 unique = CALLER@myhost.test.ex
299 no domain retry record
300 no address retry record
301 CALLER@myhost.test.ex: queued for routing
302 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
303 routing CALLER@myhost.test.ex
304 --------> r1 router <--------
305 local_part=CALLER domain=myhost.test.ex
306 processing address_data
307 search_open: mysql "NULL"
308 search_find: file="NULL"
309   key="select name from them where id='CALLER'" partial=-1 affix=NULL starflags=0
310 LRU list:
311 internal_search_find: file="NULL"
312   type=mysql key="select name from them where id='CALLER'"
313 database lookup required for select name from them where id='CALLER'
314 MySQL query: select name from them where id='CALLER'
315 MYSQL new connection: host=localhost port=0 socket=NULL database=test user=root
316 lookup yielded: Philip Hazel
317 calling r1 router
318 r1 router called for CALLER@myhost.test.ex
319   domain = myhost.test.ex
320 set transport t1
321 queued for t1 transport: local_part = CALLER
322 domain = myhost.test.ex
323   errors_to=NULL
324   domain_data=NULL localpart_data=NULL
325 routed by r1 router
326   envelope to: CALLER@myhost.test.ex
327   transport: t1
328 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
329 After routing:
330   Local deliveries:
331     CALLER@myhost.test.ex
332   Remote deliveries:
333   Failed addresses:
334   Deferred addresses:
335 search_tidyup called
336 close MYSQL connection: localhost/test/root
337 >>>>>>>>>>>>>>>> Local deliveries >>>>>>>>>>>>>>>>
338 --------> CALLER@myhost.test.ex <--------
339 locking TESTSUITE/spool/db/retry.lockfile
340 locked TESTSUITE/spool/db/retry.lockfile
341 EXIM_DBOPEN(TESTSUITE/spool/db/retry)
342 returned from EXIM_DBOPEN
343 no retry data available
344 search_tidyup called
345 changed uid/gid: local delivery to CALLER <CALLER@myhost.test.ex> transport=t1
346   uid=CALLER_UID gid=CALLER_GID pid=pppp
347   home=NULL current=/
348 set_process_info: pppp delivering 10HmaX-0005vi-00 to CALLER using t1
349 appendfile transport entered
350 search_open: mysql "NULL"
351 search_find: file="NULL"
352   key="select id from them where id='CALLER'" partial=-1 affix=NULL starflags=0
353 LRU list:
354 internal_search_find: file="NULL"
355   type=mysql key="select id from them where id='CALLER'"
356 database lookup required for select id from them where id='CALLER'
357 MySQL query: select id from them where id='CALLER'
358 MYSQL new connection: host=localhost port=0 socket=NULL database=test user=root
359 lookup yielded: CALLER
360 appendfile: mode=600 notify_comsat=0 quota=0 warning=0
361   file=TESTSUITE/test-mail/CALLER format=unix
362   message_prefix=From ${if def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}\n
363   message_suffix=\n
364   maildir_use_size_file=no
365   locking by lockfile fcntl 
366 lock name: TESTSUITE/test-mail/CALLER.lock
367 hitch name: TESTSUITE/test-mail/CALLER.lock.test.ex.dddddddd.pppppppp
368 lock file created
369 mailbox TESTSUITE/test-mail/CALLER is locked
370 writing to file TESTSUITE/test-mail/CALLER
371 writing data block fd=dddd size=sss timeout=0
372 writing data block fd=dddd size=sss timeout=0
373 writing data block fd=dddd size=sss timeout=0
374 appendfile yields 0 with errno=dd more_errno=dd
375 search_tidyup called
376 close MYSQL connection: localhost/test/root
377 journalling CALLER@myhost.test.ex
378 t1 transport returned OK for CALLER@myhost.test.ex
379 post-process CALLER@myhost.test.ex (0)
380 CALLER@myhost.test.ex delivered
381 LOG: MAIN
382   => CALLER <CALLER@myhost.test.ex> R=r1 T=t1
383 >>>>>>>>>>>>>>>> deliveries are done >>>>>>>>>>>>>>>>
384 changed uid/gid: post-delivery tidying
385   uid=EXIM_UID gid=EXIM_GID pid=pppp
386 set_process_info: pppp tidying up after delivering 10HmaX-0005vi-00
387 Processing retry items
388 Succeeded addresses:
389 CALLER@myhost.test.ex: no retry items
390 Failed addresses:
391 Deferred addresses:
392 end of retry processing
393 LOG: MAIN
394   Completed
395 end delivery of 10HmaX-0005vi-00
396 search_tidyup called
397 search_tidyup called
398 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
399 search_tidyup called
400 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>