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