Tweak debug output
[exim.git] / test / stderr / 0022
1 Exim version x.yz ....
2 changed uid/gid: forcing real = effective
3   uid=uuuu gid=CALLER_GID pid=p1235
4 configuration file is TESTSUITE/test-config
5 admin user
6 changed uid/gid: privilege not needed
7   uid=EXIM_UID gid=EXIM_GID pid=p1235
8 seeking password data for user "CALLER": cache not available
9 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
10 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
11 sender address = CALLER@test.ex
12 sender_fullhost = [V4NET.9.8.7]
13 sender_rcvhost = [V4NET.9.8.7]
14 host in hosts_connection_nolog? no (end of list)
15 LOG: smtp_connection MAIN
16   SMTP connection from [V4NET.9.8.7]
17 host in host_lookup? no (option unset)
18 set_process_info: pppp handling incoming connection from [V4NET.9.8.7]
19 host in host_reject_connection? no (option unset)
20 host in sender_unqualified_hosts? no (option unset)
21 host in recipient_unqualified_hosts? no (option unset)
22 host in helo_verify_hosts? no (option unset)
23 host in helo_try_verify_hosts? no (option unset)
24 host in helo_accept_junk_hosts? no (option unset)
25 SMTP>> 220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000
26 smtp_setup_msg entered
27 SMTP<< helo test
28 test in helo_lookup_domains? no (end of list)
29 sender_fullhost = (test) [V4NET.9.8.7]
30 sender_rcvhost = [V4NET.9.8.7] (helo=test)
31 set_process_info: pppp handling incoming connection from (test) [V4NET.9.8.7]
32 SMTP>> 250 myhost.test.ex Hello test [V4NET.9.8.7]
33 SMTP<< mail from:<x@y>
34 spool directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100 msg_size = 0
35 log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
36 SMTP>> 250 OK
37 SMTP<< rcpt to:<warn_empty@test.ex>
38 using ACL "warn_empty"
39 processing "warn" (TESTSUITE/test-config 29)
40 warn: condition test succeeded in ACL "warn_empty"
41 processing "accept" (TESTSUITE/test-config 30)
42 accept: condition test succeeded in ACL "warn_empty"
43 end of ACL "warn_empty": ACCEPT
44 SMTP>> 250 Accepted
45 SMTP<< data
46 SMTP>> 354 Enter message, ending with "." on a line by itself
47 search_tidyup called
48 >>Headers received:
49
50 qualify & rewrite recipients list
51 global rewrite rules
52 rewrite headers
53 search_tidyup called
54 >>Headers after rewriting and local additions:
55
56 Data file name: TESTSUITE/spool//input//10HmbF-0005vi-00-D
57 Data file written for message 10HmbF-0005vi-00
58 >>Generated Received: header line
59 P Received: from [V4NET.9.8.7] (helo=test)
60         by myhost.test.ex with smtp (Exim x.yz)
61         (envelope-from <x@y>)
62         id 10HmbF-0005vi-00
63         for warn_empty@test.ex;
64         Tue, 2 Mar 1999 09:44:33 +0000
65 LOG: MAIN
66   <= x@y H=(test) [V4NET.9.8.7] P=smtp S=sss
67 SMTP>> 250 OK id=10HmbF-0005vi-00
68 smtp_setup_msg entered
69 SMTP<< quit
70 SMTP>> 221 myhost.test.ex closing connection
71 LOG: smtp_connection MAIN
72   SMTP connection from (test) [V4NET.9.8.7] closed by QUIT
73 search_tidyup called
74 >>>>>>>>>>>>>>>> Exim pid=p1235 (fresh-exec) terminating with rc=0 >>>>>>>>>>>>>>>>
75 Exim version x.yz ....
76 changed uid/gid: forcing real = effective
77   uid=uuuu gid=CALLER_GID pid=p1236
78 configuration file is TESTSUITE/test-config
79 admin user
80 changed uid/gid: privilege not needed
81   uid=EXIM_UID gid=EXIM_GID pid=p1236
82 seeking password data for user "CALLER": cache not available
83 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
84 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
85 sender address = CALLER@test.ex
86 sender_fullhost = [V4NET.9.8.7]
87 sender_rcvhost = [V4NET.9.8.7]
88 host in hosts_connection_nolog? no (end of list)
89 LOG: smtp_connection MAIN
90   SMTP connection from [V4NET.9.8.7]
91 host in host_lookup? no (option unset)
92 set_process_info: pppp handling incoming connection from [V4NET.9.8.7]
93 host in host_reject_connection? no (option unset)
94 host in sender_unqualified_hosts? no (option unset)
95 host in recipient_unqualified_hosts? no (option unset)
96 host in helo_verify_hosts? no (option unset)
97 host in helo_try_verify_hosts? no (option unset)
98 host in helo_accept_junk_hosts? no (option unset)
99 SMTP>> 220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000
100 smtp_setup_msg entered
101 SMTP<< helo test
102 test in helo_lookup_domains? no (end of list)
103 sender_fullhost = (test) [V4NET.9.8.7]
104 sender_rcvhost = [V4NET.9.8.7] (helo=test)
105 set_process_info: pppp handling incoming connection from (test) [V4NET.9.8.7]
106 SMTP>> 250 myhost.test.ex Hello test [V4NET.9.8.7]
107 SMTP<< mail from:<x@y>
108 spool directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100 msg_size = 0
109 log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
110 SMTP>> 250 OK
111 SMTP<< rcpt to:<warn_log@test.ex>
112 using ACL "warn_log"
113 processing "warn" (TESTSUITE/test-config 33)
114 l_message: warn log message
115 warn: condition test succeeded in ACL "warn_log"
116 LOG: MAIN
117   H=(test) [V4NET.9.8.7] Warning: warn log message
118 processing "accept" (TESTSUITE/test-config 34)
119 accept: condition test succeeded in ACL "warn_log"
120 end of ACL "warn_log": ACCEPT
121 SMTP>> 250 Accepted
122 SMTP<< data
123 SMTP>> 354 Enter message, ending with "." on a line by itself
124 search_tidyup called
125 >>Headers received:
126
127 qualify & rewrite recipients list
128 global rewrite rules
129 rewrite headers
130 search_tidyup called
131 >>Headers after rewriting and local additions:
132
133 Data file name: TESTSUITE/spool//input//10HmbG-0005vi-00-D
134 Data file written for message 10HmbG-0005vi-00
135 >>Generated Received: header line
136 P Received: from [V4NET.9.8.7] (helo=test)
137         by myhost.test.ex with smtp (Exim x.yz)
138         (envelope-from <x@y>)
139         id 10HmbG-0005vi-00
140         for warn_log@test.ex;
141         Tue, 2 Mar 1999 09:44:33 +0000
142 LOG: MAIN
143   <= x@y H=(test) [V4NET.9.8.7] P=smtp S=sss
144 SMTP>> 250 OK id=10HmbG-0005vi-00
145 smtp_setup_msg entered
146 SMTP<< quit
147 SMTP>> 221 myhost.test.ex closing connection
148 LOG: smtp_connection MAIN
149   SMTP connection from (test) [V4NET.9.8.7] closed by QUIT
150 search_tidyup called
151 >>>>>>>>>>>>>>>> Exim pid=p1236 (fresh-exec) terminating with rc=0 >>>>>>>>>>>>>>>>
152 Exim version x.yz ....
153 changed uid/gid: forcing real = effective
154   uid=uuuu gid=CALLER_GID pid=p1237
155 configuration file is TESTSUITE/test-config
156 admin user
157 changed uid/gid: privilege not needed
158   uid=EXIM_UID gid=EXIM_GID pid=p1237
159 seeking password data for user "CALLER": cache not available
160 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
161 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
162 sender address = CALLER@test.ex
163 sender_fullhost = [V4NET.9.8.7]
164 sender_rcvhost = [V4NET.9.8.7]
165 host in hosts_connection_nolog? no (end of list)
166 LOG: smtp_connection MAIN
167   SMTP connection from [V4NET.9.8.7]
168 host in host_lookup? no (option unset)
169 set_process_info: pppp handling incoming connection from [V4NET.9.8.7]
170 host in host_reject_connection? no (option unset)
171 host in sender_unqualified_hosts? no (option unset)
172 host in recipient_unqualified_hosts? no (option unset)
173 host in helo_verify_hosts? no (option unset)
174 host in helo_try_verify_hosts? no (option unset)
175 host in helo_accept_junk_hosts? no (option unset)
176 SMTP>> 220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000
177 smtp_setup_msg entered
178 SMTP<< helo test
179 test in helo_lookup_domains? no (end of list)
180 sender_fullhost = (test) [V4NET.9.8.7]
181 sender_rcvhost = [V4NET.9.8.7] (helo=test)
182 set_process_info: pppp handling incoming connection from (test) [V4NET.9.8.7]
183 SMTP>> 250 myhost.test.ex Hello test [V4NET.9.8.7]
184 SMTP<< mail from:<x@y>
185 spool directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100 msg_size = 0
186 log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
187 SMTP>> 250 OK
188 SMTP<< rcpt to:<warn_user@test.ex>
189 using ACL "warn_user"
190 processing "warn" (TESTSUITE/test-config 37)
191   message: warn user message
192 warn: condition test succeeded in ACL "warn_user"
193 processing "accept" (TESTSUITE/test-config 38)
194 accept: condition test succeeded in ACL "warn_user"
195 end of ACL "warn_user": ACCEPT
196 SMTP>> 250 Accepted
197 SMTP<< data
198 SMTP>> 354 Enter message, ending with "." on a line by itself
199 search_tidyup called
200 >>Headers received:
201
202 qualify & rewrite recipients list
203 global rewrite rules
204 rewrite headers
205 search_tidyup called
206 >>Headers after rewriting and local additions:
207
208 Data file name: TESTSUITE/spool//input//10HmbH-0005vi-00-D
209 Data file written for message 10HmbH-0005vi-00
210 >>Generated Received: header line
211 P Received: from [V4NET.9.8.7] (helo=test)
212         by myhost.test.ex with smtp (Exim x.yz)
213         (envelope-from <x@y>)
214         id 10HmbH-0005vi-00
215         for warn_user@test.ex;
216         Tue, 2 Mar 1999 09:44:33 +0000
217 >>Headers added by MAIL or RCPT ACL:
218   X-ACL-Warn: warn user message
219 >>
220 LOG: MAIN
221   <= x@y H=(test) [V4NET.9.8.7] P=smtp S=sss
222 SMTP>> 250 OK id=10HmbH-0005vi-00
223 smtp_setup_msg entered
224 SMTP<< quit
225 SMTP>> 221 myhost.test.ex closing connection
226 LOG: smtp_connection MAIN
227   SMTP connection from (test) [V4NET.9.8.7] closed by QUIT
228 search_tidyup called
229 >>>>>>>>>>>>>>>> Exim pid=p1237 (fresh-exec) terminating with rc=0 >>>>>>>>>>>>>>>>
230 >>> host in hosts_connection_nolog? no (end of list)
231 LOG: SMTP connection from [V4NET.9.8.7]
232 >>> host in host_lookup? no (option unset)
233 >>> host in host_reject_connection? no (option unset)
234 >>> host in sender_unqualified_hosts? no (option unset)
235 >>> host in recipient_unqualified_hosts? no (option unset)
236 >>> host in helo_verify_hosts? no (option unset)
237 >>> host in helo_try_verify_hosts? no (option unset)
238 >>> host in helo_accept_junk_hosts? no (option unset)
239 >>> test in helo_lookup_domains? no (end of list)
240 >>> using ACL "defer"
241 >>> processing "defer" (TESTSUITE/test-config 51)
242 >>>   message: forcibly deferred
243 >>> defer: condition test succeeded in ACL "defer"
244 >>> end of ACL "defer": DEFER
245 LOG: H=(test) [V4NET.9.8.7] F=<x@y> temporarily rejected RCPT <defer@y>: forcibly deferred
246 >>> using ACL "accept"
247 >>> processing "accept" (TESTSUITE/test-config 24)
248 >>> accept: condition test succeeded in ACL "accept"
249 >>> end of ACL "accept": ACCEPT
250 >>> using ACL "drop"
251 >>> processing "drop" (TESTSUITE/test-config 41)
252 >>>   message: forcibly dropped
253 >>> drop: condition test succeeded in ACL "drop"
254 >>> end of ACL "drop": DROP
255 LOG: H=(test) [V4NET.9.8.7] F=<x@y> rejected RCPT <drop@y>: forcibly dropped
256 LOG: SMTP connection from (test) [V4NET.9.8.7] closed by DROP in ACL
257 >>> host in hosts_connection_nolog? no (end of list)
258 LOG: SMTP connection from [V4NET.9.8.7]
259 >>> host in host_lookup? no (option unset)
260 >>> host in host_reject_connection? no (option unset)
261 >>> host in sender_unqualified_hosts? no (option unset)
262 >>> host in recipient_unqualified_hosts? no (option unset)
263 >>> host in helo_verify_hosts? no (option unset)
264 >>> host in helo_try_verify_hosts? no (option unset)
265 >>> host in helo_accept_junk_hosts? no (option unset)
266 >>> test in helo_lookup_domains? no (end of list)
267 >>> using ACL "defer_senders"
268 >>> processing "defer" (TESTSUITE/test-config 54)
269 >>> check senders = :
270 >>>  in ":"? yes (matched "")
271 >>> defer: condition test succeeded in ACL "defer_senders"
272 >>> end of ACL "defer_senders": DEFER
273 LOG: H=(test) [V4NET.9.8.7] F=<> temporarily rejected RCPT <defer_senders@y>
274 LOG: SMTP connection from (test) [V4NET.9.8.7] closed by QUIT
275 >>> host in hosts_connection_nolog? no (end of list)
276 LOG: SMTP connection from [V4NET.9.8.7]
277 >>> host in host_lookup? no (option unset)
278 >>> host in host_reject_connection? no (option unset)
279 >>> host in sender_unqualified_hosts? no (option unset)
280 >>> host in recipient_unqualified_hosts? no (option unset)
281 >>> host in helo_verify_hosts? no (option unset)
282 >>> host in helo_try_verify_hosts? no (option unset)
283 >>> host in helo_accept_junk_hosts? no (option unset)
284 >>> test in helo_lookup_domains? no (end of list)
285 >>> using ACL "delay_accept"
286 >>> processing "accept" (TESTSUITE/test-config 57)
287 >>> check delay = 1s
288 >>> delay modifier requests 1-second delay
289 >>> delay skipped in -bh checking mode
290 >>> accept: condition test succeeded in ACL "delay_accept"
291 >>> end of ACL "delay_accept": ACCEPT
292 >>> using ACL "delay_warn"
293 >>> processing "warn" (TESTSUITE/test-config 60)
294 >>> check delay = 1s
295 >>> delay modifier requests 1-second delay
296 >>> delay skipped in -bh checking mode
297 >>> warn: condition test succeeded in ACL "delay_warn"
298 >>> processing "accept" (TESTSUITE/test-config 61)
299 >>> accept: condition test succeeded in ACL "delay_warn"
300 >>> end of ACL "delay_warn": ACCEPT
301 LOG: SMTP connection from (test) [V4NET.9.8.7] closed by QUIT
302 >>> host in hosts_connection_nolog? no (end of list)
303 LOG: SMTP connection from [V4NET.9.8.7]
304 >>> host in host_lookup? no (option unset)
305 >>> host in host_reject_connection? no (option unset)
306 >>> host in sender_unqualified_hosts? no (option unset)
307 >>> host in recipient_unqualified_hosts? no (option unset)
308 >>> host in helo_verify_hosts? no (option unset)
309 >>> host in helo_try_verify_hosts? no (option unset)
310 >>> host in helo_accept_junk_hosts? no (option unset)
311 >>> test in helo_lookup_domains? no (end of list)
312 >>> using ACL "host_check"
313 >>> processing "deny" (TESTSUITE/test-config 71)
314 >>> check hosts = net-lsearch;TESTSUITE/aux-var/0022.hosts
315 >>> host in "net-lsearch;TESTSUITE/aux-var/0022.hosts"? yes (matched "net-lsearch;TESTSUITE/aux-var/0022.hosts")
316 >>>   message: host data >$host_data<
317 >>> deny: condition test succeeded in ACL "host_check"
318 >>> end of ACL "host_check": DENY
319 LOG: H=(test) [V4NET.9.8.7] F=<x@y> rejected RCPT <host_check@y>: host data >A host-specific message<
320 >>> using ACL "host_check"
321 >>> processing "deny" (TESTSUITE/test-config 71)
322 >>> check hosts = net-lsearch;TESTSUITE/aux-var/0022.hosts
323 >>> host in "net-lsearch;TESTSUITE/aux-var/0022.hosts"? yes (matched "net-lsearch;TESTSUITE/aux-var/0022.hosts")
324 >>>   message: host data >$host_data<
325 >>> deny: condition test succeeded in ACL "host_check"
326 >>> end of ACL "host_check": DENY
327 LOG: H=(test) [V4NET.9.8.7] F=<x@y> rejected RCPT <host_check@y>: host data >A host-specific message<
328 >>> using ACL "host_check2"
329 >>> processing "deny" (TESTSUITE/test-config 75)
330 >>>   message: host data >$host_data<
331 >>> check hosts = +some_hosts
332 >>> host in "net-lsearch;TESTSUITE/aux-var/0022.hosts"? yes (matched "net-lsearch;TESTSUITE/aux-var/0022.hosts")
333 >>> host in "+some_hosts"? yes (matched "+some_hosts")
334 >>> deny: condition test succeeded in ACL "host_check2"
335 >>> end of ACL "host_check2": DENY
336 LOG: H=(test) [V4NET.9.8.7] F=<x@y> rejected RCPT <host_check2@y>: host data >A host-specific message<
337 >>> using ACL "host_check2"
338 >>> processing "deny" (TESTSUITE/test-config 75)
339 >>>   message: host data >$host_data<
340 >>> check hosts = +some_hosts
341 >>> host in "+some_hosts"? yes (matched "+some_hosts" - cached)
342 >>> deny: condition test succeeded in ACL "host_check2"
343 >>> end of ACL "host_check2": DENY
344 LOG: H=(test) [V4NET.9.8.7] F=<x@y> rejected RCPT <host_check2@y>: host data >A host-specific message<
345 LOG: SMTP connection from (test) [V4NET.9.8.7] closed by QUIT
346 LOG: smtp_connection MAIN
347   SMTP connection from CALLER
348 LOG: MAIN
349   Connections=0
350 LOG: MAIN
351   <= CALLER@test.ex U=CALLER P=local-smtp S=sss
352 LOG: MAIN
353   frozen by ACL
354 LOG: MAIN
355   <= CALLER@test.ex U=CALLER P=local-smtp S=sss
356 delivering 10HmaY-0005vi-00
357 LOG: MAIN
358   *> accept <accept@y> R=accept T=appendfile
359 LOG: MAIN
360   Completed
361 LOG: MAIN
362   <= CALLER@test.ex U=CALLER P=local-smtp S=sss
363 LOG: delay_delivery MAIN
364   no immediate delivery: queued by ACL
365 LOG: MAIN
366   <= CALLER@test.ex U=CALLER P=local-smtp S=sss
367 delivering 10HmbA-0005vi-00
368 LOG: MAIN
369   *> accept <accept@y> R=accept T=appendfile
370 LOG: MAIN
371   Completed
372 LOG: smtp_connection MAIN
373   SMTP connection from CALLER closed by QUIT
374 >>> host in hosts_connection_nolog? no (end of list)
375 LOG: SMTP connection from [V4NET.9.8.7]
376 >>> host in host_lookup? no (option unset)
377 >>> host in host_reject_connection? no (option unset)
378 >>> host in sender_unqualified_hosts? no (option unset)
379 >>> host in recipient_unqualified_hosts? no (option unset)
380 >>> host in helo_verify_hosts? no (option unset)
381 >>> host in helo_try_verify_hosts? no (option unset)
382 >>> host in helo_accept_junk_hosts? no (option unset)
383 >>> test in helo_lookup_domains? no (end of list)
384 >>> using ACL "nested_drop"
385 >>> processing "accept" (TESTSUITE/test-config 44)
386 >>> check acl = drop
387 >>>  using ACL "drop"
388 >>>  processing "drop" (TESTSUITE/test-config 41)
389 >>>    message: forcibly dropped
390 >>>  drop: condition test succeeded in ACL "drop"
391 >>>  end of ACL "drop": DROP
392 >>> accept: condition test yielded "drop" in ACL "nested_drop"
393 >>> accept: endpass encountered - denying access
394 LOG: H=(test) [V4NET.9.8.7] F=<x@y> rejected RCPT <nested_drop@y>: forcibly dropped
395 LOG: SMTP connection from (test) [V4NET.9.8.7] closed by DROP in ACL
396 >>> host in hosts_connection_nolog? no (end of list)
397 LOG: SMTP connection from [V4NET.9.8.7]
398 >>> host in host_lookup? no (option unset)
399 >>> host in host_reject_connection? no (option unset)
400 >>> host in sender_unqualified_hosts? no (option unset)
401 >>> host in recipient_unqualified_hosts? no (option unset)
402 >>> host in helo_verify_hosts? no (option unset)
403 >>> host in helo_try_verify_hosts? no (option unset)
404 >>> host in helo_accept_junk_hosts? no (option unset)
405 >>> test in helo_lookup_domains? no (end of list)
406 >>> using ACL "nested_drop_require"
407 >>> processing "require" (TESTSUITE/test-config 48)
408 >>> check acl = drop
409 >>>  using ACL "drop"
410 >>>  processing "drop" (TESTSUITE/test-config 41)
411 >>>    message: forcibly dropped
412 >>>  drop: condition test succeeded in ACL "drop"
413 >>>  end of ACL "drop": DROP
414 >>> require: condition test yielded "drop" in ACL "nested_drop_require"
415 >>> end of ACL "nested_drop_require": not OK
416 LOG: H=(test) [V4NET.9.8.7] F=<x@y> rejected RCPT <nested_drop_require@y>: forcibly dropped
417 LOG: SMTP connection from (test) [V4NET.9.8.7] closed by DROP in ACL
418
419 ******** SERVER ********