TLS: log input for pipelining violation
[exim.git] / test / stderr / 2201
index 27851019e450790d13fc92b01a34a3ccc12934b5..927c7c6de57d3f4edb3a842e8a306d4d0b409407 100644 (file)
@@ -1,6 +1,6 @@
 Exim version x.yz ....
 changed uid/gid: forcing real = effective
-  uid=uuuu gid=CALLER_GID pid=pppp
+  uid=uuuu gid=CALLER_GID pid=p1236
 seeking password data for user "CALLER": cache not available
 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 configuration file is TESTSUITE/test-config
@@ -21,38 +21,43 @@ routing test.ex@test.ex
 --------> r0 router <--------
 local_part=test.ex domain=test.ex
 checking senders
-address match test: subject=CALLER@myhost.test.ex pattern=a@shorthost.test.ex
+CALLER@myhost.test.ex in "a@shorthost.test.ex"?
+ list element: a@shorthost.test.ex
+ address match test: subject=CALLER@myhost.test.ex pattern=a@shorthost.test.ex
 CALLER@myhost.test.ex in "a@shorthost.test.ex"? no (end of list)
 r0 router skipped: senders mismatch
 --------> r1 router <--------
 local_part=test.ex domain=test.ex
 checking domains
-search_open: dnsdb "NULL"
-search_find: file="NULL"
-  key="test.ex" partial=-1 affix=NULL starflags=0
-LRU list:
-internal_search_find: file="NULL"
-  type=dnsdb key="test.ex"
-database lookup required for test.ex
-dnsdb key: test.ex
+test.ex in "dnsdb;test.ex"?
+ list element: dnsdb;test.ex
+ search_open: dnsdb "NULL"
+ search_find: file="NULL"
+   key="test.ex" partial=-1 affix=NULL starflags=0 opts=NULL
+ LRU list:
+ internal_search_find: file="NULL"
+   type=dnsdb key="test.ex" opts=NULL
+ database lookup required for test.ex
+                              (tainted)
+ dnsdb key: test.ex
 DNS lookup of test.ex (TXT) using fakens
-fresh-exec forking for fakens-search
-postfork: fakens-search
-fresh-exec forked for fakens-search: npppp
 DNS lookup of test.ex (TXT) succeeded
-lookup yielded: A TXT record for test.ex.
-test.ex in "dnsdb;test.ex"? yes (matched "dnsdb;test.ex")
+ creating new cache entry
+ lookup yielded: A TXT record for test.ex.
+ test.ex in "dnsdb;test.ex"? yes (matched "dnsdb;test.ex")
 checking local_parts
-search_open: dnsdb "NULL"
-  cached open
-search_find: file="NULL"
-  key="test.ex" partial=-1 affix=NULL starflags=0
-LRU list:
-internal_search_find: file="NULL"
-  type=dnsdb key="test.ex"
-cached data used for lookup of test.ex
-lookup yielded: A TXT record for test.ex.
-test.ex in "dnsdb;test.ex"? yes (matched "dnsdb;test.ex")
+test.ex in "dnsdb;test.ex"?
+ list element: dnsdb;test.ex
+ search_open: dnsdb "NULL"
+   cached open
+ search_find: file="NULL"
+   key="test.ex" partial=-1 affix=NULL starflags=0 opts=NULL
+ LRU list:
+ internal_search_find: file="NULL"
+   type=dnsdb key="test.ex" opts=NULL
+ cached data used for lookup of test.ex
+ lookup yielded: A TXT record for test.ex.
+ test.ex in "dnsdb;test.ex"? yes (matched "dnsdb;test.ex")
 calling r1 router
 r1 router called for test.ex@test.ex
   domain = test.ex
@@ -60,7 +65,7 @@ set transport local_delivery
 queued for local_delivery transport: local_part = test.ex
 domain = test.ex
   errors_to=NULL
-  domain_data=A TXT record for test.ex. localpart_data=A TXT record for test.ex.
+  domain_data=A TXT record for test.ex. local_part_data=A TXT record for test.ex.
 routed by r1 router
   envelope to: test.ex@test.ex
   transport: local_delivery
@@ -73,74 +78,81 @@ routing unknown@test.ex
 --------> r0 router <--------
 local_part=unknown domain=test.ex
 checking senders
-address match test: subject=CALLER@myhost.test.ex pattern=a@shorthost.test.ex
+CALLER@myhost.test.ex in "a@shorthost.test.ex"?
+ list element: a@shorthost.test.ex
+ address match test: subject=CALLER@myhost.test.ex pattern=a@shorthost.test.ex
 CALLER@myhost.test.ex in "a@shorthost.test.ex"? no (end of list)
 r0 router skipped: senders mismatch
 --------> r1 router <--------
 local_part=unknown domain=test.ex
 checking domains
-search_open: dnsdb "NULL"
-  cached open
-search_find: file="NULL"
-  key="test.ex" partial=-1 affix=NULL starflags=0
-LRU list:
-internal_search_find: file="NULL"
-  type=dnsdb key="test.ex"
-cached data used for lookup of test.ex
-lookup yielded: A TXT record for test.ex.
-test.ex in "dnsdb;test.ex"? yes (matched "dnsdb;test.ex")
+test.ex in "dnsdb;test.ex"?
+ list element: dnsdb;test.ex
+ search_open: dnsdb "NULL"
+   cached open
+ search_find: file="NULL"
+   key="test.ex" partial=-1 affix=NULL starflags=0 opts=NULL
+ LRU list:
+ internal_search_find: file="NULL"
+   type=dnsdb key="test.ex" opts=NULL
+ cached data used for lookup of test.ex
+ lookup yielded: A TXT record for test.ex.
+ test.ex in "dnsdb;test.ex"? yes (matched "dnsdb;test.ex")
 checking local_parts
-search_open: dnsdb "NULL"
-  cached open
-search_find: file="NULL"
-  key="unknown" partial=-1 affix=NULL starflags=0
-LRU list:
-internal_search_find: file="NULL"
-  type=dnsdb key="unknown"
-database lookup required for unknown
-dnsdb key: unknown
+unknown in "dnsdb;unknown"?
+ list element: dnsdb;unknown
+ search_open: dnsdb "NULL"
+   cached open
+ search_find: file="NULL"
+   key="unknown" partial=-1 affix=NULL starflags=0 opts=NULL
+ LRU list:
+ internal_search_find: file="NULL"
+   type=dnsdb key="unknown" opts=NULL
+ database lookup required for unknown
+                              (tainted)
+ dnsdb key: unknown
 DNS lookup of unknown (TXT) using fakens
-fresh-exec forking for fakens-search
-postfork: fakens-search
-fresh-exec forked for fakens-search: npppp
 DNS lookup of unknown (TXT) gave HOST_NOT_FOUND
 returning DNS_NOMATCH
 faking res_search(TXT) response length as 65535
  writing neg-cache entry for unknown-TXT-xxxx, ttl 3000
-lookup failed
+ creating new cache entry
+ lookup failed
 unknown in "dnsdb;unknown"? no (end of list)
 r1 router skipped: local_parts mismatch
 --------> r2 router <--------
 local_part=unknown domain=test.ex
 checking domains
-search_open: dnsdb "NULL"
-  cached open
-search_find: file="NULL"
-  key="test.ex" partial=-1 affix=NULL starflags=0
-LRU list:
-internal_search_find: file="NULL"
-  type=dnsdb key="test.ex"
-cached data used for lookup of test.ex
-lookup yielded: A TXT record for test.ex.
-test.ex in "dnsdb;test.ex"? yes (matched "dnsdb;test.ex")
+test.ex in "dnsdb;test.ex"?
+ list element: dnsdb;test.ex
+ search_open: dnsdb "NULL"
+   cached open
+ search_find: file="NULL"
+   key="test.ex" partial=-1 affix=NULL starflags=0 opts=NULL
+ LRU list:
+ internal_search_find: file="NULL"
+   type=dnsdb key="test.ex" opts=NULL
+ cached data used for lookup of test.ex
+ lookup yielded: A TXT record for test.ex.
+ test.ex in "dnsdb;test.ex"? yes (matched "dnsdb;test.ex")
 checking senders
-address match test: subject=CALLER@myhost.test.ex pattern=dnsdb;A=myhost.test.ex
-search_open: dnsdb "NULL"
-  cached open
-search_find: file="NULL"
-  key="A=myhost.test.ex" partial=-1 affix=NULL starflags=0
-LRU list:
-internal_search_find: file="NULL"
-  type=dnsdb key="A=myhost.test.ex"
-database lookup required for A=myhost.test.ex
-dnsdb key: myhost.test.ex
+CALLER@myhost.test.ex in "dnsdb;A=myhost.test.ex"?
+ list element: dnsdb;A=myhost.test.ex
+ address match test: subject=CALLER@myhost.test.ex pattern=dnsdb;A=myhost.test.ex
+ search_open: dnsdb "NULL"
+   cached open
+ search_find: file="NULL"
+   key="A=myhost.test.ex" partial=-1 affix=NULL starflags=0 opts=NULL
+ LRU list:
+ internal_search_find: file="NULL"
+   type=dnsdb key="A=myhost.test.ex" opts=NULL
+ database lookup required for A=myhost.test.ex
+ dnsdb key: myhost.test.ex
 DNS lookup of myhost.test.ex (A) using fakens
-fresh-exec forking for fakens-search
-postfork: fakens-search
-fresh-exec forked for fakens-search: npppp
 DNS lookup of myhost.test.ex (A) succeeded
-lookup yielded: V4NET.10.10.10
-CALLER@myhost.test.ex in "dnsdb;A=myhost.test.ex"? yes (matched "dnsdb;A=myhost.test.ex")
+ creating new cache entry
+ lookup yielded: V4NET.10.10.10
+ CALLER@myhost.test.ex in "dnsdb;A=myhost.test.ex"? yes (matched "dnsdb;A=myhost.test.ex")
 calling r2 router
 r2 router called for unknown@test.ex
   domain = test.ex
@@ -148,12 +160,12 @@ set transport local_delivery
 queued for local_delivery transport: local_part = unknown
 domain = test.ex
   errors_to=NULL
-  domain_data=A TXT record for test.ex. localpart_data=NULL
+  domain_data=A TXT record for test.ex. local_part_data=NULL
 routed by r2 router
   envelope to: unknown@test.ex
   transport: local_delivery
 search_tidyup called
->>>>>>>>>>>>>>>> Exim pid=pppp (main) terminating with rc=0 >>>>>>>>>>>>>>>>
+>>>>>>>>>>>>>>>> Exim pid=p1236 (fresh-exec) terminating with rc=0 >>>>>>>>>>>>>>>>
 Exim version x.yz ....
 configuration file is TESTSUITE/test-config
 trusted user
@@ -162,43 +174,41 @@ search_tidyup called
 search_tidyup called
 search_open: dnsdb "NULL"
 search_find: file="NULL"
-  key="a=shorthost.test.ex" partial=-1 affix=NULL starflags=0
+  key="a=shorthost.test.ex" partial=-1 affix=NULL starflags=0 opts=NULL
 LRU list:
 internal_search_find: file="NULL"
-  type=dnsdb key="a=shorthost.test.ex"
+  type=dnsdb key="a=shorthost.test.ex" opts=NULL
 database lookup required for a=shorthost.test.ex
+                             (tainted)
 dnsdb key: shorthost.test.ex
-fresh-exec forking for fakens-search
-postfork: fakens-search
-fresh-exec forked for fakens-search: npppp
+creating new cache entry
 lookup yielded: 127.0.0.1
 search_open: dnsdb "NULL"
   cached open
 search_find: file="NULL"
-  key="a=shorthost.test.ex" partial=-1 affix=NULL starflags=0
+  key="a=shorthost.test.ex" partial=-1 affix=NULL starflags=0 opts=NULL
 LRU list:
 internal_search_find: file="NULL"
-  type=dnsdb key="a=shorthost.test.ex"
+  type=dnsdb key="a=shorthost.test.ex" opts=NULL
 cached data used for lookup of a=shorthost.test.ex
 lookup yielded: 127.0.0.1
 search_open: dnsdb "NULL"
   cached open
 search_find: file="NULL"
-  key="a=shorthost.test.ex" partial=-1 affix=NULL starflags=0
+  key="a=shorthost.test.ex" partial=-1 affix=NULL starflags=0 opts=NULL
 LRU list:
 internal_search_find: file="NULL"
-  type=dnsdb key="a=shorthost.test.ex"
-cached data found but past valid time; database lookup required for a=shorthost.test.ex
+  type=dnsdb key="a=shorthost.test.ex" opts=NULL
+cached data found but out-of-date; database lookup required for a=shorthost.test.ex
+                             (tainted)
 dnsdb key: shorthost.test.ex
-fresh-exec forking for fakens-search
-postfork: fakens-search
-fresh-exec forked for fakens-search: npppp
+replacing old cache entry
 lookup yielded: 127.0.0.1
 LOG: MAIN
   <= a@shorthost.test.ex U=CALLER P=local S=sss
 created log directory TESTSUITE/spool/log
 search_tidyup called
->>>>>>>>>>>>>>>> Exim pid=pppp (main) terminating with rc=0 >>>>>>>>>>>>>>>>
+>>>>>>>>>>>>>>>> Exim pid=p1237 (fresh-exec) terminating with rc=0 >>>>>>>>>>>>>>>>
 
 ******** SERVER ********
 Exim version x.yz ....
@@ -206,67 +216,44 @@ configuration file is TESTSUITE/test-config
 trusted user
 admin user
 dropping to exim gid; retaining priv uid
-ppppp daemon_smtp_port overridden by -oX:
-ppppp   <: 1225
-ppppp creating notifier socket
-ppppp  TESTSUITE/spool/exim_daemon_notify
-ppppp listening on all interfaces (IPv4) port 1225
-ppppp pid written to TESTSUITE/spool/exim-daemon.pid
-ppppp LOG: MAIN
-ppppp   exim x.yz daemon started: pid=pppp, no queue runs, listening for SMTP on port 1225
-ppppp daemon running with uid=EXIM_UID gid=EXIM_GID euid=EXIM_UID egid=EXIM_GID
-ppppp Listening...
-ppppp Connection request from 127.0.0.1 port sssss
-ppppp fresh-exec forking for daemon accept
-ppppp postfork: daemon accept
-ppppp Process ppppp is handling incoming connection from [127.0.0.1]
-ppppp Process ppppp is ready for new message
-ppppp daemon accept forking for fakens-search
-ppppp postfork: fakens-search
-ppppp fresh-exec forked for daemon accept: npppp
-ppppp 1 SMTP accept process running
-ppppp Listening...
-ppppp daemon accept forked for fakens-search: npppp
-ppppp daemon accept forking for fakens-search
-ppppp postfork: fakens-search
-ppppp daemon accept forked for fakens-search: npppp
-ppppp dnslists check: rbl.test.ex/V4NET.11.12.14
-ppppp new DNS lookup for 14.12.11.V4NET.rbl.test.ex
-ppppp daemon accept forking for fakens-search
-ppppp postfork: fakens-search
-ppppp daemon accept forked for fakens-search: npppp
-ppppp dnslists: wrote cache entry, ttl=2
-ppppp DNS lookup for 14.12.11.V4NET.rbl.test.ex succeeded (yielding 127.0.0.2)
-ppppp daemon accept forking for fakens-search
-ppppp postfork: fakens-search
-ppppp daemon accept forked for fakens-search: npppp
-ppppp => that means V4NET.11.12.14 is listed at rbl.test.ex
-ppppp dnslists check: rbl.test.ex/V4NET.11.12.14
-ppppp dnslists: using result of previous lookup
-ppppp DNS lookup for 14.12.11.V4NET.rbl.test.ex succeeded (yielding 127.0.0.2)
-ppppp => that means V4NET.11.12.14 is listed at rbl.test.ex
-ppppp dnslists check: rbl.test.ex/V4NET.11.12.14
-ppppp cached data found but past valid time; new DNS lookup for 14.12.11.V4NET.rbl.test.ex
-ppppp daemon accept forking for fakens-search
-ppppp postfork: fakens-search
-ppppp daemon accept forked for fakens-search: npppp
-ppppp dnslists: wrote cache entry, ttl=2
-ppppp DNS lookup for 14.12.11.V4NET.rbl.test.ex succeeded (yielding 127.0.0.2)
-ppppp daemon accept forking for fakens-search
-ppppp postfork: fakens-search
-ppppp daemon accept forked for fakens-search: npppp
-ppppp => that means V4NET.11.12.14 is listed at rbl.test.ex
-ppppp LOG: MAIN
-ppppp   <= a@shorthost.test.ex H=localhost (myhost.test.ex) [127.0.0.1] P=esmtp S=sss id=E10HmaX-0005vi-00@myhost.test.ex
-ppppp Process ppppp is ready for new message
-ppppp LOG: smtp_connection MAIN
-ppppp   SMTP connection from localhost (myhost.test.ex) [127.0.0.1] closed by QUIT
-ppppp >>>>>>>>>>>>>>>> Exim pid=pppp (conn-setup) terminating with rc=0 >>>>>>>>>>>>>>>>
-ppppp child ppppp ended: status=0x0
-ppppp   normal exit, 0
-ppppp 0 SMTP accept processes now running
-ppppp Listening...
-ppppp fresh-exec forking for daemon del pidfile
-ppppp postfork: daemon del pidfile
-ppppp fresh-exec forked for daemon del pidfile: npppp
-ppppp >>>>>>>>>>>>>>>> Exim pid=pppp (daemon) terminating with rc=0 >>>>>>>>>>>>>>>>
+daemon_smtp_port overridden by -oX:
+  <: 1225
+creating notifier socket
+ TESTSUITE/spool/exim_daemon_notify
+listening on all interfaces (IPv4) port PORT_D
+pid written to TESTSUITE/spool/exim-daemon.pid
+LOG: MAIN
+  exim x.yz daemon started: pid=p1235, no queue runs, listening for SMTP on port PORT_D
+daemon running with uid=EXIM_UID gid=EXIM_GID euid=EXIM_UID egid=EXIM_GID
+Listening...
+Connection request from 127.0.0.1 port sssss
+p1238 Process p1238 is handling incoming connection from [127.0.0.1]
+p1238 Process p1238 is ready for new message
+1 SMTP accept process running
+Listening...
+p1238 dnslists check: rbl.test.ex/V4NET.11.12.14
+p1238 new DNS lookup for 14.12.11.V4NET.rbl.test.ex
+p1238 dnslists: wrote cache entry, ttl=2
+p1238 DNS lookup for 14.12.11.V4NET.rbl.test.ex succeeded (yielding 127.0.0.2)
+p1238 => that means V4NET.11.12.14 is listed at rbl.test.ex
+p1238 dnslists check: rbl.test.ex/V4NET.11.12.14
+p1238 dnslists: using result of previous lookup
+p1238 DNS lookup for 14.12.11.V4NET.rbl.test.ex succeeded (yielding 127.0.0.2)
+p1238 => that means V4NET.11.12.14 is listed at rbl.test.ex
+p1238 dnslists check: rbl.test.ex/V4NET.11.12.14
+p1238 cached data found but past valid time; new DNS lookup for 14.12.11.V4NET.rbl.test.ex
+p1238 dnslists: wrote cache entry, ttl=2
+p1238 DNS lookup for 14.12.11.V4NET.rbl.test.ex succeeded (yielding 127.0.0.2)
+p1238 => that means V4NET.11.12.14 is listed at rbl.test.ex
+LOG: MAIN
+  <= a@shorthost.test.ex H=localhost (myhost.test.ex) [127.0.0.1] P=esmtp S=sss id=E10HmaX-0005vi-00@myhost.test.ex
+Process p1238 is ready for new message
+LOG: smtp_connection MAIN
+  SMTP connection from localhost (myhost.test.ex) [127.0.0.1] D=qqs closed by QUIT
+>>>>>>>>>>>>>>>> Exim pid=p1238 (daemon-accept) terminating with rc=0 >>>>>>>>>>>>>>>>
+p1235 child p1238 ended: status=0x0
+p1235   normal exit, 0
+p1235 0 SMTP accept processes now running
+p1235 Listening...
+p1235 SIGTERM/SIGINT seen
+p1235 >>>>>>>>>>>>>>>> Exim pid=p1235 (daemon) terminating with rc=0 >>>>>>>>>>>>>>>>