Logging: fix initial listening-on log line
[exim.git] / test / stderr / 0432
1 >>> host in hosts_connection_nolog? no (option unset)
2 >>> host in host_lookup? no (option unset)
3 >>> host in host_reject_connection? no (option unset)
4 >>> host in sender_unqualified_hosts? no (option unset)
5 >>> host in recipient_unqualified_hosts? no (option unset)
6 >>> host in helo_verify_hosts? no (option unset)
7 >>> host in helo_try_verify_hosts? no (option unset)
8 >>> host in helo_accept_junk_hosts? no (option unset)
9 >>> using ACL "mail"
10 >>> processing "accept"
11 >>> check verify = sender/callout=1s,maxwait=1s
12 >>> >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
13 >>> routing x@y
14 >>> calling r1 router
15 >>> routed by r1 router
16 >>> local host found for non-MX address
17 MUNGED: ::1 will be omitted in what follows
18 >>> get[host|ipnode]byname[2] looked up these IP addresses:
19 >>>   name=127.0.0.1 address=127.0.0.1
20 >>> Attempting full verification using callout
21 >>> ... callout omitted by default when host testing
22 >>> (Use -bhc if you want the callouts to happen.)
23 >>> ----------- end verify ------------
24 >>> accept: condition test succeeded in ACL "mail"
25 >>> end of ACL "mail": ACCEPT
26 Exim version x.yz ....
27 changed uid/gid: forcing real = effective
28   uid=uuuu gid=CALLER_GID pid=pppp
29 configuration file is TESTSUITE/test-config
30 admin user
31 changed uid/gid: privilege not needed
32   uid=EXIM_UID gid=EXIM_GID pid=pppp
33 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
34 sender address = CALLER@myhost.test.ex
35 sender_fullhost = [1.2.3.4]
36 sender_rcvhost = [1.2.3.4]
37 host in hosts_connection_nolog? no (option unset)
38 LOG: smtp_connection MAIN
39   SMTP connection from [1.2.3.4]
40 host in host_lookup? no (option unset)
41 set_process_info: pppp handling incoming connection from [1.2.3.4]
42 host in host_reject_connection? no (option unset)
43 host in sender_unqualified_hosts? no (option unset)
44 host in recipient_unqualified_hosts? no (option unset)
45 host in helo_verify_hosts? no (option unset)
46 host in helo_try_verify_hosts? no (option unset)
47 host in helo_accept_junk_hosts? no (option unset)
48 SMTP>> 220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000
49 smtp_setup_msg entered
50 SMTP<< mail from:<x@y>
51 spool directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100 msg_size = 0
52 log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
53 using ACL "mail"
54 processing "accept"
55 check verify = sender/callout=1s,maxwait=1s
56 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
57 Verifying x@y
58 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
59 Considering x@y
60 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
61 routing x@y
62 --------> r1 router <--------
63 local_part=x domain=y
64 calling r1 router
65 r1 router called for x@y
66   domain = y
67 set transport t1
68 queued for t1 transport: local_part = x
69 domain = y
70   errors_to=NULL
71   domain_data=NULL localpart_data=NULL
72 routed by r1 router
73   envelope to: x@y
74   transport: t1
75 using host_fake_gethostbyname for 127.0.0.1 (IPv4)
76 local host found for non-MX address
77 MUNGED: ::1 will be omitted in what follows
78 get[host|ipnode]byname[2] looked up these IP addresses:
79   name=127.0.0.1 address=127.0.0.1
80 Attempting full verification using callout
81  locking TESTSUITE/spool/db/callout.lockfile
82  locked  TESTSUITE/spool/db/callout.lockfile
83  EXIM_DBOPEN: file <TESTSUITE/spool/db/callout> dir <TESTSUITE/spool/db> flags=O_RDWR
84  returned from EXIM_DBOPEN: 0xAAAAAAAA
85  opened hints database TESTSUITE/spool/db/callout: flags=O_RDWR
86  dbfn_read: key=y
87 callout cache: no domain record found for y
88  dbfn_read: key=x@y
89 callout cache: no address record found for x@y
90  EXIM_DBCLOSE(0xAAAAAAAA)
91  closed hints database and lockfile
92 interface=NULL port=1224
93 Connecting to 127.0.0.1 [127.0.0.1]:1224 ... connected
94   SMTP<< 220 server ready
95 127.0.0.1 in hosts_avoid_esmtp? no (option unset)
96   SMTP>> EHLO myhost.test.ex
97 cmd buf flush ddd bytes
98   SMTP<< 250 OK
99 not using PIPELINING
100 not using DSN
101 127.0.0.1 in hosts_require_auth? no (option unset)
102   SMTP>> MAIL FROM:<>
103 cmd buf flush ddd bytes
104   SMTP<< 250 OK
105   SMTP>> RCPT TO:<x@y>
106 cmd buf flush ddd bytes
107 sync_responses expect rcpt
108   SMTP<< 250 OK
109   SMTP>> QUIT
110 cmd buf flush ddd bytes
111   SMTP<< 220 OK
112   SMTP(close)>>
113  locking TESTSUITE/spool/db/callout.lockfile
114  locked  TESTSUITE/spool/db/callout.lockfile
115  EXIM_DBOPEN: file <TESTSUITE/spool/db/callout> dir <TESTSUITE/spool/db> flags=O_RDWR|O_CREAT
116  returned from EXIM_DBOPEN: 0xAAAAAAAA
117  opened hints database TESTSUITE/spool/db/callout: flags=O_RDWR|O_CREAT
118  dbfn_write: key=y
119 wrote callout cache domain record for y:
120   result=1 postmaster=0 random=0
121  dbfn_write: key=x@y
122 wrote positive callout cache address record for x@y
123  EXIM_DBCLOSE(0xAAAAAAAA)
124  closed hints database and lockfile
125 ----------- end verify ------------
126 sender x@y verified ok
127 accept: condition test succeeded in ACL "mail"
128 end of ACL "mail": ACCEPT
129 SMTP>> 250 OK
130 SMTP<< quit
131 SMTP>> 221 myhost.test.ex closing connection
132 LOG: smtp_connection MAIN
133   SMTP connection from [1.2.3.4] closed by QUIT
134 search_tidyup called
135 >>>>>>>>>>>>>>>> Exim pid=pppp (main) terminating with rc=0 >>>>>>>>>>>>>>>>
136 Exim version x.yz ....
137 changed uid/gid: forcing real = effective
138   uid=uuuu gid=CALLER_GID pid=pppp
139 configuration file is TESTSUITE/test-config
140 admin user
141 changed uid/gid: privilege not needed
142   uid=EXIM_UID gid=EXIM_GID pid=pppp
143 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
144 sender address = CALLER@myhost.test.ex
145 sender_fullhost = [1.2.3.4]
146 sender_rcvhost = [1.2.3.4]
147 host in hosts_connection_nolog? no (option unset)
148 LOG: smtp_connection MAIN
149   SMTP connection from [1.2.3.4]
150 host in host_lookup? no (option unset)
151 set_process_info: pppp handling incoming connection from [1.2.3.4]
152 host in host_reject_connection? no (option unset)
153 host in sender_unqualified_hosts? no (option unset)
154 host in recipient_unqualified_hosts? no (option unset)
155 host in helo_verify_hosts? no (option unset)
156 host in helo_try_verify_hosts? no (option unset)
157 host in helo_accept_junk_hosts? no (option unset)
158 SMTP>> 220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000
159 smtp_setup_msg entered
160 SMTP<< mail from:<x@y>
161 spool directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100 msg_size = 0
162 log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
163 using ACL "mail"
164 processing "accept"
165 check verify = sender/callout=1s,maxwait=1s
166 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
167 Verifying x@y
168 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
169 Considering x@y
170 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
171 routing x@y
172 --------> r1 router <--------
173 local_part=x domain=y
174 calling r1 router
175 r1 router called for x@y
176   domain = y
177 set transport t1
178 queued for t1 transport: local_part = x
179 domain = y
180   errors_to=NULL
181   domain_data=NULL localpart_data=NULL
182 routed by r1 router
183   envelope to: x@y
184   transport: t1
185 using host_fake_gethostbyname for 127.0.0.1 (IPv4)
186 local host found for non-MX address
187 MUNGED: ::1 will be omitted in what follows
188 get[host|ipnode]byname[2] looked up these IP addresses:
189   name=127.0.0.1 address=127.0.0.1
190 Attempting full verification using callout
191  locking TESTSUITE/spool/db/callout.lockfile
192  locked  TESTSUITE/spool/db/callout.lockfile
193  EXIM_DBOPEN: file <TESTSUITE/spool/db/callout> dir <TESTSUITE/spool/db> flags=O_RDWR
194  returned from EXIM_DBOPEN: 0xAAAAAAAA
195  opened hints database TESTSUITE/spool/db/callout: flags=O_RDWR
196  dbfn_read: key=y
197 callout cache: found domain record for y
198  dbfn_read: key=x@y
199 callout cache: found address record for x@y
200 callout cache: address record is positive
201  EXIM_DBCLOSE(0xAAAAAAAA)
202  closed hints database and lockfile
203 ----------- end verify ------------
204 sender x@y verified ok
205 accept: condition test succeeded in ACL "mail"
206 end of ACL "mail": ACCEPT
207 SMTP>> 250 OK
208 SMTP<< quit
209 SMTP>> 221 myhost.test.ex closing connection
210 LOG: smtp_connection MAIN
211   SMTP connection from [1.2.3.4] closed by QUIT
212 search_tidyup called
213 >>>>>>>>>>>>>>>> Exim pid=pppp (main) terminating with rc=0 >>>>>>>>>>>>>>>>
214 >>> host in hosts_connection_nolog? no (option unset)
215 >>> host in host_lookup? no (option unset)
216 >>> host in host_reject_connection? no (option unset)
217 >>> host in sender_unqualified_hosts? no (option unset)
218 >>> host in recipient_unqualified_hosts? no (option unset)
219 >>> host in helo_verify_hosts? no (option unset)
220 >>> host in helo_try_verify_hosts? no (option unset)
221 >>> host in helo_accept_junk_hosts? no (option unset)
222 >>> using ACL "mail"
223 >>> processing "accept"
224 >>> check verify = sender/callout=1s,maxwait=1s
225 >>> >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
226 >>> routing x@y
227 >>> calling r1 router
228 >>> routed by r1 router
229 >>> local host found for non-MX address
230 MUNGED: ::1 will be omitted in what follows
231 >>> get[host|ipnode]byname[2] looked up these IP addresses:
232 >>>   name=127.0.0.1 address=127.0.0.1
233 >>> Attempting full verification using callout
234 >>> callout cache: found domain record for y
235 >>> callout cache: found address record for x@y
236 >>> callout cache: address record is positive
237 >>> ----------- end verify ------------
238 >>> accept: condition test succeeded in ACL "mail"
239 >>> end of ACL "mail": ACCEPT
240 >>> host in hosts_connection_nolog? no (option unset)
241 >>> host in host_lookup? no (option unset)
242 >>> host in host_reject_connection? no (option unset)
243 >>> host in sender_unqualified_hosts? no (option unset)
244 >>> host in recipient_unqualified_hosts? no (option unset)
245 >>> host in helo_verify_hosts? no (option unset)
246 >>> host in helo_try_verify_hosts? no (option unset)
247 >>> host in helo_accept_junk_hosts? no (option unset)
248 >>> using ACL "mail"
249 >>> processing "accept"
250 >>> check verify = sender/callout=1s,maxwait=1s
251 >>> >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
252 >>> routing a@b
253 >>> calling r1 router
254 >>> routed by r1 router
255 >>> local host found for non-MX address
256 MUNGED: ::1 will be omitted in what follows
257 >>> get[host|ipnode]byname[2] looked up these IP addresses:
258 >>>   name=127.0.0.1 address=127.0.0.1
259 >>> Attempting full verification using callout
260 >>> callout cache: no domain record found for b
261 >>> callout cache: no address record found for a@b
262 >>> interface=NULL port=1224
263 >>> Connecting to 127.0.0.1 [127.0.0.1]:1224 ... connected
264 >>>   SMTP<< 220 server ready
265 >>> 127.0.0.1 in hosts_avoid_esmtp? no (option unset)
266 >>>   SMTP>> EHLO myhost.test.ex
267 >>> cmd buf flush 21 bytes
268 >>>   SMTP<< 250 OK
269 >>> 127.0.0.1 in hosts_require_auth? no (option unset)
270 >>>   SMTP>> MAIL FROM:<>
271 >>> cmd buf flush 14 bytes
272 >>>   SMTP<< 250 OK
273 >>>   SMTP>> RCPT TO:<a@b>
274 >>> cmd buf flush 15 bytes
275 >>>   SMTP<< 250 OK
276 >>>   SMTP>> QUIT
277 >>> cmd buf flush 6 bytes
278 >>>   SMTP<< 220 OK
279 >>>   SMTP(close)>>
280 >>> wrote callout cache domain record for b:
281 >>>   result=1 postmaster=0 random=0
282 >>> wrote positive callout cache address record for a@b
283 >>> ----------- end verify ------------
284 >>> accept: condition test succeeded in ACL "mail"
285 >>> end of ACL "mail": ACCEPT
286 >>> host in hosts_connection_nolog? no (option unset)
287 >>> host in host_lookup? no (option unset)
288 >>> host in host_reject_connection? no (option unset)
289 >>> host in sender_unqualified_hosts? no (option unset)
290 >>> host in recipient_unqualified_hosts? no (option unset)
291 >>> host in helo_verify_hosts? no (option unset)
292 >>> host in helo_try_verify_hosts? no (option unset)
293 >>> host in helo_accept_junk_hosts? no (option unset)
294 >>> using ACL "mail"
295 >>> processing "accept"
296 >>> check verify = sender/callout=1s,maxwait=1s
297 >>> >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
298 >>> routing p1@q
299 >>> calling r1 router
300 >>> routed by r1 router
301 >>> local host found for non-MX address
302 MUNGED: ::1 will be omitted in what follows
303 >>> get[host|ipnode]byname[2] looked up these IP addresses:
304 >>>   name=127.0.0.1 address=127.0.0.1
305 >>> Attempting full verification using callout
306 >>> callout cache: no domain record found for q
307 >>> callout cache: no address record found for p1@q
308 >>> interface=NULL port=1224
309 >>> Connecting to 127.0.0.1 [127.0.0.1]:1224 ... connected
310 >>>   SMTP<< 220 server ready
311 >>> 127.0.0.1 in hosts_avoid_esmtp? no (option unset)
312 >>>   SMTP>> EHLO myhost.test.ex
313 >>> cmd buf flush 21 bytes
314 >>>   SMTP(close)>>
315 >>> SMTP timeout
316 >>> ----------- end verify ------------
317 >>> accept: condition test deferred in ACL "mail"
318 LOG: H=[1.2.3.4] sender verify defer for <p1@q>: Could not complete sender verify callout: 127.0.0.1 [127.0.0.1] : SMTP timeout after EHLO myhost.test.ex
319 LOG: H=[1.2.3.4] temporarily rejected MAIL <p1@q>: Could not complete sender verify callout