Exim was not testing for a space following SMTP commands such as EHLO
[exim.git] / test / stderr / 9100
1 Exim version x.yz ....
2 configuration file is TESTSUITE/test-config
3 admin user
4 search_open: mysql "NULL"
5 search_find: file="NULL"
6   key="select name from them where id='CALLER';" partial=-1 affix=NULL starflags=0
7 LRU list:
8 internal_search_find: file="NULL"
9   type=mysql key="select name from them where id='CALLER';"
10 database lookup required for select name from them where id='CALLER';
11 MYSQL query: select name from them where id='CALLER';
12 MYSQL new connection: host=localhost port=0 socket=NULL database=test user=root
13 lookup yielded: Philip Hazel
14 search_open: mysql "NULL"
15   cached open
16 search_find: file="NULL"
17   key="select name from them where id='CALLER';" partial=-1 affix=NULL starflags=0
18 LRU list:
19 internal_search_find: file="NULL"
20   type=mysql key="select name from them where id='CALLER';"
21 cached data used for lookup of select name from them where id='CALLER';
22 lookup yielded: Philip Hazel
23 search_open: mysql "NULL"
24   cached open
25 search_find: file="NULL"
26   key="select name from them where id='xxxx';" partial=-1 affix=NULL starflags=0
27 LRU list:
28 internal_search_find: file="NULL"
29   type=mysql key="select name from them where id='xxxx';"
30 database lookup required for select name from them where id='xxxx';
31 MYSQL query: select name from them where id='xxxx';
32 MYSQL using cached connection for localhost/test/root
33 MYSQL: no data found
34 lookup failed
35 search_open: mysql "NULL"
36   cached open
37 search_find: file="NULL"
38   key="select name from them where id='nothing';" partial=-1 affix=NULL starflags=0
39 LRU list:
40 internal_search_find: file="NULL"
41   type=mysql key="select name from them where id='nothing';"
42 database lookup required for select name from them where id='nothing';
43 MYSQL query: select name from them where id='nothing';
44 MYSQL using cached connection for localhost/test/root
45 MYSQL: no data found
46 lookup failed
47 search_open: mysql "NULL"
48   cached open
49 search_find: file="NULL"
50   key="select id,name from them where id='nothing';" partial=-1 affix=NULL starflags=0
51 LRU list:
52 internal_search_find: file="NULL"
53   type=mysql key="select id,name from them where id='nothing';"
54 database lookup required for select id,name from them where id='nothing';
55 MYSQL query: select id,name from them where id='nothing';
56 MYSQL using cached connection for localhost/test/root
57 lookup yielded: id=nothing name="" 
58 search_open: mysql "NULL"
59   cached open
60 search_find: file="NULL"
61   key="delete from them where id='nonexist';" partial=-1 affix=NULL starflags=0
62 LRU list:
63 internal_search_find: file="NULL"
64   type=mysql key="delete from them where id='nonexist';"
65 database lookup required for delete from them where id='nonexist';
66 MYSQL query: delete from them where id='nonexist';
67 MYSQL using cached connection for localhost/test/root
68 MYSQL: query was not one that returns data
69 lookup forced cache cleanup
70 lookup yielded: 0
71 search_open: mysql "NULL"
72   cached open
73 search_find: file="NULL"
74   key="select * from them where id='quote';" partial=-1 affix=NULL starflags=0
75 LRU list:
76 internal_search_find: file="NULL"
77   type=mysql key="select * from them where id='quote';"
78 database lookup required for select * from them where id='quote';
79 MYSQL query: select * from them where id='quote';
80 MYSQL using cached connection for localhost/test/root
81 lookup yielded: id=quote name="\"Q\" Oted" home=/home/quoted mail=quoted@xxx 
82 search_open: mysql "NULL"
83   cached open
84 search_find: file="NULL"
85   key="select * from them where id='filter';" partial=-1 affix=NULL starflags=0
86 LRU list:
87 internal_search_find: file="NULL"
88   type=mysql key="select * from them where id='filter';"
89 database lookup required for select * from them where id='filter';
90 MYSQL query: select * from them where id='filter';
91 MYSQL using cached connection for localhost/test/root
92 lookup yielded: id=filter name=filter home=filter mail="#Exim filter
93 deliver postmaster" 
94 search_open: mysql "NULL"
95   cached open
96 search_find: file="NULL"
97   key="select * from them where id='quote2';" partial=-1 affix=NULL starflags=0
98 LRU list:
99 internal_search_find: file="NULL"
100   type=mysql key="select * from them where id='quote2';"
101 database lookup required for select * from them where id='quote2';
102 MYSQL query: select * from them where id='quote2';
103 MYSQL using cached connection for localhost/test/root
104 lookup yielded: id=quote2 name="\"qnosp" home=/home/q2 mail="" 
105 search_open: mysql "NULL"
106   cached open
107 search_find: file="NULL"
108   key="select * from them where id='nlonly';" partial=-1 affix=NULL starflags=0
109 LRU list:
110 internal_search_find: file="NULL"
111   type=mysql key="select * from them where id='nlonly';"
112 database lookup required for select * from them where id='nlonly';
113 MYSQL query: select * from them where id='nlonly';
114 MYSQL using cached connection for localhost/test/root
115 lookup yielded: id=nlonly name=filter home=filter mail="Before
116 After" 
117 search_tidyup called
118 close MYSQL connection: localhost/test/root
119 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
120 Exim version x.yz ....
121 changed uid/gid: forcing real = effective
122   uid=uuuu gid=CALLER_GID pid=pppp
123 configuration file is TESTSUITE/test-config
124 admin user
125 changed uid/gid: privilege not needed
126   uid=EXIM_UID gid=EXIM_GID pid=pppp
127 seeking password data for user "CALLER": cache not available
128 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
129 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
130 sender address = CALLER@myhost.test.ex
131 sender_fullhost = [10.0.0.0]
132 sender_rcvhost = [10.0.0.0]
133 host in hosts_connection_nolog? no (option unset)
134 LOG: smtp_connection MAIN
135   SMTP connection from [10.0.0.0]
136 host in host_lookup? no (option unset)
137 set_process_info: pppp handling incoming connection from [10.0.0.0]
138 host in host_reject_connection? no (option unset)
139 host in sender_unqualified_hosts? no (option unset)
140 host in recipient_unqualified_hosts? no (option unset)
141 host in helo_verify_hosts? no (option unset)
142 host in helo_try_verify_hosts? no (option unset)
143 host in helo_accept_junk_hosts? no (option unset)
144 SMTP>> 220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000
145 smtp_setup_msg entered
146 SMTP<< mail from:<a@b>
147 SMTP>> 250 OK
148 SMTP<< rcpt to:<c@d>
149 using ACL "check_recipient"
150 processing "accept"
151 check domains = +local_domains
152 d in "@"? no (end of list)
153 d in "+local_domains"? no (end of list)
154 accept: condition test failed
155 processing "accept"
156 check hosts = +relay_hosts
157 search_open: mysql "NULL"
158 search_find: file="NULL"
159   key="select * from them where id='10.0.0.0'" partial=-1 affix=NULL starflags=0
160 LRU list:
161 internal_search_find: file="NULL"
162   type=mysql key="select * from them where id='10.0.0.0'"
163 database lookup required for select * from them where id='10.0.0.0'
164 MYSQL query: select * from them where id='10.0.0.0'
165 MYSQL new connection: host=localhost port=0 socket=NULL database=test user=root
166 MYSQL: no data found
167 lookup failed
168 host in "net-mysql;select * from them where id='10.0.0.0'"? no (end of list)
169 host in "+relay_hosts"? no (end of list)
170 accept: condition test failed
171 processing "deny"
172 deny: condition test succeeded
173 SMTP>> 550 relay not permitted
174 LOG: MAIN REJECT
175   H=[10.0.0.0] F=<a@b> rejected RCPT <c@d>: relay not permitted
176 SMTP<< quit
177 SMTP>> 221 myhost.test.ex closing connection
178 LOG: smtp_connection MAIN
179   SMTP connection from [10.0.0.0] closed by QUIT
180 search_tidyup called
181 close MYSQL connection: localhost/test/root
182 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
183 Exim version x.yz ....
184 changed uid/gid: forcing real = effective
185   uid=uuuu gid=CALLER_GID pid=pppp
186 configuration file is TESTSUITE/test-config
187 admin user
188 changed uid/gid: privilege not needed
189   uid=EXIM_UID gid=EXIM_GID pid=pppp
190 seeking password data for user "CALLER": cache not available
191 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
192 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
193 sender address = CALLER@myhost.test.ex
194 set_process_info: pppp accepting a local non-SMTP message from <CALLER@myhost.test.ex>
195 Sender: CALLER@myhost.test.ex
196 Recipients:
197   CALLER
198 search_tidyup called
199 >>Headers received:
200
201 rewrite_one_header: type=F:
202   From: CALLER_NAME <CALLER@myhost.test.ex>
203 search_tidyup called
204 >>Headers after rewriting and local additions:
205 I Message-Id: <E10HmaX-0005vi-00@myhost.test.ex>
206 F From: CALLER_NAME <CALLER@myhost.test.ex>
207   Date: Tue, 2 Mar 1999 09:44:33 +0000
208
209 Data file written for message 10HmaX-0005vi-00
210 >>Generated Received: header line
211 P Received: from CALLER by myhost.test.ex with local (Exim x.yz)
212         (envelope-from <CALLER@myhost.test.ex>)
213         id 10HmaX-0005vi-00
214         for CALLER@myhost.test.ex; Tue, 2 Mar 1999 09:44:33 +0000
215 calling local_scan(); timeout=300
216 local_scan() returned 0 NULL
217 Writing spool header file
218 Size of headers = sss
219 LOG: MAIN
220   <= CALLER@myhost.test.ex U=CALLER P=local S=sss
221 created log directory TESTSUITE/spool/log
222 search_tidyup called
223 exec TESTSUITE/eximdir/exim -DEXIM_PATH=TESTSUITE/eximdir/exim -C TESTSUITE/test-config -d=0xfbb95cfd -odi -Mc 10HmaX-0005vi-00
224 Exim version x.yz ....
225 changed uid/gid: forcing real = effective
226   uid=uuuu gid=EXIM_GID pid=pppp
227 configuration file is TESTSUITE/test-config
228 trusted user
229 admin user
230 skipping ACL configuration - not needed
231 seeking password data for user "CALLER": cache not available
232 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
233 set_process_info: pppp delivering specified messages
234 set_process_info: pppp delivering 10HmaX-0005vi-00
235 reading spool file 10HmaX-0005vi-00-H
236 user=CALLER uid=CALLER_UID gid=CALLER_GID sender=CALLER@myhost.test.ex
237 sender_local=1 ident=CALLER
238 Non-recipients:
239 Empty Tree
240 ---- End of tree ----
241 recipients_count=1
242 body_linecount=1 message_linecount=7
243 Delivery address list:
244   CALLER@myhost.test.ex 
245 locking TESTSUITE/spool/db/retry.lockfile
246 locked TESTSUITE/spool/db/retry.lockfile
247 EXIM_DBOPEN(TESTSUITE/spool/db/retry)
248 returned from EXIM_DBOPEN
249 ensuring TESTSUITE/spool/db/retry.lockfile is owned by exim
250 no retry data available
251 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
252 Considering: CALLER@myhost.test.ex
253 unique = CALLER@myhost.test.ex
254 no domain retry record
255 no address retry record
256 CALLER@myhost.test.ex: queued for routing
257 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
258 routing CALLER@myhost.test.ex
259 --------> r1 router <--------
260 local_part=CALLER domain=myhost.test.ex
261 processing address_data
262 search_open: mysql "NULL"
263 search_find: file="NULL"
264   key="select name from them where id='CALLER'" partial=-1 affix=NULL starflags=0
265 LRU list:
266 internal_search_find: file="NULL"
267   type=mysql key="select name from them where id='CALLER'"
268 database lookup required for select name from them where id='CALLER'
269 MYSQL query: select name from them where id='CALLER'
270 MYSQL new connection: host=localhost port=0 socket=NULL database=test user=root
271 lookup yielded: Philip Hazel
272 calling r1 router
273 r1 router called for CALLER@myhost.test.ex
274   domain = myhost.test.ex
275 set transport t1
276 queued for t1 transport: local_part = CALLER
277 domain = myhost.test.ex
278   errors_to=NULL
279   domain_data=NULL localpart_data=NULL
280 routed by r1 router
281   envelope to: CALLER@myhost.test.ex
282   transport: t1
283 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
284 After routing:
285   Local deliveries:
286     CALLER@myhost.test.ex
287   Remote deliveries:
288   Failed addresses:
289   Deferred addresses:
290 search_tidyup called
291 close MYSQL connection: localhost/test/root
292 >>>>>>>>>>>>>>>> Local deliveries >>>>>>>>>>>>>>>>
293 --------> CALLER@myhost.test.ex <--------
294 locking TESTSUITE/spool/db/retry.lockfile
295 locked TESTSUITE/spool/db/retry.lockfile
296 EXIM_DBOPEN(TESTSUITE/spool/db/retry)
297 returned from EXIM_DBOPEN
298 no retry data available
299 search_tidyup called
300 changed uid/gid: local delivery to CALLER <CALLER@myhost.test.ex> transport=t1
301   uid=CALLER_UID gid=CALLER_GID pid=pppp
302   home=NULL current=/
303 set_process_info: pppp delivering 10HmaX-0005vi-00 to CALLER using t1
304 appendfile transport entered
305 search_open: mysql "NULL"
306 search_find: file="NULL"
307   key="select id from them where id='CALLER'" partial=-1 affix=NULL starflags=0
308 LRU list:
309 internal_search_find: file="NULL"
310   type=mysql key="select id from them where id='CALLER'"
311 database lookup required for select id from them where id='CALLER'
312 MYSQL query: select id from them where id='CALLER'
313 MYSQL new connection: host=localhost port=0 socket=NULL database=test user=root
314 lookup yielded: CALLER
315 appendfile: mode=600 notify_comsat=0 quota=0 warning=0
316   file=TESTSUITE/test-mail/CALLER format=unix
317   message_prefix=From ${if def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}\n
318   message_suffix=\n
319   maildir_use_size_file=no
320   locking by lockfile fcntl 
321 lock name: TESTSUITE/test-mail/CALLER.lock
322 hitch name: TESTSUITE/test-mail/CALLER.lock.test.ex.dddddddd.pppppppp
323 lock file created
324 mailbox TESTSUITE/test-mail/CALLER is locked
325 writing to file TESTSUITE/test-mail/CALLER
326 writing data block fd=dddd size=sss timeout=0
327 writing data block fd=dddd size=sss timeout=0
328 writing data block fd=dddd size=sss timeout=0
329 appendfile yields 0 with errno=dd more_errno=dd
330 search_tidyup called
331 close MYSQL connection: localhost/test/root
332 journalling CALLER@myhost.test.ex
333 t1 transport returned OK for CALLER@myhost.test.ex
334 post-process CALLER@myhost.test.ex (0)
335 CALLER@myhost.test.ex delivered
336 LOG: MAIN
337   => CALLER <CALLER@myhost.test.ex> R=r1 T=t1
338 >>>>>>>>>>>>>>>> deliveries are done >>>>>>>>>>>>>>>>
339 changed uid/gid: post-delivery tidying
340   uid=EXIM_UID gid=EXIM_GID pid=pppp
341 set_process_info: pppp tidying up after delivering 10HmaX-0005vi-00
342 Processing retry items
343 Succeeded addresses:
344 CALLER@myhost.test.ex: no retry items
345 Failed addresses:
346 Deferred addresses:
347 end of retry processing
348 LOG: MAIN
349   Completed
350 end delivery of 10HmaX-0005vi-00
351 search_tidyup called
352 search_tidyup called
353 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
354 search_tidyup called
355 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>