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".