Rewrites: avoid a split log line when rewiting hits a malformed address. Bug 3160
[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?
245  list element: @
246  list element: @[]
247 test in helo_lookup_domains? no (end of list)
248 sender_fullhost = (test) [10.0.0.0]
249 sender_rcvhost = [10.0.0.0] (helo=test)
250 set_process_info: pppp handling incoming connection from (test) [10.0.0.0]
251 SMTP>> 250 myhost.test.ex Hello test [10.0.0.0]
252 SMTP<< mail from:<a@b>
253 spool directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100 msg_size = 0
254 log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
255 SMTP>> 250 OK
256 SMTP<< rcpt to:<c@d>
257 using ACL "check_recipient"
258 processing "warn" (TESTSUITE/test-config 27)
259  search_open: pgsql "NULL"
260  search_find: file="NULL"
261    key="select name from them where id = 'c'" partial=-1 affix=NULL starflags=0 opts=NULL
262  LRU list:
263  internal_search_find: file="NULL"
264    type=pgsql key="select name from them where id = 'c'" opts=NULL
265  database lookup required for select name from them where id = 'c'
266                               (tainted, quoted:pgsql)
267  PostgreSQL query: "select name from them where id = 'c'" opts 'NULL'
268  PGSQL new connection: host=localhost port=PORT_N database=test user=CALLER
269  PGSQL: no data found
270  creating new cache entry
271  lookup failed
272 check set acl_m0 = ok:   ${lookup pgsql                    {select name from them where id = '${quote_pgsql:$local_part}'}}
273                  = ok:   
274  search_open: pgsql "NULL"
275    cached open
276  search_find: file="NULL"
277    key="select name from them where id = 'c'" partial=-1 affix=NULL starflags=0 opts="cache=no_rd"
278  LRU list:
279  internal_search_find: file="NULL"
280    type=pgsql key="select name from them where id = 'c'" opts=NULL
281  cached data found but no_rd option set;  database lookup required for select name from them where id = 'c'
282                               (tainted)
283 LOG: MAIN PANIC
284   tainted search query is not properly quoted (ACL warn, TESTSUITE/test-config 27): select name from them where id = 'c'
285  search_type NN (pgsql) quoting -1 (none)
286  PostgreSQL query: "select name from them where id = 'c'" opts 'NULL'
287  PGSQL using cached connection for localhost:PORT_N/test/CALLER
288  PGSQL: no data found
289  replacing old cache entry
290  lookup failed
291 check set acl_m0 = FAIL: ${lookup pgsql,cache=no_rd        {select name from them where id = '$local_part'}}
292                  = FAIL: 
293 warn: condition test succeeded in ACL "check_recipient"
294 processing "warn" (TESTSUITE/test-config 32)
295  search_open: pgsql "NULL"
296    cached open
297  search_find: file="NULL"
298    key="select name from them where id = 'c'" partial=-1 affix=NULL starflags=0 opts="servers=localhost::PORT_N/test/CALLER/"
299  LRU list:
300  internal_search_find: file="NULL"
301    type=pgsql key="select name from them where id = 'c'" opts="servers=localhost::PORT_N/test/CALLER/"
302  cached data found but wrong opts;  database lookup required for select name from them where id = 'c'
303                               (tainted, quoted:pgsql)
304  PostgreSQL query: "select name from them where id = 'c'" opts 'servers=localhost::PORT_N/test/CALLER/'
305  PGSQL using cached connection for localhost:PORT_N/test/CALLER
306  PGSQL: no data found
307  replacing old cache entry
308  lookup failed
309 check set acl_m0 = ok:   ${lookup pgsql,servers=localhost::PORT_N/test/CALLER/      {select name from them where id = '${quote_pgsql:$local_part}'}}
310                  = ok:   
311  search_open: pgsql "NULL"
312    cached open
313  search_find: file="NULL"
314    key="select name from them where id = 'c'" partial=-1 affix=NULL starflags=0 opts="servers=localhost::PORT_N"
315  LRU list:
316  internal_search_find: file="NULL"
317    type=pgsql key="select name from them where id = 'c'" opts="servers=localhost::PORT_N"
318  cached data found but wrong opts;  database lookup required for select name from them where id = 'c'
319                               (tainted, quoted:pgsql)
320  PostgreSQL query: "select name from them where id = 'c'" opts 'servers=localhost::PORT_N'
321  PGSQL using cached connection for localhost:PORT_N/test/CALLER
322  PGSQL: no data found
323  replacing old cache entry
324  lookup failed
325 check set acl_m0 = ok:   ${lookup pgsql,servers=localhost::PORT_N    {select name from them where id = '${quote_pgsql:$local_part}'}}
326                  = ok:   
327  search_open: pgsql "NULL"
328    cached open
329  search_find: file="NULL"
330    key="servers=localhost::PORT_N/test/CALLER/; select name from them where id = 'c'" partial=-1 affix=NULL starflags=0 opts=NULL
331  LRU list:
332  internal_search_find: file="NULL"
333    type=pgsql key="servers=localhost::PORT_N/test/CALLER/; select name from them where id = 'c'" opts=NULL
334  database lookup required for servers=localhost::PORT_N/test/CALLER/; select name from them where id = 'c'
335                               (tainted, quoted:pgsql)
336  PostgreSQL query: "servers=localhost::PORT_N/test/CALLER/; select name from them where id = 'c'" opts 'NULL'
337  lookup deferred: PostgreSQL server "localhost:PORT_N/test/CALLER/" is tainted
338 warn: condition test deferred in ACL "check_recipient"
339 LOG: MAIN
340   H=(test) [10.0.0.0] Warning: ACL "warn" statement skipped: condition test deferred: PostgreSQL server "localhost:PORT_N/test/CALLER/" is tainted
341 processing "warn" (TESTSUITE/test-config 41)
342 check set acl_m0 = ok:   hostlist
343 check hosts = net-pgsql;select * from them where id='${quote_pgsql:$local_part}'
344 host in "net-pgsql;select * from them where id='c'"?
345  list element: net-pgsql;select * from them where id='c'
346  search_open: pgsql "NULL"
347    cached open
348  search_find: file="NULL"
349    key="select * from them where id='c'" partial=-1 affix=NULL starflags=0 opts=NULL
350  LRU list:
351  internal_search_find: file="NULL"
352    type=pgsql key="select * from them where id='c'" opts=NULL
353  database lookup required for select * from them where id='c'
354                               (tainted, quoted:pgsql)
355  PostgreSQL query: "select * from them where id='c'" opts 'NULL'
356  PGSQL using cached connection for localhost:PORT_N/test/CALLER
357  PGSQL: no data found
358  creating new cache entry
359  lookup failed
360 host in "net-pgsql;select * from them where id='c'"? no (end of list)
361 warn: condition test failed in ACL "check_recipient"
362 processing "warn" (TESTSUITE/test-config 44)
363 check set acl_m0 = FAIL: hostlist
364 check hosts = <& net-pgsql;servers=localhost::PORT_N/test/CALLER/; select * from them where id='${quote_pgsql:$local_part}'
365 host in "<& net-pgsql;servers=localhost::PORT_N/test/CALLER/; select * from them where id='c'"?
366  list element: net-pgsql;servers=localhost::PORT_N/test/CALLER/; select * from them where id='c'
367  search_open: pgsql "NULL"
368    cached open
369  search_find: file="NULL"
370    key="servers=localhost::PORT_N/test/CALLER/; select * from them where id='c'" partial=-1 affix=NULL starflags=0 opts=NULL
371  LRU list:
372  internal_search_find: file="NULL"
373    type=pgsql key="servers=localhost::PORT_N/test/CALLER/; select * from them where id='c'" opts=NULL
374  database lookup required for servers=localhost::PORT_N/test/CALLER/; select * from them where id='c'
375                               (tainted, quoted:pgsql)
376  PostgreSQL query: "servers=localhost::PORT_N/test/CALLER/; select * from them where id='c'" opts 'NULL'
377  lookup deferred: PostgreSQL server "localhost:PORT_N/test/CALLER/" is tainted
378 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'
379 warn: condition test deferred in ACL "check_recipient"
380 LOG: MAIN
381   H=(test) [10.0.0.0] Warning: ACL "warn" statement skipped: condition test deferred: PostgreSQL server "localhost:PORT_N/test/CALLER/" is tainted
382 processing "warn" (TESTSUITE/test-config 49)
383 check set acl_m0 = FAIL: hostlist
384 check hosts = <& net-pgsql,servers=localhost::PORT_N/test/CALLER/; select * from them where id='${quote_pgsql:$local_part}'
385 host in "<& net-pgsql,servers=localhost::PORT_N/test/CALLER/; select * from them where id='c'"?
386  list element: net-pgsql,servers=localhost::PORT_N/test/CALLER/; select * from them where id='c'
387  search_open: pgsql "NULL"
388    cached open
389  search_find: file="NULL"
390    key=" select * from them where id='c'" partial=-1 affix=NULL starflags=0 opts="servers=localhost::PORT_N/test/CALLER/"
391  LRU list:
392  internal_search_find: file="NULL"
393    type=pgsql key=" select * from them where id='c'" opts="servers=localhost::PORT_N/test/CALLER/"
394  database lookup required for  select * from them where id='c'
395                               (tainted, quoted:pgsql)
396  PostgreSQL query: " select * from them where id='c'" opts 'servers=localhost::PORT_N/test/CALLER/'
397  lookup deferred: PostgreSQL server "localhost:PORT_N/test/CALLER/" is tainted
398 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'
399 warn: condition test deferred in ACL "check_recipient"
400 LOG: MAIN
401   H=(test) [10.0.0.0] Warning: ACL "warn" statement skipped: condition test deferred: PostgreSQL server "localhost:PORT_N/test/CALLER/" is tainted
402 processing "accept" (TESTSUITE/test-config 52)
403 check domains = +local_domains
404 d in "+local_domains"?
405  list element: +local_domains
406   start sublist local_domains
407    d in "@"?
408    ╎list element: @
409    d in "@"? no (end of list)
410   end sublist local_domains
411 d in "+local_domains"? no (end of list)
412 accept: condition test failed in ACL "check_recipient"
413 processing "accept" (TESTSUITE/test-config 53)
414 check hosts = +relay_hosts
415 host in "+relay_hosts"?
416  list element: +relay_hosts
417   start sublist relay_hosts
418   host in "net-pgsql;select * from them where id='10.0.0.0'"?
419    ╎list element: net-pgsql;select * from them where id='10.0.0.0'
420    ╎search_open: pgsql "NULL"
421    ╎  cached open
422    ╎search_find: file="NULL"
423    ╎  key="select * from them where id='10.0.0.0'" partial=-1 affix=NULL starflags=0 opts=NULL
424    ╎LRU list:
425    ╎internal_search_find: file="NULL"
426    ╎  type=pgsql key="select * from them where id='10.0.0.0'" opts=NULL
427    ╎database lookup required for select * from them where id='10.0.0.0'
428    ╎PostgreSQL query: "select * from them where id='10.0.0.0'" opts 'NULL'
429    ╎PGSQL using cached connection for localhost:PORT_N/test/CALLER
430    ╎PGSQL: no data found
431    ╎creating new cache entry
432    ╎lookup failed
433   host in "net-pgsql;select * from them where id='10.0.0.0'"? no (end of list)
434   end sublist relay_hosts
435 host in "+relay_hosts"? no (end of list)
436 accept: condition test failed in ACL "check_recipient"
437 processing "deny" (TESTSUITE/test-config 54)
438   message: relay not permitted
439 deny: condition test succeeded in ACL "check_recipient"
440 end of ACL "check_recipient": DENY
441 SMTP>> 550 relay not permitted
442 LOG: MAIN REJECT
443   H=(test) [10.0.0.0] F=<a@b> rejected RCPT <c@d>: relay not permitted
444 SMTP<< rcpt to:<c@d>
445 using ACL "check_recipient"
446 processing "warn" (TESTSUITE/test-config 27)
447  search_open: pgsql "NULL"
448    cached open
449  search_find: file="NULL"
450    key="select name from them where id = 'c'" partial=-1 affix=NULL starflags=0 opts=NULL
451  LRU list:
452  internal_search_find: file="NULL"
453    type=pgsql key="select name from them where id = 'c'" opts=NULL
454  cached data found but wrong opts;  database lookup required for select name from them where id = 'c'
455                               (tainted, quoted:pgsql)
456  PostgreSQL query: "select name from them where id = 'c'" opts 'NULL'
457  PGSQL using cached connection for localhost:PORT_N/test/CALLER
458  PGSQL: no data found
459  replacing old cache entry
460  lookup failed
461 check set acl_m0 = ok:   ${lookup pgsql                    {select name from them where id = '${quote_pgsql:$local_part}'}}
462                  = ok:   
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="cache=no_rd"
467  LRU list:
468  internal_search_find: file="NULL"
469    type=pgsql key="select name from them where id = 'c'" opts=NULL
470  cached data found but no_rd option set;  database lookup required for select name from them where id = 'c'
471                               (tainted)
472 LOG: MAIN PANIC
473   tainted search query is not properly quoted (ACL warn, TESTSUITE/test-config 27): select name from them where id = 'c'
474  search_type NN (pgsql) quoting -1 (none)
475  PostgreSQL query: "select name from them where id = 'c'" opts 'NULL'
476  PGSQL using cached connection for localhost:PORT_N/test/CALLER
477  PGSQL: no data found
478  replacing old cache entry
479  lookup failed
480 check set acl_m0 = FAIL: ${lookup pgsql,cache=no_rd        {select name from them where id = '$local_part'}}
481                  = FAIL: 
482 warn: condition test succeeded in ACL "check_recipient"
483 processing "warn" (TESTSUITE/test-config 32)
484  search_open: pgsql "NULL"
485    cached open
486  search_find: file="NULL"
487    key="select name from them where id = 'c'" partial=-1 affix=NULL starflags=0 opts="servers=localhost::PORT_N/test/CALLER/"
488  LRU list:
489  internal_search_find: file="NULL"
490    type=pgsql key="select name from them where id = 'c'" opts="servers=localhost::PORT_N/test/CALLER/"
491  cached data found but wrong opts;  database lookup required for select name from them where id = 'c'
492                               (tainted, quoted:pgsql)
493  PostgreSQL query: "select name from them where id = 'c'" opts 'servers=localhost::PORT_N/test/CALLER/'
494  PGSQL using cached connection for localhost:PORT_N/test/CALLER
495  PGSQL: no data found
496  replacing old cache entry
497  lookup failed
498 check set acl_m0 = ok:   ${lookup pgsql,servers=localhost::PORT_N/test/CALLER/      {select name from them where id = '${quote_pgsql:$local_part}'}}
499                  = ok:   
500  search_open: pgsql "NULL"
501    cached open
502  search_find: file="NULL"
503    key="select name from them where id = 'c'" partial=-1 affix=NULL starflags=0 opts="servers=localhost::PORT_N"
504  LRU list:
505  internal_search_find: file="NULL"
506    type=pgsql key="select name from them where id = 'c'" opts="servers=localhost::PORT_N"
507  cached data found but wrong opts;  database lookup required for select name from them where id = 'c'
508                               (tainted, quoted:pgsql)
509  PostgreSQL query: "select name from them where id = 'c'" opts 'servers=localhost::PORT_N'
510  PGSQL using cached connection for localhost:PORT_N/test/CALLER
511  PGSQL: no data found
512  replacing old cache entry
513  lookup failed
514 check set acl_m0 = ok:   ${lookup pgsql,servers=localhost::PORT_N    {select name from them where id = '${quote_pgsql:$local_part}'}}
515                  = ok:   
516  search_open: pgsql "NULL"
517    cached open
518  search_find: file="NULL"
519    key="servers=localhost::PORT_N/test/CALLER/; select name from them where id = 'c'" partial=-1 affix=NULL starflags=0 opts=NULL
520  LRU list:
521  internal_search_find: file="NULL"
522    type=pgsql key="servers=localhost::PORT_N/test/CALLER/; select name from them where id = 'c'" opts=NULL
523  database lookup required for servers=localhost::PORT_N/test/CALLER/; select name from them where id = 'c'
524                               (tainted, quoted:pgsql)
525  PostgreSQL query: "servers=localhost::PORT_N/test/CALLER/; select name from them where id = 'c'" opts 'NULL'
526  lookup deferred: PostgreSQL server "localhost:PORT_N/test/CALLER/" is tainted
527 warn: condition test deferred in ACL "check_recipient"
528 LOG: MAIN
529   H=(test) [10.0.0.0] Warning: ACL "warn" statement skipped: condition test deferred: PostgreSQL server "localhost:PORT_N/test/CALLER/" is tainted
530 processing "warn" (TESTSUITE/test-config 41)
531 check set acl_m0 = ok:   hostlist
532 check hosts = net-pgsql;select * from them where id='${quote_pgsql:$local_part}'
533 host in "net-pgsql;select * from them where id='c'"?
534  list element: net-pgsql;select * from them where id='c'
535  search_open: pgsql "NULL"
536    cached open
537  search_find: file="NULL"
538    key="select * from them where id='c'" partial=-1 affix=NULL starflags=0 opts=NULL
539  LRU list:
540  internal_search_find: file="NULL"
541    type=pgsql key="select * from them where id='c'" opts=NULL
542  cached data used for lookup of select * from them where id='c'
543  lookup failed
544 host in "net-pgsql;select * from them where id='c'"? no (end of list)
545 warn: condition test failed in ACL "check_recipient"
546 processing "warn" (TESTSUITE/test-config 44)
547 check set acl_m0 = FAIL: hostlist
548 check hosts = <& net-pgsql;servers=localhost::PORT_N/test/CALLER/; select * from them where id='${quote_pgsql:$local_part}'
549 host in "<& net-pgsql;servers=localhost::PORT_N/test/CALLER/; select * from them where id='c'"?
550  list element: net-pgsql;servers=localhost::PORT_N/test/CALLER/; select * from them where id='c'
551  search_open: pgsql "NULL"
552    cached open
553  search_find: file="NULL"
554    key="servers=localhost::PORT_N/test/CALLER/; select * from them where id='c'" partial=-1 affix=NULL starflags=0 opts=NULL
555  LRU list:
556  internal_search_find: file="NULL"
557    type=pgsql key="servers=localhost::PORT_N/test/CALLER/; select * from them where id='c'" opts=NULL
558  database lookup required for servers=localhost::PORT_N/test/CALLER/; select * from them where id='c'
559                               (tainted, quoted:pgsql)
560  PostgreSQL query: "servers=localhost::PORT_N/test/CALLER/; select * from them where id='c'" opts 'NULL'
561  lookup deferred: PostgreSQL server "localhost:PORT_N/test/CALLER/" is tainted
562 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'
563 warn: condition test deferred in ACL "check_recipient"
564 LOG: MAIN
565   H=(test) [10.0.0.0] Warning: ACL "warn" statement skipped: condition test deferred: PostgreSQL server "localhost:PORT_N/test/CALLER/" is tainted
566 processing "warn" (TESTSUITE/test-config 49)
567 check set acl_m0 = FAIL: hostlist
568 check hosts = <& net-pgsql,servers=localhost::PORT_N/test/CALLER/; select * from them where id='${quote_pgsql:$local_part}'
569 host in "<& net-pgsql,servers=localhost::PORT_N/test/CALLER/; select * from them where id='c'"?
570  list element: net-pgsql,servers=localhost::PORT_N/test/CALLER/; select * from them where id='c'
571  search_open: pgsql "NULL"
572    cached open
573  search_find: file="NULL"
574    key=" select * from them where id='c'" partial=-1 affix=NULL starflags=0 opts="servers=localhost::PORT_N/test/CALLER/"
575  LRU list:
576  internal_search_find: file="NULL"
577    type=pgsql key=" select * from them where id='c'" opts="servers=localhost::PORT_N/test/CALLER/"
578  database lookup required for  select * from them where id='c'
579                               (tainted, quoted:pgsql)
580  PostgreSQL query: " select * from them where id='c'" opts 'servers=localhost::PORT_N/test/CALLER/'
581  lookup deferred: PostgreSQL server "localhost:PORT_N/test/CALLER/" is tainted
582 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'
583 warn: condition test deferred in ACL "check_recipient"
584 LOG: MAIN
585   H=(test) [10.0.0.0] Warning: ACL "warn" statement skipped: condition test deferred: PostgreSQL server "localhost:PORT_N/test/CALLER/" is tainted
586 processing "accept" (TESTSUITE/test-config 52)
587 check domains = +local_domains
588 d in "+local_domains"?
589  list element: +local_domains
590   start sublist local_domains
591    d in "@"?
592    ╎list element: @
593    d in "@"? no (end of list)
594   end sublist local_domains
595 d in "+local_domains"? no (end of list)
596 accept: condition test failed in ACL "check_recipient"
597 processing "accept" (TESTSUITE/test-config 53)
598 check hosts = +relay_hosts
599 host in "+relay_hosts"?
600  list element: +relay_hosts
601   start sublist relay_hosts
602   host in "net-pgsql;select * from them where id='10.0.0.0'"?
603    ╎list element: net-pgsql;select * from them where id='10.0.0.0'
604    ╎search_open: pgsql "NULL"
605    ╎  cached open
606    ╎search_find: file="NULL"
607    ╎  key="select * from them where id='10.0.0.0'" partial=-1 affix=NULL starflags=0 opts=NULL
608    ╎LRU list:
609    ╎internal_search_find: file="NULL"
610    ╎  type=pgsql key="select * from them where id='10.0.0.0'" opts=NULL
611    ╎cached data used for lookup of select * from them where id='10.0.0.0'
612    ╎lookup failed
613   host in "net-pgsql;select * from them where id='10.0.0.0'"? no (end of list)
614   end sublist relay_hosts
615 host in "+relay_hosts"? no (end of list)
616 accept: condition test failed in ACL "check_recipient"
617 processing "deny" (TESTSUITE/test-config 54)
618   message: relay not permitted
619 deny: condition test succeeded in ACL "check_recipient"
620 end of ACL "check_recipient": DENY
621 SMTP>> 550 relay not permitted
622 LOG: MAIN REJECT
623   H=(test) [10.0.0.0] F=<a@b> rejected RCPT <c@d>: relay not permitted
624 SMTP<< quit
625 SMTP>> 221 myhost.test.ex closing connection
626 LOG: smtp_connection MAIN
627   SMTP connection from (test) [10.0.0.0] D=qqs closed by QUIT
628 search_tidyup called
629 close PGSQL connection: localhost:PORT_N/test/CALLER
630 >>>>>>>>>>>>>>>> Exim pid=p1236 (fresh-exec) terminating with rc=0 >>>>>>>>>>>>>>>>
631 Exim version x.yz ....
632 changed uid/gid: forcing real = effective
633   uid=uuuu gid=CALLER_GID pid=p1237
634 configuration file is TESTSUITE/test-config
635 admin user
636 changed uid/gid: privilege not needed
637   uid=EXIM_UID gid=EXIM_GID pid=p1237
638 seeking password data for user "CALLER": cache not available
639 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
640 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
641 sender address = CALLER@myhost.test.ex
642 set_process_info: pppp accepting a local non-SMTP message from <CALLER@myhost.test.ex>
643 spool directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100 msg_size = 0
644 log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
645 Sender: CALLER@myhost.test.ex
646 Recipients:
647   CALLER
648 search_tidyup called
649 >>Headers received:
650
651 qualify & rewrite recipients list
652 rewrite rules on sender address
653 qualify and rewrite headers
654  rewrite_one_header: type=F:
655    From: CALLER_NAME <CALLER@myhost.test.ex>
656 search_tidyup called
657 >>Headers after rewriting and local additions:
658  I Message-Id: <E10HmaX-000000005vi-0000@myhost.test.ex>
659  F From: CALLER_NAME <CALLER@myhost.test.ex>
660    Date: Tue, 2 Mar 1999 09:44:33 +0000
661
662 Data file name: TESTSUITE/spool//input//10HmaX-000000005vi-0000-D
663 Data file written for message 10HmaX-000000005vi-0000
664 >>Generated Received: header line
665 P Received: from CALLER by myhost.test.ex with local (Exim x.yz)
666         (envelope-from <CALLER@myhost.test.ex>)
667         id 10HmaX-000000005vi-0000
668         for CALLER@myhost.test.ex;
669         Tue, 2 Mar 1999 09:44:33 +0000
670 Writing spool header file: TESTSUITE/spool//input//hdr.10HmaX-000000005vi-0000
671 DSN: **** SPOOL_OUT - address: <CALLER@myhost.test.ex> errorsto: <NULL> orcpt: <NULL> dsn_flags: 0x0
672 Renaming spool header file: TESTSUITE/spool//input//10HmaX-000000005vi-0000-H
673 Size of headers = sss
674 LOG: MAIN
675   <= CALLER@myhost.test.ex U=CALLER P=local S=sss
676 created log directory TESTSUITE/spool/log
677 search_tidyup called
678 exec TESTSUITE/eximdir/exim -DEXIM_PATH=TESTSUITE/eximdir/exim -C TESTSUITE/test-config -d=0xf7715cfd -MCd local-accept-delivery -odi -Mc 10HmaX-000000005vi-0000
679 Exim version x.yz ....
680 changed uid/gid: forcing real = effective
681   uid=uuuu gid=EXIM_GID pid=p1238
682 configuration file is TESTSUITE/test-config
683 trusted user
684 admin user
685 dropping to exim gid; retaining priv uid
686 seeking password data for user "CALLER": cache not available
687 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
688 set_process_info: pppp delivering specified messages
689 set_process_info: pppp delivering 10HmaX-000000005vi-0000
690 Trying spool file TESTSUITE/spool//input//10HmaX-000000005vi-0000-D
691 reading spool file 10HmaX-000000005vi-0000-H
692 user=CALLER uid=CALLER_UID gid=CALLER_GID sender=CALLER@myhost.test.ex
693 sender_local=1 ident=CALLER
694 Non-recipients:
695  Empty Tree
696 ---- End of tree ----
697 recipients_count=1
698 **** SPOOL_IN - No additional fields
699 body_linecount=1 message_linecount=8
700 DSN: set orcpt:   flags: 0x0
701 Delivery address list:
702   CALLER@myhost.test.ex 
703  locking TESTSUITE/spool/db/retry.lockfile
704  locked  TESTSUITE/spool/db/retry.lockfile
705  EXIM_DBOPEN: file <TESTSUITE/spool/db/retry> dir <TESTSUITE/spool/db> flags=O_RDONLY
706  returned from EXIM_DBOPEN: (nil)
707  failed to open DB file TESTSUITE/spool/db/retry: No such file or directory
708 no retry data available
709 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
710 Considering: CALLER@myhost.test.ex
711 unique = CALLER@myhost.test.ex
712 no   domain  retry record
713 no   address retry record
714 CALLER@myhost.test.ex: queued for routing
715 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
716 routing CALLER@myhost.test.ex
717 --------> r1 router <--------
718 local_part=CALLER domain=myhost.test.ex
719 processing address_data
720  search_open: pgsql "NULL"
721  search_find: file="NULL"
722    key="select name from them where id='ph10'" partial=-1 affix=NULL starflags=0 opts=NULL
723  LRU list:
724  internal_search_find: file="NULL"
725    type=pgsql key="select name from them where id='ph10'" opts=NULL
726  database lookup required for select name from them where id='ph10'
727  PostgreSQL query: "select name from them where id='ph10'" opts 'NULL'
728  PGSQL new connection: host=localhost port=PORT_N database=test user=CALLER
729  creating new cache entry
730  lookup yielded: Philip Hazel
731 calling r1 router
732 r1 router called for CALLER@myhost.test.ex
733   domain = myhost.test.ex
734 set transport t1
735 queued for t1 transport: local_part = CALLER
736 domain = myhost.test.ex
737   errors_to=NULL
738   domain_data=NULL local_part_data=NULL
739 routed by r1 router
740   envelope to: CALLER@myhost.test.ex
741   transport: t1
742 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
743 After routing:
744   Local deliveries:
745     CALLER@myhost.test.ex
746   Remote deliveries:
747   Failed addresses:
748   Deferred addresses:
749 search_tidyup called
750 close PGSQL connection: localhost:PORT_N/test/CALLER
751 >>>>>>>>>>>>>>>> Local deliveries >>>>>>>>>>>>>>>>
752 --------> CALLER@myhost.test.ex <--------
753  locking TESTSUITE/spool/db/retry.lockfile
754  locked  TESTSUITE/spool/db/retry.lockfile
755  EXIM_DBOPEN: file <TESTSUITE/spool/db/retry> dir <TESTSUITE/spool/db> flags=O_RDONLY
756  returned from EXIM_DBOPEN: (nil)
757  failed to open DB file TESTSUITE/spool/db/retry: No such file or directory
758 no retry data available
759 search_tidyup called
760 changed uid/gid: local delivery to CALLER <CALLER@myhost.test.ex> transport=t1
761   uid=CALLER_UID gid=CALLER_GID pid=p1239
762   home=NULL current=/
763 set_process_info: pppp delivering 10HmaX-000000005vi-0000 to CALLER using t1
764 appendfile transport entered
765  search_open: pgsql "NULL"
766  search_find: file="NULL"
767    key="select id from them where id='ph10'" partial=-1 affix=NULL starflags=0 opts=NULL
768  LRU list:
769  internal_search_find: file="NULL"
770    type=pgsql key="select id from them where id='ph10'" opts=NULL
771  database lookup required for select id from them where id='ph10'
772  PostgreSQL query: "select id from them where id='ph10'" opts 'NULL'
773  PGSQL new connection: host=localhost port=PORT_N database=test user=CALLER
774  creating new cache entry
775  lookup yielded: ph10
776 appendfile: mode=600 notify_comsat=0 quota=0 warning=0
777   file=TESTSUITE/test-mail/ph10 format=unix
778   message_prefix=From ${if def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}\n
779   message_suffix=\n
780   maildir_use_size_file=no
781   locking by lockfile fcntl 
782 lock name: TESTSUITE/test-mail/ph10.lock
783 hitch name: TESTSUITE/test-mail/ph10.lock.test.ex.dddddddd.pppppppp
784 lock file created
785 mailbox TESTSUITE/test-mail/ph10 is locked
786 writing to file TESTSUITE/test-mail/ph10
787 writing data block fd=dddd size=sss timeout=0
788 cannot use sendfile for body: spoolfile not wireformat
789 writing data block fd=dddd size=sss timeout=0
790 writing data block fd=dddd size=sss timeout=0
791 appendfile yields 0 with errno=dd more_errno=dd
792 search_tidyup called
793 close PGSQL connection: localhost:PORT_N/test/CALLER
794 journalling CALLER@myhost.test.ex
795 t1 transport returned OK for CALLER@myhost.test.ex
796 post-process CALLER@myhost.test.ex (0)
797 CALLER@myhost.test.ex delivered
798 LOG: MAIN
799   => CALLER <CALLER@myhost.test.ex> R=r1 T=t1
800 >>>>>>>>>>>>>>>> deliveries are done >>>>>>>>>>>>>>>>
801 changed uid/gid: post-delivery tidying
802   uid=EXIM_UID gid=EXIM_GID pid=p1238
803 set_process_info: pppp tidying up after delivering 10HmaX-000000005vi-0000
804 Processing retry items
805 Succeeded addresses:
806  CALLER@myhost.test.ex: no retry items
807 Failed addresses:
808 Deferred addresses:
809 end of retry processing
810 DSN: processing router : r1
811 DSN: processing successful delivery address: CALLER@myhost.test.ex
812 DSN: Sender_address: CALLER@myhost.test.ex
813 DSN: orcpt: NULL  flags: 0x0
814 DSN: envid: NULL  ret: 0
815 DSN: Final recipient: CALLER@myhost.test.ex
816 DSN: Remote SMTP server supports DSN: 0
817 DSN: not sending DSN success message
818 LOG: MAIN
819   Completed
820 end delivery of 10HmaX-000000005vi-0000
821 search_tidyup called
822 search_tidyup called
823 >>>>>>>>>>>>>>>> Exim pid=p1238 (local-accept-delivery) terminating with rc=0 >>>>>>>>>>>>>>>>
824 search_tidyup called
825 >>>>>>>>>>>>>>>> Exim pid=p1237 (fresh-exec) terminating with rc=0 >>>>>>>>>>>>>>>>
826 Exim version x.yz ....
827 configuration file is TESTSUITE/test-config
828 admin user
829 dropping to exim gid; retaining priv uid
830  search_open: pgsql "NULL"
831  search_find: file="NULL"
832    key="select name from them where id='ph10';" partial=-1 affix=NULL starflags=0 opts=NULL
833  LRU list:
834  internal_search_find: file="NULL"
835    type=pgsql key="select name from them where id='ph10';" opts=NULL
836  database lookup required for select name from them where id='ph10';
837  PostgreSQL query: "select name from them where id='ph10';" opts 'NULL'
838  PGSQL new connection: socket=TESTSUITE/pgsql/.s.PGSQL.1223 database=test user=CALLER
839  creating new cache entry
840  lookup yielded: Philip Hazel
841 search_tidyup called
842 close PGSQL connection: (TESTSUITE/pgsql/.s.PGSQL.1223)/test/CALLER
843 >>>>>>>>>>>>>>>> Exim pid=p1240 (fresh-exec) terminating with rc=0 >>>>>>>>>>>>>>>>
844
845 ******** SERVER ********
846 2017-07-30 18:51:05.712 [pppp] LOG:  redirecting log output to logging collector process
847 2017-07-30 18:51:05.712 [pppp] HINT:  Future log output will appear in directory "log".