Testsuite: tweak pgsql testcase
[exim.git] / test / stderr / 2620
1
2 WARNING: enabling "trust" authentication for local connections
3 You can change this by editing pg_hba.conf or using the option -A, or
4 --auth-local and --auth-host, the next time you run initdb.
5 Exim version x.yz ....
6 configuration file is TESTSUITE/test-config
7 admin user
8 dropping to exim gid; retaining priv uid
9  search_open: pgsql "NULL"
10  search_find: file="NULL"
11    key="select name from them where id='ph10';" partial=-1 affix=NULL starflags=0 opts=NULL
12  LRU list:
13  internal_search_find: file="NULL"
14    type=pgsql key="select name from them where id='ph10';" opts=NULL
15  database lookup required for select name from them where id='ph10';
16  PostgreSQL query: "select name from them where id='ph10';" opts 'NULL'
17  PGSQL new connection: host=localhost port=PORT_N database=test user=CALLER
18  creating new cache entry
19  lookup yielded: Philip Hazel
20  search_open: pgsql "NULL"
21    cached open
22  search_find: file="NULL"
23    key="select name from them where id='ph10';" partial=-1 affix=NULL starflags=0 opts=NULL
24  LRU list:
25  internal_search_find: file="NULL"
26    type=pgsql key="select name from them where id='ph10';" opts=NULL
27  cached data used for lookup of select name from them where id='ph10';
28  lookup yielded: Philip Hazel
29  search_open: pgsql "NULL"
30    cached open
31  search_find: file="NULL"
32    key="select name from them where id='xxxx';" partial=-1 affix=NULL starflags=0 opts=NULL
33  LRU list:
34  internal_search_find: file="NULL"
35    type=pgsql key="select name from them where id='xxxx';" opts=NULL
36  database lookup required for select name from them where id='xxxx';
37  PostgreSQL query: "select name from them where id='xxxx';" opts 'NULL'
38  PGSQL using cached connection for localhost:PORT_N/test/CALLER
39  PGSQL: no data found
40  creating new cache entry
41  lookup failed
42  search_open: pgsql "NULL"
43    cached open
44  search_find: file="NULL"
45    key="select name from them where id='nothing';" partial=-1 affix=NULL starflags=0 opts=NULL
46  LRU list:
47  internal_search_find: file="NULL"
48    type=pgsql key="select name from them where id='nothing';" opts=NULL
49  database lookup required for select name from them where id='nothing';
50  PostgreSQL query: "select name from them where id='nothing';" opts 'NULL'
51  PGSQL using cached connection for localhost:PORT_N/test/CALLER
52  creating new cache entry
53  lookup yielded: 
54  search_open: pgsql "NULL"
55    cached open
56  search_find: file="NULL"
57    key="select id,name from them where id='nothing';" partial=-1 affix=NULL starflags=0 opts=NULL
58  LRU list:
59  internal_search_find: file="NULL"
60    type=pgsql key="select id,name from them where id='nothing';" opts=NULL
61  database lookup required for select id,name from them where id='nothing';
62  PostgreSQL query: "select id,name from them where id='nothing';" opts 'NULL'
63  PGSQL using cached connection for localhost:PORT_N/test/CALLER
64  creating new cache entry
65  lookup yielded: id=nothing name="" 
66  search_open: pgsql "NULL"
67    cached open
68  search_find: file="NULL"
69    key="delete from them where id='nonexist';" partial=-1 affix=NULL starflags=0 opts=NULL
70  LRU list:
71  internal_search_find: file="NULL"
72    type=pgsql key="delete from them where id='nonexist';" opts=NULL
73  database lookup required for delete from them where id='nonexist';
74  PostgreSQL query: "delete from them where id='nonexist';" opts 'NULL'
75  PGSQL using cached connection for localhost:PORT_N/test/CALLER
76  PGSQL: command does not return any data but was successful. Rows affected: 0
77  lookup forced cache cleanup
78  lookup yielded: 0
79  search_open: pgsql "NULL"
80    cached open
81  search_find: file="NULL"
82    key="select * from them where id='quote2';" partial=-1 affix=NULL starflags=0 opts=NULL
83  LRU list:
84  internal_search_find: file="NULL"
85    type=pgsql key="select * from them where id='quote2';" opts=NULL
86  database lookup required for select * from them where id='quote2';
87  PostgreSQL query: "select * from them where id='quote2';" opts 'NULL'
88  PGSQL using cached connection for localhost:PORT_N/test/CALLER
89  creating new cache entry
90  lookup yielded: name="\"stquot" id=quote2 
91  search_open: pgsql "NULL"
92    cached open
93  search_find: file="NULL"
94    key="select * from them where id='newline';" partial=-1 affix=NULL starflags=0 opts=NULL
95  LRU list:
96  internal_search_find: file="NULL"
97    type=pgsql key="select * from them where id='newline';" opts=NULL
98  database lookup required for select * from them where id='newline';
99  PostgreSQL query: "select * from them where id='newline';" opts 'NULL'
100  PGSQL using cached connection for localhost:PORT_N/test/CALLER
101  creating new cache entry
102  lookup yielded: name="before\r
103  after" id=newline 
104  search_open: pgsql "NULL"
105    cached open
106  search_find: file="NULL"
107    key="select * from them where id='tab';" partial=-1 affix=NULL starflags=0 opts=NULL
108  LRU list:
109  internal_search_find: file="NULL"
110    type=pgsql key="select * from them where id='tab';" opts=NULL
111  database lookup required for select * from them where id='tab';
112  PostgreSQL query: "select * from them where id='tab';" opts 'NULL'
113  PGSQL using cached connection for localhost:PORT_N/test/CALLER
114  creating new cache entry
115  lookup yielded: name="x        x" id=tab 
116  search_open: pgsql "NULL"
117    cached open
118  search_find: file="NULL"
119    key="select * from them where name='''stquot';" partial=-1 affix=NULL starflags=0 opts=NULL
120  LRU list:
121  internal_search_find: file="NULL"
122    type=pgsql key="select * from them where name='''stquot';" opts=NULL
123  database lookup required for select * from them where name='''stquot';
124  PostgreSQL query: "select * from them where name='''stquot';" opts 'NULL'
125  PGSQL using cached connection for localhost:PORT_N/test/CALLER
126  creating new cache entry
127  lookup yielded: name='stquot id=quote1 
128  search_open: pgsql "NULL"
129    cached open
130  search_find: file="NULL"
131    key="servers=x:localhost; select name from them where id='ph10';" partial=-1 affix=NULL starflags=0 opts=NULL
132  LRU list:
133  internal_search_find: file="NULL"
134    type=pgsql key="servers=x:localhost; select name from them where id='ph10';" opts=NULL
135  database lookup required for servers=x:localhost; select name from them where id='ph10';
136  PostgreSQL query: "servers=x:localhost; select name from them where id='ph10';" opts 'NULL'
137  lookup deferred: PostgreSQL server "x" not found in pgsql_servers
138  search_open: pgsql "NULL"
139    cached open
140  search_find: file="NULL"
141    key="servers=localhost::PORT_N:x; select name from them where id='ph10';" partial=-1 affix=NULL starflags=0 opts=NULL
142  LRU list:
143  internal_search_find: file="NULL"
144    type=pgsql key="servers=localhost::PORT_N:x; select name from them where id='ph10';" opts=NULL
145  database lookup required for servers=localhost::PORT_N:x; select name from them where id='ph10';
146  PostgreSQL query: "servers=localhost::PORT_N:x; select name from them where id='ph10';" opts 'NULL'
147  PGSQL using cached connection for localhost:PORT_N/test/CALLER
148  creating new cache entry
149  lookup yielded: Philip Hazel
150  search_open: pgsql "NULL"
151    cached open
152  search_find: file="NULL"
153    key="servers=localhost::PORT_N/test/CALLER/:x; select name from them where id='ph10';" partial=-1 affix=NULL starflags=0 opts=NULL
154  LRU list:
155  internal_search_find: file="NULL"
156    type=pgsql key="servers=localhost::PORT_N/test/CALLER/:x; select name from them where id='ph10';" opts=NULL
157  database lookup required for servers=localhost::PORT_N/test/CALLER/:x; select name from them where id='ph10';
158  PostgreSQL query: "servers=localhost::PORT_N/test/CALLER/:x; select name from them where id='ph10';" opts 'NULL'
159  PGSQL using cached connection for localhost:PORT_N/test/CALLER
160  creating new cache entry
161  lookup yielded: Philip Hazel
162  search_open: pgsql "NULL"
163    cached open
164  search_find: file="NULL"
165    key="servers=(TESTSUITE/pgsql/.s.PGSQL.1223)/test/CALLER/:x; select name from them where id='ph10';" partial=-1 affix=NULL starflags=0 opts=NULL
166  LRU list:
167  internal_search_find: file="NULL"
168    type=pgsql key="servers=(TESTSUITE/pgsql/.s.PGSQL.1223)/test/CALLER/:x; select name from them where id='ph10';" opts=NULL
169  database lookup required for servers=(TESTSUITE/pgsql/.s.PGSQL.1223)/test/CALLER/:x; select name from them where id='ph10';
170  PostgreSQL query: "servers=(TESTSUITE/pgsql/.s.PGSQL.1223)/test/CALLER/:x; select name from them where id='ph10';" opts 'NULL'
171  PGSQL new connection: socket=TESTSUITE/pgsql/.s.PGSQL.1223 database=test user=CALLER
172  creating new cache entry
173  lookup yielded: Philip Hazel
174  search_open: pgsql "NULL"
175    cached open
176  search_find: file="NULL"
177    key="SELECT name FROM them WHERE id IN ('ph10', 'aaaa');" partial=-1 affix=NULL starflags=0 opts=NULL
178  LRU list:
179  internal_search_find: file="NULL"
180    type=pgsql key="SELECT name FROM them WHERE id IN ('ph10', 'aaaa');" opts=NULL
181  database lookup required for SELECT name FROM them WHERE id IN ('ph10', 'aaaa');
182  PostgreSQL query: "SELECT name FROM them WHERE id IN ('ph10', 'aaaa');" opts 'NULL'
183  PGSQL using cached connection for localhost:PORT_N/test/CALLER
184  creating new cache entry
185  lookup yielded: Philip Hazel
186  Aristotle
187  search_open: pgsql "NULL"
188    cached open
189  search_find: file="NULL"
190    key="SELECT *    FROM them WHERE id IN ('ph10', 'aaaa');" partial=-1 affix=NULL starflags=0 opts=NULL
191  LRU list:
192  internal_search_find: file="NULL"
193    type=pgsql key="SELECT *    FROM them WHERE id IN ('ph10', 'aaaa');" opts=NULL
194  database lookup required for SELECT *    FROM them WHERE id IN ('ph10', 'aaaa');
195  PostgreSQL query: "SELECT *    FROM them WHERE id IN ('ph10', 'aaaa');" opts 'NULL'
196  PGSQL using cached connection for localhost:PORT_N/test/CALLER
197  creating new cache entry
198  lookup yielded: name="Philip Hazel" id=ph10 
199  name=Aristotle id=aaaa 
200  search_open: pgsql "NULL"
201    cached open
202  search_find: file="NULL"
203    key="delete from them where id='aaaa'" partial=-1 affix=NULL starflags=0 opts=NULL
204  LRU list:
205  internal_search_find: file="NULL"
206    type=pgsql key="delete from them where id='aaaa'" opts=NULL
207  database lookup required for delete from them where id='aaaa'
208  PostgreSQL query: "delete from them where id='aaaa'" opts 'NULL'
209  PGSQL using cached connection for localhost:PORT_N/test/CALLER
210  PGSQL: command does not return any data but was successful. Rows affected: 1
211  lookup forced cache cleanup
212  lookup yielded: 1
213 search_tidyup called
214 close PGSQL connection: (TESTSUITE/pgsql/.s.PGSQL.1223)/test/CALLER
215 close PGSQL connection: localhost:PORT_N/test/CALLER
216 >>>>>>>>>>>>>>>> Exim pid=p1235 (fresh-exec) terminating with rc=0 >>>>>>>>>>>>>>>>
217 Exim version x.yz ....
218 changed uid/gid: forcing real = effective
219   uid=uuuu gid=CALLER_GID pid=p1236
220 configuration file is TESTSUITE/test-config
221 admin user
222 changed uid/gid: privilege not needed
223   uid=EXIM_UID gid=EXIM_GID pid=p1236
224 seeking password data for user "CALLER": cache not available
225 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
226 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
227 sender address = CALLER@myhost.test.ex
228 sender_fullhost = [10.0.0.0]
229 sender_rcvhost = [10.0.0.0]
230 host in hosts_connection_nolog? no (option unset)
231 LOG: smtp_connection MAIN
232   SMTP connection from [10.0.0.0]
233 host in host_lookup? no (option unset)
234 set_process_info: pppp handling incoming connection from [10.0.0.0]
235 host in host_reject_connection? no (option unset)
236 host in sender_unqualified_hosts? no (option unset)
237 host in recipient_unqualified_hosts? no (option unset)
238 host in helo_verify_hosts? no (option unset)
239 host in helo_try_verify_hosts? no (option unset)
240 host in helo_accept_junk_hosts? no (option unset)
241 SMTP>> 220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000
242 smtp_setup_msg entered
243 SMTP<< helo test
244 test in helo_lookup_domains? no (end of list)
245 sender_fullhost = (test) [10.0.0.0]
246 sender_rcvhost = [10.0.0.0] (helo=test)
247 set_process_info: pppp handling incoming connection from (test) [10.0.0.0]
248 SMTP>> 250 myhost.test.ex Hello test [10.0.0.0]
249 SMTP<< mail from:<a@b>
250 spool directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100 msg_size = 0
251 log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
252 SMTP>> 250 OK
253 SMTP<< rcpt to:<c@d>
254 using ACL "check_recipient"
255 processing "warn" (TESTSUITE/test-config 27)
256  search_open: pgsql "NULL"
257  search_find: file="NULL"
258    key="select name from them where id = 'c'" partial=-1 affix=NULL starflags=0 opts=NULL
259  LRU list:
260  internal_search_find: file="NULL"
261    type=pgsql key="select name from them where id = 'c'" opts=NULL
262  database lookup required for select name from them where id = 'c'
263                               (tainted, quoted:pgsql)
264  PostgreSQL query: "select name from them where id = 'c'" opts 'NULL'
265  PGSQL new connection: host=localhost port=PORT_N database=test user=CALLER
266  PGSQL: no data found
267  creating new cache entry
268  lookup failed
269 check set acl_m0 = ok:   ${lookup pgsql                    {select name from them where id = '${quote_pgsql:$local_part}'}}
270                  = ok:   
271  search_open: pgsql "NULL"
272    cached open
273  search_find: file="NULL"
274    key="select name from them where id = 'c'" partial=-1 affix=NULL starflags=0 opts="cache=no_rd"
275  LRU list:
276  internal_search_find: file="NULL"
277    type=pgsql key="select name from them where id = 'c'" opts=NULL
278  cached data found but no_rd option set;  database lookup required for select name from them where id = 'c'
279                               (tainted)
280 LOG: MAIN PANIC
281   tainted search query is not properly quoted (ACL warn, TESTSUITE/test-config 27): select name from them where id = 'c'
282  search_type NN (pgsql) quoting -1 (none)
283  PostgreSQL query: "select name from them where id = 'c'" opts 'NULL'
284  PGSQL using cached connection for localhost:PORT_N/test/CALLER
285  PGSQL: no data found
286  replacing old cache entry
287  lookup failed
288 check set acl_m0 = FAIL: ${lookup pgsql,cache=no_rd        {select name from them where id = '$local_part'}}
289                  = FAIL: 
290 warn: condition test succeeded in ACL "check_recipient"
291 processing "warn" (TESTSUITE/test-config 32)
292  search_open: pgsql "NULL"
293    cached open
294  search_find: file="NULL"
295    key="select name from them where id = 'c'" partial=-1 affix=NULL starflags=0 opts="servers=localhost::PORT_N/test/CALLER/"
296  LRU list:
297  internal_search_find: file="NULL"
298    type=pgsql key="select name from them where id = 'c'" opts="servers=localhost::PORT_N/test/CALLER/"
299  cached data found but wrong opts;  database lookup required for select name from them where id = 'c'
300                               (tainted, quoted:pgsql)
301  PostgreSQL query: "select name from them where id = 'c'" opts 'servers=localhost::PORT_N/test/CALLER/'
302  PGSQL using cached connection for localhost:PORT_N/test/CALLER
303  PGSQL: no data found
304  replacing old cache entry
305  lookup failed
306 check set acl_m0 = ok:   ${lookup pgsql,servers=localhost::PORT_N/test/CALLER/      {select name from them where id = '${quote_pgsql:$local_part}'}}
307                  = ok:   
308  search_open: pgsql "NULL"
309    cached open
310  search_find: file="NULL"
311    key="select name from them where id = 'c'" partial=-1 affix=NULL starflags=0 opts="servers=localhost::PORT_N"
312  LRU list:
313  internal_search_find: file="NULL"
314    type=pgsql key="select name from them where id = 'c'" opts="servers=localhost::PORT_N"
315  cached data found but wrong opts;  database lookup required for select name from them where id = 'c'
316                               (tainted, quoted:pgsql)
317  PostgreSQL query: "select name from them where id = 'c'" opts 'servers=localhost::PORT_N'
318  PGSQL using cached connection for localhost:PORT_N/test/CALLER
319  PGSQL: no data found
320  replacing old cache entry
321  lookup failed
322 check set acl_m0 = ok:   ${lookup pgsql,servers=localhost::PORT_N    {select name from them where id = '${quote_pgsql:$local_part}'}}
323                  = ok:   
324  search_open: pgsql "NULL"
325    cached open
326  search_find: file="NULL"
327    key="servers=localhost::PORT_N/test/CALLER/; select name from them where id = 'c'" partial=-1 affix=NULL starflags=0 opts=NULL
328  LRU list:
329  internal_search_find: file="NULL"
330    type=pgsql key="servers=localhost::PORT_N/test/CALLER/; select name from them where id = 'c'" opts=NULL
331  database lookup required for servers=localhost::PORT_N/test/CALLER/; select name from them where id = 'c'
332                               (tainted, quoted:pgsql)
333  PostgreSQL query: "servers=localhost::PORT_N/test/CALLER/; select name from them where id = 'c'" opts 'NULL'
334  lookup deferred: PostgreSQL server "localhost:PORT_N/test/CALLER/" is tainted
335 warn: condition test deferred in ACL "check_recipient"
336 LOG: MAIN
337   H=(test) [10.0.0.0] Warning: ACL "warn" statement skipped: condition test deferred: PostgreSQL server "localhost:PORT_N/test/CALLER/" is tainted
338 processing "warn" (TESTSUITE/test-config 41)
339 check set acl_m0 = ok:   hostlist
340 check hosts = net-pgsql;select * from them where id='${quote_pgsql:$local_part}'
341 search_open: pgsql "NULL"
342   cached open
343 search_find: file="NULL"
344   key="select * from them where id='c'" partial=-1 affix=NULL starflags=0 opts=NULL
345 LRU list:
346 internal_search_find: file="NULL"
347   type=pgsql key="select * from them where id='c'" opts=NULL
348 database lookup required for select * from them where id='c'
349                              (tainted, quoted:pgsql)
350 PostgreSQL query: "select * from them where id='c'" opts 'NULL'
351 PGSQL using cached connection for localhost:PORT_N/test/CALLER
352 PGSQL: no data found
353 creating new cache entry
354 lookup failed
355 host in "net-pgsql;select * from them where id='c'"? no (end of list)
356 warn: condition test failed in ACL "check_recipient"
357 processing "warn" (TESTSUITE/test-config 44)
358 check set acl_m0 = FAIL: hostlist
359 check hosts = <& net-pgsql;servers=localhost::PORT_N/test/CALLER/; select * from them where id='${quote_pgsql:$local_part}'
360 search_open: pgsql "NULL"
361   cached open
362 search_find: file="NULL"
363   key="servers=localhost::PORT_N/test/CALLER/; select * from them where id='c'" partial=-1 affix=NULL starflags=0 opts=NULL
364 LRU list:
365 internal_search_find: file="NULL"
366   type=pgsql key="servers=localhost::PORT_N/test/CALLER/; select * from them where id='c'" opts=NULL
367 database lookup required for servers=localhost::PORT_N/test/CALLER/; select * from them where id='c'
368                              (tainted, quoted:pgsql)
369 PostgreSQL query: "servers=localhost::PORT_N/test/CALLER/; select * from them where id='c'" opts 'NULL'
370 lookup deferred: PostgreSQL server "localhost:PORT_N/test/CALLER/" is tainted
371 host in "<& net-pgsql;servers=localhost::PORT_N/test/CALLER/; select * from them where id='c'"? list match deferred for net-pgsql;servers=localhost::1223/test/CALLER/; select * from them where id='c'
372 warn: condition test deferred in ACL "check_recipient"
373 LOG: MAIN
374   H=(test) [10.0.0.0] Warning: ACL "warn" statement skipped: condition test deferred: PostgreSQL server "localhost:PORT_N/test/CALLER/" is tainted
375 processing "warn" (TESTSUITE/test-config 49)
376 check set acl_m0 = FAIL: hostlist
377 check hosts = <& net-pgsql,servers=localhost::PORT_N/test/CALLER/; select * from them where id='${quote_pgsql:$local_part}'
378 search_open: pgsql "NULL"
379   cached open
380 search_find: file="NULL"
381   key=" select * from them where id='c'" partial=-1 affix=NULL starflags=0 opts="servers=localhost::PORT_N/test/CALLER/"
382 LRU list:
383 internal_search_find: file="NULL"
384   type=pgsql key=" select * from them where id='c'" opts="servers=localhost::PORT_N/test/CALLER/"
385 database lookup required for  select * from them where id='c'
386                              (tainted, quoted:pgsql)
387 PostgreSQL query: " select * from them where id='c'" opts 'servers=localhost::PORT_N/test/CALLER/'
388 lookup deferred: PostgreSQL server "localhost:PORT_N/test/CALLER/" is tainted
389 host in "<& net-pgsql,servers=localhost::PORT_N/test/CALLER/; select * from them where id='c'"? list match deferred for net-pgsql,servers=localhost::1223/test/CALLER/; select * from them where id='c'
390 warn: condition test deferred in ACL "check_recipient"
391 LOG: MAIN
392   H=(test) [10.0.0.0] Warning: ACL "warn" statement skipped: condition test deferred: PostgreSQL server "localhost:PORT_N/test/CALLER/" is tainted
393 processing "accept" (TESTSUITE/test-config 52)
394 check domains = +local_domains
395 d in "@"? no (end of list)
396 d in "+local_domains"? no (end of list)
397 accept: condition test failed in ACL "check_recipient"
398 processing "accept" (TESTSUITE/test-config 53)
399 check hosts = +relay_hosts
400 search_open: pgsql "NULL"
401   cached open
402 search_find: file="NULL"
403   key="select * from them where id='10.0.0.0'" partial=-1 affix=NULL starflags=0 opts=NULL
404 LRU list:
405 internal_search_find: file="NULL"
406   type=pgsql key="select * from them where id='10.0.0.0'" opts=NULL
407 database lookup required for select * from them where id='10.0.0.0'
408 PostgreSQL query: "select * from them where id='10.0.0.0'" opts 'NULL'
409 PGSQL using cached connection for localhost:PORT_N/test/CALLER
410 PGSQL: no data found
411 creating new cache entry
412 lookup failed
413 host in "net-pgsql;select * from them where id='10.0.0.0'"? no (end of list)
414 host in "+relay_hosts"? no (end of list)
415 accept: condition test failed in ACL "check_recipient"
416 processing "deny" (TESTSUITE/test-config 54)
417   message: relay not permitted
418 deny: condition test succeeded in ACL "check_recipient"
419 end of ACL "check_recipient": DENY
420 SMTP>> 550 relay not permitted
421 LOG: MAIN REJECT
422   H=(test) [10.0.0.0] F=<a@b> rejected RCPT <c@d>: relay not permitted
423 SMTP<< rcpt to:<c@d>
424 using ACL "check_recipient"
425 processing "warn" (TESTSUITE/test-config 27)
426  search_open: pgsql "NULL"
427    cached open
428  search_find: file="NULL"
429    key="select name from them where id = 'c'" partial=-1 affix=NULL starflags=0 opts=NULL
430  LRU list:
431  internal_search_find: file="NULL"
432    type=pgsql key="select name from them where id = 'c'" opts=NULL
433  cached data found but wrong opts;  database lookup required for select name from them where id = 'c'
434                               (tainted, quoted:pgsql)
435  PostgreSQL query: "select name from them where id = 'c'" opts 'NULL'
436  PGSQL using cached connection for localhost:PORT_N/test/CALLER
437  PGSQL: no data found
438  replacing old cache entry
439  lookup failed
440 check set acl_m0 = ok:   ${lookup pgsql                    {select name from them where id = '${quote_pgsql:$local_part}'}}
441                  = ok:   
442  search_open: pgsql "NULL"
443    cached open
444  search_find: file="NULL"
445    key="select name from them where id = 'c'" partial=-1 affix=NULL starflags=0 opts="cache=no_rd"
446  LRU list:
447  internal_search_find: file="NULL"
448    type=pgsql key="select name from them where id = 'c'" opts=NULL
449  cached data found but no_rd option set;  database lookup required for select name from them where id = 'c'
450                               (tainted)
451 LOG: MAIN PANIC
452   tainted search query is not properly quoted (ACL warn, TESTSUITE/test-config 27): select name from them where id = 'c'
453  search_type NN (pgsql) quoting -1 (none)
454  PostgreSQL query: "select name from them where id = 'c'" opts 'NULL'
455  PGSQL using cached connection for localhost:PORT_N/test/CALLER
456  PGSQL: no data found
457  replacing old cache entry
458  lookup failed
459 check set acl_m0 = FAIL: ${lookup pgsql,cache=no_rd        {select name from them where id = '$local_part'}}
460                  = FAIL: 
461 warn: condition test succeeded in ACL "check_recipient"
462 processing "warn" (TESTSUITE/test-config 32)
463  search_open: pgsql "NULL"
464    cached open
465  search_find: file="NULL"
466    key="select name from them where id = 'c'" partial=-1 affix=NULL starflags=0 opts="servers=localhost::PORT_N/test/CALLER/"
467  LRU list:
468  internal_search_find: file="NULL"
469    type=pgsql key="select name from them where id = 'c'" opts="servers=localhost::PORT_N/test/CALLER/"
470  cached data found but wrong opts;  database lookup required for select name from them where id = 'c'
471                               (tainted, quoted:pgsql)
472  PostgreSQL query: "select name from them where id = 'c'" opts 'servers=localhost::PORT_N/test/CALLER/'
473  PGSQL using cached connection for localhost:PORT_N/test/CALLER
474  PGSQL: no data found
475  replacing old cache entry
476  lookup failed
477 check set acl_m0 = ok:   ${lookup pgsql,servers=localhost::PORT_N/test/CALLER/      {select name from them where id = '${quote_pgsql:$local_part}'}}
478                  = ok:   
479  search_open: pgsql "NULL"
480    cached open
481  search_find: file="NULL"
482    key="select name from them where id = 'c'" partial=-1 affix=NULL starflags=0 opts="servers=localhost::PORT_N"
483  LRU list:
484  internal_search_find: file="NULL"
485    type=pgsql key="select name from them where id = 'c'" opts="servers=localhost::PORT_N"
486  cached data found but wrong opts;  database lookup required for select name from them where id = 'c'
487                               (tainted, quoted:pgsql)
488  PostgreSQL query: "select name from them where id = 'c'" opts 'servers=localhost::PORT_N'
489  PGSQL using cached connection for localhost:PORT_N/test/CALLER
490  PGSQL: no data found
491  replacing old cache entry
492  lookup failed
493 check set acl_m0 = ok:   ${lookup pgsql,servers=localhost::PORT_N    {select name from them where id = '${quote_pgsql:$local_part}'}}
494                  = ok:   
495  search_open: pgsql "NULL"
496    cached open
497  search_find: file="NULL"
498    key="servers=localhost::PORT_N/test/CALLER/; select name from them where id = 'c'" partial=-1 affix=NULL starflags=0 opts=NULL
499  LRU list:
500  internal_search_find: file="NULL"
501    type=pgsql key="servers=localhost::PORT_N/test/CALLER/; select name from them where id = 'c'" opts=NULL
502  database lookup required for servers=localhost::PORT_N/test/CALLER/; select name from them where id = 'c'
503                               (tainted, quoted:pgsql)
504  PostgreSQL query: "servers=localhost::PORT_N/test/CALLER/; select name from them where id = 'c'" opts 'NULL'
505  lookup deferred: PostgreSQL server "localhost:PORT_N/test/CALLER/" is tainted
506 warn: condition test deferred in ACL "check_recipient"
507 LOG: MAIN
508   H=(test) [10.0.0.0] Warning: ACL "warn" statement skipped: condition test deferred: PostgreSQL server "localhost:PORT_N/test/CALLER/" is tainted
509 processing "warn" (TESTSUITE/test-config 41)
510 check set acl_m0 = ok:   hostlist
511 check hosts = net-pgsql;select * from them where id='${quote_pgsql:$local_part}'
512 search_open: pgsql "NULL"
513   cached open
514 search_find: file="NULL"
515   key="select * from them where id='c'" partial=-1 affix=NULL starflags=0 opts=NULL
516 LRU list:
517 internal_search_find: file="NULL"
518   type=pgsql key="select * from them where id='c'" opts=NULL
519 cached data used for lookup of select * from them where id='c'
520 lookup failed
521 host in "net-pgsql;select * from them where id='c'"? no (end of list)
522 warn: condition test failed in ACL "check_recipient"
523 processing "warn" (TESTSUITE/test-config 44)
524 check set acl_m0 = FAIL: hostlist
525 check hosts = <& net-pgsql;servers=localhost::PORT_N/test/CALLER/; select * from them where id='${quote_pgsql:$local_part}'
526 search_open: pgsql "NULL"
527   cached open
528 search_find: file="NULL"
529   key="servers=localhost::PORT_N/test/CALLER/; select * from them where id='c'" partial=-1 affix=NULL starflags=0 opts=NULL
530 LRU list:
531 internal_search_find: file="NULL"
532   type=pgsql key="servers=localhost::PORT_N/test/CALLER/; select * from them where id='c'" opts=NULL
533 database lookup required for servers=localhost::PORT_N/test/CALLER/; select * from them where id='c'
534                              (tainted, quoted:pgsql)
535 PostgreSQL query: "servers=localhost::PORT_N/test/CALLER/; select * from them where id='c'" opts 'NULL'
536 lookup deferred: PostgreSQL server "localhost:PORT_N/test/CALLER/" is tainted
537 host in "<& net-pgsql;servers=localhost::PORT_N/test/CALLER/; select * from them where id='c'"? list match deferred for net-pgsql;servers=localhost::1223/test/CALLER/; select * from them where id='c'
538 warn: condition test deferred in ACL "check_recipient"
539 LOG: MAIN
540   H=(test) [10.0.0.0] Warning: ACL "warn" statement skipped: condition test deferred: PostgreSQL server "localhost:PORT_N/test/CALLER/" is tainted
541 processing "warn" (TESTSUITE/test-config 49)
542 check set acl_m0 = FAIL: hostlist
543 check hosts = <& net-pgsql,servers=localhost::PORT_N/test/CALLER/; select * from them where id='${quote_pgsql:$local_part}'
544 search_open: pgsql "NULL"
545   cached open
546 search_find: file="NULL"
547   key=" select * from them where id='c'" partial=-1 affix=NULL starflags=0 opts="servers=localhost::PORT_N/test/CALLER/"
548 LRU list:
549 internal_search_find: file="NULL"
550   type=pgsql key=" select * from them where id='c'" opts="servers=localhost::PORT_N/test/CALLER/"
551 database lookup required for  select * from them where id='c'
552                              (tainted, quoted:pgsql)
553 PostgreSQL query: " select * from them where id='c'" opts 'servers=localhost::PORT_N/test/CALLER/'
554 lookup deferred: PostgreSQL server "localhost:PORT_N/test/CALLER/" is tainted
555 host in "<& net-pgsql,servers=localhost::PORT_N/test/CALLER/; select * from them where id='c'"? list match deferred for net-pgsql,servers=localhost::1223/test/CALLER/; select * from them where id='c'
556 warn: condition test deferred in ACL "check_recipient"
557 LOG: MAIN
558   H=(test) [10.0.0.0] Warning: ACL "warn" statement skipped: condition test deferred: PostgreSQL server "localhost:PORT_N/test/CALLER/" is tainted
559 processing "accept" (TESTSUITE/test-config 52)
560 check domains = +local_domains
561 d in "@"? no (end of list)
562 d in "+local_domains"? no (end of list)
563 accept: condition test failed in ACL "check_recipient"
564 processing "accept" (TESTSUITE/test-config 53)
565 check hosts = +relay_hosts
566 search_open: pgsql "NULL"
567   cached open
568 search_find: file="NULL"
569   key="select * from them where id='10.0.0.0'" partial=-1 affix=NULL starflags=0 opts=NULL
570 LRU list:
571 internal_search_find: file="NULL"
572   type=pgsql key="select * from them where id='10.0.0.0'" opts=NULL
573 cached data used for lookup of select * from them where id='10.0.0.0'
574 lookup failed
575 host in "net-pgsql;select * from them where id='10.0.0.0'"? no (end of list)
576 host in "+relay_hosts"? no (end of list)
577 accept: condition test failed in ACL "check_recipient"
578 processing "deny" (TESTSUITE/test-config 54)
579   message: relay not permitted
580 deny: condition test succeeded in ACL "check_recipient"
581 end of ACL "check_recipient": DENY
582 SMTP>> 550 relay not permitted
583 LOG: MAIN REJECT
584   H=(test) [10.0.0.0] F=<a@b> rejected RCPT <c@d>: relay not permitted
585 SMTP<< quit
586 SMTP>> 221 myhost.test.ex closing connection
587 LOG: smtp_connection MAIN
588   SMTP connection from (test) [10.0.0.0] closed by QUIT
589 search_tidyup called
590 close PGSQL connection: localhost:PORT_N/test/CALLER
591 >>>>>>>>>>>>>>>> Exim pid=p1236 (fresh-exec) terminating with rc=0 >>>>>>>>>>>>>>>>
592 Exim version x.yz ....
593 changed uid/gid: forcing real = effective
594   uid=uuuu gid=CALLER_GID pid=p1237
595 configuration file is TESTSUITE/test-config
596 admin user
597 changed uid/gid: privilege not needed
598   uid=EXIM_UID gid=EXIM_GID pid=p1237
599 seeking password data for user "CALLER": cache not available
600 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
601 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
602 sender address = CALLER@myhost.test.ex
603 set_process_info: pppp accepting a local non-SMTP message from <CALLER@myhost.test.ex>
604 spool directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100 msg_size = 0
605 log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
606 Sender: CALLER@myhost.test.ex
607 Recipients:
608   CALLER
609 search_tidyup called
610 >>Headers received:
611
612 qualify & rewrite recipients list
613 global rewrite rules
614 rewrite headers
615  rewrite_one_header: type=F:
616    From: CALLER_NAME <CALLER@myhost.test.ex>
617 search_tidyup called
618 >>Headers after rewriting and local additions:
619 I Message-Id: <E10HmaX-0005vi-00@myhost.test.ex>
620 F From: CALLER_NAME <CALLER@myhost.test.ex>
621   Date: Tue, 2 Mar 1999 09:44:33 +0000
622
623 Data file name: TESTSUITE/spool//input//10HmaX-0005vi-00-D
624 Data file written for message 10HmaX-0005vi-00
625 >>Generated Received: header line
626 P Received: from CALLER by myhost.test.ex with local (Exim x.yz)
627         (envelope-from <CALLER@myhost.test.ex>)
628         id 10HmaX-0005vi-00
629         for CALLER@myhost.test.ex;
630         Tue, 2 Mar 1999 09:44:33 +0000
631 Writing spool header file: TESTSUITE/spool//input//hdr.10HmaX-0005vi-00
632 DSN: **** SPOOL_OUT - address: <CALLER@myhost.test.ex> errorsto: <NULL> orcpt: <NULL> dsn_flags: 0x0
633 Renaming spool header file: TESTSUITE/spool//input//10HmaX-0005vi-00-H
634 Size of headers = sss
635 LOG: MAIN
636   <= CALLER@myhost.test.ex U=CALLER P=local S=sss
637 created log directory TESTSUITE/spool/log
638 search_tidyup called
639 exec TESTSUITE/eximdir/exim -DEXIM_PATH=TESTSUITE/eximdir/exim -C TESTSUITE/test-config -d=0xf7715cfd -MCd local-accept-delivery -odi -Mc 10HmaX-0005vi-00
640 Exim version x.yz ....
641 changed uid/gid: forcing real = effective
642   uid=uuuu gid=EXIM_GID pid=p1238
643 configuration file is TESTSUITE/test-config
644 trusted user
645 admin user
646 dropping to exim gid; retaining priv uid
647 seeking password data for user "CALLER": cache not available
648 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
649 set_process_info: pppp delivering specified messages
650 set_process_info: pppp delivering 10HmaX-0005vi-00
651 Trying spool file TESTSUITE/spool//input//10HmaX-0005vi-00-D
652 reading spool file 10HmaX-0005vi-00-H
653 user=CALLER uid=CALLER_UID gid=CALLER_GID sender=CALLER@myhost.test.ex
654 sender_local=1 ident=CALLER
655 Non-recipients:
656  Empty Tree
657 ---- End of tree ----
658 recipients_count=1
659 **** SPOOL_IN - No additional fields
660 body_linecount=1 message_linecount=8
661 DSN: set orcpt:   flags: 0x0
662 Delivery address list:
663   CALLER@myhost.test.ex 
664  locking TESTSUITE/spool/db/retry.lockfile
665  locked  TESTSUITE/spool/db/retry.lockfile
666  EXIM_DBOPEN: file <TESTSUITE/spool/db/retry> dir <TESTSUITE/spool/db> flags=O_RDONLY
667  returned from EXIM_DBOPEN: (nil)
668  failed to open DB file TESTSUITE/spool/db/retry: No such file or directory
669 no retry data available
670 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
671 Considering: CALLER@myhost.test.ex
672 unique = CALLER@myhost.test.ex
673 no   domain  retry record
674 no   address retry record
675 CALLER@myhost.test.ex: queued for routing
676 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
677 routing CALLER@myhost.test.ex
678 --------> r1 router <--------
679 local_part=CALLER domain=myhost.test.ex
680 processing address_data
681  search_open: pgsql "NULL"
682  search_find: file="NULL"
683    key="select name from them where id='ph10'" partial=-1 affix=NULL starflags=0 opts=NULL
684  LRU list:
685  internal_search_find: file="NULL"
686    type=pgsql key="select name from them where id='ph10'" opts=NULL
687  database lookup required for select name from them where id='ph10'
688  PostgreSQL query: "select name from them where id='ph10'" opts 'NULL'
689  PGSQL new connection: host=localhost port=PORT_N database=test user=CALLER
690  creating new cache entry
691  lookup yielded: Philip Hazel
692 calling r1 router
693 r1 router called for CALLER@myhost.test.ex
694   domain = myhost.test.ex
695 set transport t1
696 queued for t1 transport: local_part = CALLER
697 domain = myhost.test.ex
698   errors_to=NULL
699   domain_data=NULL local_part_data=NULL
700 routed by r1 router
701   envelope to: CALLER@myhost.test.ex
702   transport: t1
703 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
704 After routing:
705   Local deliveries:
706     CALLER@myhost.test.ex
707   Remote deliveries:
708   Failed addresses:
709   Deferred addresses:
710 search_tidyup called
711 close PGSQL connection: localhost:PORT_N/test/CALLER
712 >>>>>>>>>>>>>>>> Local deliveries >>>>>>>>>>>>>>>>
713 --------> CALLER@myhost.test.ex <--------
714  locking TESTSUITE/spool/db/retry.lockfile
715  locked  TESTSUITE/spool/db/retry.lockfile
716  EXIM_DBOPEN: file <TESTSUITE/spool/db/retry> dir <TESTSUITE/spool/db> flags=O_RDONLY
717  returned from EXIM_DBOPEN: (nil)
718  failed to open DB file TESTSUITE/spool/db/retry: No such file or directory
719 no retry data available
720 search_tidyup called
721 changed uid/gid: local delivery to CALLER <CALLER@myhost.test.ex> transport=t1
722   uid=CALLER_UID gid=CALLER_GID pid=p1239
723   home=NULL current=/
724 set_process_info: pppp delivering 10HmaX-0005vi-00 to CALLER using t1
725 appendfile transport entered
726  search_open: pgsql "NULL"
727  search_find: file="NULL"
728    key="select id from them where id='ph10'" partial=-1 affix=NULL starflags=0 opts=NULL
729  LRU list:
730  internal_search_find: file="NULL"
731    type=pgsql key="select id from them where id='ph10'" opts=NULL
732  database lookup required for select id from them where id='ph10'
733  PostgreSQL query: "select id from them where id='ph10'" opts 'NULL'
734  PGSQL new connection: host=localhost port=PORT_N database=test user=CALLER
735  creating new cache entry
736  lookup yielded: ph10
737 appendfile: mode=600 notify_comsat=0 quota=0 warning=0
738   file=TESTSUITE/test-mail/ph10 format=unix
739   message_prefix=From ${if def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}\n
740   message_suffix=\n
741   maildir_use_size_file=no
742   locking by lockfile fcntl 
743 lock name: TESTSUITE/test-mail/ph10.lock
744 hitch name: TESTSUITE/test-mail/ph10.lock.test.ex.dddddddd.pppppppp
745 lock file created
746 mailbox TESTSUITE/test-mail/ph10 is locked
747 writing to file TESTSUITE/test-mail/ph10
748 writing data block fd=dddd size=sss timeout=0
749 cannot use sendfile for body: spoolfile not wireformat
750 writing data block fd=dddd size=sss timeout=0
751 writing data block fd=dddd size=sss timeout=0
752 appendfile yields 0 with errno=dd more_errno=dd
753 search_tidyup called
754 close PGSQL connection: localhost:PORT_N/test/CALLER
755 journalling CALLER@myhost.test.ex
756 t1 transport returned OK for CALLER@myhost.test.ex
757 post-process CALLER@myhost.test.ex (0)
758 CALLER@myhost.test.ex delivered
759 LOG: MAIN
760   => CALLER <CALLER@myhost.test.ex> R=r1 T=t1
761 >>>>>>>>>>>>>>>> deliveries are done >>>>>>>>>>>>>>>>
762 changed uid/gid: post-delivery tidying
763   uid=EXIM_UID gid=EXIM_GID pid=p1238
764 set_process_info: pppp tidying up after delivering 10HmaX-0005vi-00
765 Processing retry items
766 Succeeded addresses:
767  CALLER@myhost.test.ex: no retry items
768 Failed addresses:
769 Deferred addresses:
770 end of retry processing
771 DSN: processing router : r1
772 DSN: processing successful delivery address: CALLER@myhost.test.ex
773 DSN: Sender_address: CALLER@myhost.test.ex
774 DSN: orcpt: NULL  flags: 0x0
775 DSN: envid: NULL  ret: 0
776 DSN: Final recipient: CALLER@myhost.test.ex
777 DSN: Remote SMTP server supports DSN: 0
778 DSN: not sending DSN success message
779 LOG: MAIN
780   Completed
781 end delivery of 10HmaX-0005vi-00
782 search_tidyup called
783 search_tidyup called
784 >>>>>>>>>>>>>>>> Exim pid=p1238 (local-accept-delivery) terminating with rc=0 >>>>>>>>>>>>>>>>
785 search_tidyup called
786 >>>>>>>>>>>>>>>> Exim pid=p1237 (fresh-exec) terminating with rc=0 >>>>>>>>>>>>>>>>
787 Exim version x.yz ....
788 configuration file is TESTSUITE/test-config
789 admin user
790 dropping to exim gid; retaining priv uid
791  search_open: pgsql "NULL"
792  search_find: file="NULL"
793    key="select name from them where id='ph10';" partial=-1 affix=NULL starflags=0 opts=NULL
794  LRU list:
795  internal_search_find: file="NULL"
796    type=pgsql key="select name from them where id='ph10';" opts=NULL
797  database lookup required for select name from them where id='ph10';
798  PostgreSQL query: "select name from them where id='ph10';" opts 'NULL'
799  PGSQL new connection: socket=TESTSUITE/pgsql/.s.PGSQL.1223 database=test user=CALLER
800  creating new cache entry
801  lookup yielded: Philip Hazel
802 search_tidyup called
803 close PGSQL connection: (TESTSUITE/pgsql/.s.PGSQL.1223)/test/CALLER
804 >>>>>>>>>>>>>>>> Exim pid=p1240 (fresh-exec) terminating with rc=0 >>>>>>>>>>>>>>>>
805
806 ******** SERVER ********
807 2017-07-30 18:51:05.712 BST [pppp] LOG:  redirecting log output to logging collector process
808 2017-07-30 18:51:05.712 BST [pppp] HINT:  Future log output will appear in directory "log".