test/stderr/0386

   1 Exim version x.yz ....
   2 changed uid/gid: forcing real = effective
   3   uid=uuuu gid=CALLER_GID pid=pppp
   4 seeking password data for user "CALLER": cache not available
   5 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
   6 configuration file is TESTSUITE/test-config
   7 trusted user
   8 admin user
   9 changed uid/gid: privilege not needed
  10   uid=EXIM_UID gid=EXIM_GID pid=pppp
  11 seeking password data for user "CALLER": using cached result
  12 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
  13 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
  14 sender address = CALLER@test.ex
  15 sender_fullhost = [V4NET.9.8.7]
  16 sender_rcvhost = [V4NET.9.8.7]
  17 host in hosts_connection_nolog? no (option unset)
  18 LOG: smtp_connection MAIN
  19   SMTP connection from [V4NET.9.8.7]
  20 host in host_lookup? no (option unset)
  21 set_process_info: pppp handling incoming connection from [V4NET.9.8.7]
  22 host in host_reject_connection? no (option unset)
  23 host in sender_unqualified_hosts? no (option unset)
  24 host in recipient_unqualified_hosts? no (option unset)
  25 host in helo_verify_hosts? no (option unset)
  26 host in helo_try_verify_hosts? no (option unset)
  27 host in helo_accept_junk_hosts? no (option unset)
  28 SMTP>> 220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000
  29 smtp_setup_msg entered
  30 SMTP<< mail from:<x@y>
  31 SMTP>> 250 OK
  32 SMTP<< rcpt to:<1@b>
  33 read ACL from file TESTSUITE/aux-fixed/0386.acl1
  34 processing "accept"
  35 check hosts = :
  36 host in ":"? no (end of list)
  37 accept: condition test failed in ACL "TESTSUITE/aux-fixed/0386.acl1"
  38 processing "deny"
  39 check local_parts = ^.*[@%!/|]
  40 1 in "^.*[@%!/|]"? no (end of list)
  41 deny: condition test failed in ACL "TESTSUITE/aux-fixed/0386.acl1"
  42 processing "require"
  43 check verify = sender/defer_ok
  44 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
  45 Verifying x@y
  46 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
  47 Considering x@y
  48 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
  49 routing x@y
  50 --------> r1 router <--------
  51 local_part=x domain=y
  52 calling r1 router
  53 r1 router called for x@y
  54   domain = y
  55 set transport t1
  56 queued for t1 transport: local_part = x
  57 domain = y
  58   errors_to=NULL
  59   domain_data=NULL localpart_data=NULL
  60 routed by r1 router
  61   envelope to: x@y
  62   transport: t1
  63 ----------- end verify ------------
  64 sender x@y verified ok
  65 require: condition test succeeded in ACL "TESTSUITE/aux-fixed/0386.acl1"
  66 processing "deny"
  67 deny: condition test succeeded in ACL "TESTSUITE/aux-fixed/0386.acl1"
  68 SMTP>> 550 No such user here
  69 LOG: MAIN REJECT
  70   H=[V4NET.9.8.7] F=<x@y> rejected RCPT <1@b>: No such user here
  71 SMTP<< rset
  72 SMTP>> 250 Reset OK
  73 SMTP<< mail from:<x@y>
  74 SMTP>> 250 OK
  75 SMTP<< rcpt to:<1@b>
  76 using ACL "TESTSUITE/aux-fixed/0386.acl1"
  77 processing "accept"
  78 check hosts = :
  79 host in ":"? no (end of list)
  80 accept: condition test failed in ACL "TESTSUITE/aux-fixed/0386.acl1"
  81 processing "deny"
  82 check local_parts = ^.*[@%!/|]
  83 1 in "^.*[@%!/|]"? no (end of list)
  84 deny: condition test failed in ACL "TESTSUITE/aux-fixed/0386.acl1"
  85 processing "require"
  86 check verify = sender/defer_ok
  87 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
  88 Verifying x@y
  89 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
  90 Considering x@y
  91 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
  92 routing x@y
  93 --------> r1 router <--------
  94 local_part=x domain=y
  95 calling r1 router
  96 r1 router called for x@y
  97   domain = y
  98 queued for t1 transport: local_part = x
  99 domain = y
 100   errors_to=NULL
 101   domain_data=NULL localpart_data=NULL
 102 routed by r1 router
 103   envelope to: x@y
 104   transport: t1
 105 ----------- end verify ------------
 106 sender x@y verified ok
 107 require: condition test succeeded in ACL "TESTSUITE/aux-fixed/0386.acl1"
 108 processing "deny"
 109 deny: condition test succeeded in ACL "TESTSUITE/aux-fixed/0386.acl1"
 110 SMTP>> 550 No such user here
 111 LOG: MAIN REJECT
 112   H=[V4NET.9.8.7] F=<x@y> rejected RCPT <1@b>: No such user here
 113 SMTP<< quit
 114 SMTP>> 221 myhost.test.ex closing connection
 115 LOG: smtp_connection MAIN
 116   SMTP connection from [V4NET.9.8.7] closed by QUIT
 117 search_tidyup called
 118 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
 119 Exim version x.yz ....
 120 changed uid/gid: forcing real = effective
 121   uid=uuuu gid=CALLER_GID pid=pppp
 122 seeking password data for user "CALLER": cache not available
 123 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 124 configuration file is TESTSUITE/test-config
 125 trusted user
 126 admin user
 127 changed uid/gid: privilege not needed
 128   uid=EXIM_UID gid=EXIM_GID pid=pppp
 129 seeking password data for user "CALLER": using cached result
 130 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 131 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 132 sender address = NULL
 133 sender_fullhost = [V4NET.11.12.13]
 134 sender_rcvhost = [V4NET.11.12.13] (ident=CALLER)
 135 set_process_info: pppp handling incoming connection from [V4NET.11.12.13] via -oMa
 136 set_process_info: pppp accepting a local SMTP message from <CALLER>
 137 host in hosts_connection_nolog? no (option unset)
 138 LOG: smtp_connection MAIN
 139   SMTP connection from CALLER
 140 host in host_lookup? no (option unset)
 141 set_process_info: pppp handling incoming connection from [V4NET.11.12.13] U=CALLER
 142 host in host_reject_connection? no (option unset)
 143 host in sender_unqualified_hosts? no (option unset)
 144 host in recipient_unqualified_hosts? no (option unset)
 145 host in helo_verify_hosts? no (option unset)
 146 host in helo_try_verify_hosts? no (option unset)
 147 host in helo_accept_junk_hosts? no (option unset)
 148 SMTP>> 220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000
 149 smtp_setup_msg entered
 150 SMTP<< mail from:<x@y>
 151 SMTP>> 250 OK
 152 SMTP<< rcpt to:<2@b>
 153 read ACL from file TESTSUITE/aux-fixed/0386.acl2
 154 processing "warn"
 155 check dnslists = rbl.test.ex
 156 DNS list check: rbl.test.ex
 157 new DNS lookup for 13.12.11.V4NET.rbl.test.ex
 158 DNS lookup of 13.12.11.V4NET.rbl.test.ex (A) using fakens
 159 DNS lookup of 13.12.11.V4NET.rbl.test.ex (A) succeeded
 160 DNS lookup for 13.12.11.V4NET.rbl.test.ex succeeded (yielding 127.0.0.2)
 161 DNS lookup of 13.12.11.V4NET.rbl.test.ex (TXT) using fakens
 162 DNS lookup of 13.12.11.V4NET.rbl.test.ex (TXT) succeeded
 163 => that means V4NET.11.12.13 is listed at rbl.test.ex
 164 warn: condition test succeeded in ACL "TESTSUITE/aux-fixed/0386.acl2"
 165 LOG: MAIN
 166   H=[V4NET.11.12.13] U=CALLER Warning: found in rbl.test.ex: This is a test blacklisting message
 167 created log directory TESTSUITE/spool/log
 168 processing "accept"
 169 accept: condition test succeeded in ACL "TESTSUITE/aux-fixed/0386.acl2"
 170 SMTP>> 250 Accepted
 171 SMTP<< data
 172 SMTP>> 354 Enter message, ending with "." on a line by itself
 173 search_tidyup called
 174 host in ignore_fromline_hosts? no (option unset)
 175 >>Headers received:
 176
 177 search_tidyup called
 178 >>Headers after rewriting and local additions:
 179
 180 Data file written for message 10HmaX-0005vi-00
 181 >>Generated Received: header line
 182 P Received: from [V4NET.11.12.13] (ident=CALLER)
 183         by myhost.test.ex with smtp (Exim x.yz)
 184         (envelope-from <x@y>)
 185         id 10HmaX-0005vi-00
 186         for 2@b; Tue, 2 Mar 1999 09:44:33 +0000
 187 >>Headers added by MAIL or RCPT ACL:
 188   X-Warning: V4NET.11.12.13 is listed at rbl.test.ex
 189   X-Warning: This is a test blacklisting message
 190 >>
 191 calling local_scan(); timeout=300
 192 local_scan() returned 0 NULL
 193 Writing spool header file
 194 Size of headers = sss
 195 LOG: MAIN
 196   <= x@y H=[V4NET.11.12.13] U=CALLER P=smtp S=sss
 197 SMTP>> 250 OK id=10HmaX-0005vi-00
 198 search_tidyup called
 199 exec TESTSUITE/eximdir/exim -DEXIM_PATH=TESTSUITE/eximdir/exim -C TESTSUITE/test-config -d=0xfbb95cfd -odi -Mc 10HmaX-0005vi-00
 200 Exim version x.yz ....
 201 changed uid/gid: forcing real = effective
 202   uid=uuuu gid=EXIM_GID pid=pppp
 203 seeking password data for user "CALLER": cache not available
 204 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 205 configuration file is TESTSUITE/test-config
 206 trusted user
 207 admin user
 208 seeking password data for user "CALLER": using cached result
 209 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 210 set_process_info: pppp delivering specified messages
 211 set_process_info: pppp delivering 10HmaX-0005vi-00
 212 reading spool file 10HmaX-0005vi-00-H
 213 user=CALLER uid=CALLER_UID gid=CALLER_GID sender=x@y
 214 sender_fullhost = [V4NET.11.12.13]
 215 sender_rcvhost = [V4NET.11.12.13] (ident=CALLER)
 216 sender_local=0 ident=CALLER
 217 Non-recipients:
 218 Empty Tree
 219 ---- End of tree ----
 220 recipients_count=1
 221 body_linecount=1 message_linecount=7
 222 Delivery address list:
 223   2@b
 224 locking TESTSUITE/spool/db/retry.lockfile
 225 locked TESTSUITE/spool/db/retry.lockfile
 226 EXIM_DBOPEN(TESTSUITE/spool/db/retry)
 227 returned from EXIM_DBOPEN
 228 ensuring TESTSUITE/spool/db/retry.lockfile is owned by exim
 229 no retry data available
 230 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
 231 Considering: 2@b
 232 unique = 2@b
 233 no domain retry record
 234 no address retry record
 235 2@b: queued for routing
 236 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
 237 routing 2@b
 238 --------> r1 router <--------
 239 local_part=2 domain=b
 240 calling r1 router
 241 r1 router called for 2@b
 242   domain = b
 243 set transport t1
 244 queued for t1 transport: local_part = 2
 245 domain = b
 246   errors_to=NULL
 247   domain_data=NULL localpart_data=NULL
 248 routed by r1 router
 249   envelope to: 2@b
 250   transport: t1
 251 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
 252 After routing:
 253   Local deliveries:
 254     2@b
 255   Remote deliveries:
 256   Failed addresses:
 257   Deferred addresses:
 258 search_tidyup called
 259 >>>>>>>>>>>>>>>> Local deliveries >>>>>>>>>>>>>>>>
 260 --------> 2@b <--------
 261 locking TESTSUITE/spool/db/retry.lockfile
 262 locked TESTSUITE/spool/db/retry.lockfile
 263 EXIM_DBOPEN(TESTSUITE/spool/db/retry)
 264 returned from EXIM_DBOPEN
 265 no retry data available
 266 search_tidyup called
 267 changed uid/gid: local delivery to 2 <2@b> transport=t1
 268   uid=CALLER_UID gid=CALLER_GID pid=pppp
 269   home=NULL current=/
 270 set_process_info: pppp delivering 10HmaX-0005vi-00 to 2 using t1
 271 appendfile transport entered
 272 appendfile: mode=600 notify_comsat=0 quota=0 warning=0
 273   file=TESTSUITE/test-mail/2 format=unix
 274   message_prefix=From ${if def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}\n
 275   message_suffix=\n
 276   maildir_use_size_file=no
 277   locking by lockfile fcntl
 278 lock name: TESTSUITE/test-mail/2.lock
 279 hitch name: TESTSUITE/test-mail/2.lock.test.ex.dddddddd.pppppppp
 280 lock file created
 281 mailbox TESTSUITE/test-mail/2 is locked
 282 writing to file TESTSUITE/test-mail/2
 283 writing data block fd=dddd size=sss timeout=0
 284 writing data block fd=dddd size=sss timeout=0
 285 writing data block fd=dddd size=sss timeout=0
 286 appendfile yields 0 with errno=dd more_errno=dd
 287 search_tidyup called
 288 journalling 2@b
 289 t1 transport returned OK for 2@b
 290 post-process 2@b (0)
 291 2@b delivered
 292 LOG: MAIN
 293   => 2 <2@b> R=r1 T=t1
 294 >>>>>>>>>>>>>>>> deliveries are done >>>>>>>>>>>>>>>>
 295 changed uid/gid: post-delivery tidying
 296   uid=EXIM_UID gid=EXIM_GID pid=pppp
 297 set_process_info: pppp tidying up after delivering 10HmaX-0005vi-00
 298 Processing retry items
 299 Succeeded addresses:
 300 2@b: no retry items
 301 Failed addresses:
 302 Deferred addresses:
 303 end of retry processing
 304 LOG: MAIN
 305   Completed
 306 end delivery of 10HmaX-0005vi-00
 307 search_tidyup called
 308 search_tidyup called
 309 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
 310 smtp_setup_msg entered
 311 SMTP<< rset
 312 SMTP>> 250 Reset OK
 313 SMTP<< mail from:<x@y>
 314 SMTP>> 250 OK
 315 SMTP<< rcpt to:<2@b>
 316 using ACL "TESTSUITE/aux-fixed/0386.acl2"
 317 processing "warn"
 318 check dnslists = rbl.test.ex
 319 DNS list check: rbl.test.ex
 320 using result of previous DNS lookup
 321 DNS lookup for 13.12.11.V4NET.rbl.test.ex succeeded (yielding 127.0.0.2)
 322 => that means V4NET.11.12.13 is listed at rbl.test.ex
 323 warn: condition test succeeded in ACL "TESTSUITE/aux-fixed/0386.acl2"
 324 LOG: MAIN
 325   H=[V4NET.11.12.13] U=CALLER Warning: found in rbl.test.ex: This is a test blacklisting message
 326 processing "accept"
 327 accept: condition test succeeded in ACL "TESTSUITE/aux-fixed/0386.acl2"
 328 SMTP>> 250 Accepted
 329 SMTP<< data
 330 SMTP>> 354 Enter message, ending with "." on a line by itself
 331 search_tidyup called
 332 host in ignore_fromline_hosts? no (option unset)
 333 >>Headers received:
 334
 335 search_tidyup called
 336 >>Headers after rewriting and local additions:
 337
 338 Data file written for message 10HmaY-0005vi-00
 339 >>Generated Received: header line
 340 P Received: from [V4NET.11.12.13] (ident=CALLER)
 341         by myhost.test.ex with smtp (Exim x.yz)
 342         (envelope-from <x@y>)
 343         id 10HmaY-0005vi-00
 344         for 2@b; Tue, 2 Mar 1999 09:44:33 +0000
 345 >>Headers added by MAIL or RCPT ACL:
 346   X-Warning: V4NET.11.12.13 is listed at rbl.test.ex
 347   X-Warning: This is a test blacklisting message
 348 >>
 349 calling local_scan(); timeout=300
 350 local_scan() returned 0 NULL
 351 Writing spool header file
 352 Size of headers = sss
 353 LOG: MAIN
 354   <= x@y H=[V4NET.11.12.13] U=CALLER P=smtp S=sss
 355 SMTP>> 250 OK id=10HmaY-0005vi-00
 356 search_tidyup called
 357 exec TESTSUITE/eximdir/exim -DEXIM_PATH=TESTSUITE/eximdir/exim -C TESTSUITE/test-config -d=0xfbb95cfd -odi -Mc 10HmaY-0005vi-00
 358 Exim version x.yz ....
 359 changed uid/gid: forcing real = effective
 360   uid=uuuu gid=EXIM_GID pid=pppp
 361 seeking password data for user "CALLER": cache not available
 362 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 363 configuration file is TESTSUITE/test-config
 364 trusted user
 365 admin user
 366 seeking password data for user "CALLER": using cached result
 367 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 368 set_process_info: pppp delivering specified messages
 369 set_process_info: pppp delivering 10HmaY-0005vi-00
 370 reading spool file 10HmaY-0005vi-00-H
 371 user=CALLER uid=CALLER_UID gid=CALLER_GID sender=x@y
 372 sender_fullhost = [V4NET.11.12.13]
 373 sender_rcvhost = [V4NET.11.12.13] (ident=CALLER)
 374 sender_local=0 ident=CALLER
 375 Non-recipients:
 376 Empty Tree
 377 ---- End of tree ----
 378 recipients_count=1
 379 body_linecount=1 message_linecount=7
 380 Delivery address list:
 381   2@b
 382 locking TESTSUITE/spool/db/retry.lockfile
 383 locked TESTSUITE/spool/db/retry.lockfile
 384 EXIM_DBOPEN(TESTSUITE/spool/db/retry)
 385 returned from EXIM_DBOPEN
 386 no retry data available
 387 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
 388 Considering: 2@b
 389 unique = 2@b
 390 no domain retry record
 391 no address retry record
 392 2@b: queued for routing
 393 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
 394 routing 2@b
 395 --------> r1 router <--------
 396 local_part=2 domain=b
 397 calling r1 router
 398 r1 router called for 2@b
 399   domain = b
 400 set transport t1
 401 queued for t1 transport: local_part = 2
 402 domain = b
 403   errors_to=NULL
 404   domain_data=NULL localpart_data=NULL
 405 routed by r1 router
 406   envelope to: 2@b
 407   transport: t1
 408 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
 409 After routing:
 410   Local deliveries:
 411     2@b
 412   Remote deliveries:
 413   Failed addresses:
 414   Deferred addresses:
 415 search_tidyup called
 416 >>>>>>>>>>>>>>>> Local deliveries >>>>>>>>>>>>>>>>
 417 --------> 2@b <--------
 418 locking TESTSUITE/spool/db/retry.lockfile
 419 locked TESTSUITE/spool/db/retry.lockfile
 420 EXIM_DBOPEN(TESTSUITE/spool/db/retry)
 421 returned from EXIM_DBOPEN
 422 no retry data available
 423 search_tidyup called
 424 changed uid/gid: local delivery to 2 <2@b> transport=t1
 425   uid=CALLER_UID gid=CALLER_GID pid=pppp
 426   home=NULL current=/
 427 set_process_info: pppp delivering 10HmaY-0005vi-00 to 2 using t1
 428 appendfile transport entered
 429 appendfile: mode=600 notify_comsat=0 quota=0 warning=0
 430   file=TESTSUITE/test-mail/2 format=unix
 431   message_prefix=From ${if def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}\n
 432   message_suffix=\n
 433   maildir_use_size_file=no
 434   locking by lockfile fcntl
 435 lock name: TESTSUITE/test-mail/2.lock
 436 hitch name: TESTSUITE/test-mail/2.lock.test.ex.dddddddd.pppppppp
 437 lock file created
 438 mailbox TESTSUITE/test-mail/2 is locked
 439 writing to file TESTSUITE/test-mail/2
 440 writing data block fd=dddd size=sss timeout=0
 441 writing data block fd=dddd size=sss timeout=0
 442 writing data block fd=dddd size=sss timeout=0
 443 appendfile yields 0 with errno=dd more_errno=dd
 444 search_tidyup called
 445 journalling 2@b
 446 t1 transport returned OK for 2@b
 447 post-process 2@b (0)
 448 2@b delivered
 449 LOG: MAIN
 450   => 2 <2@b> R=r1 T=t1
 451 >>>>>>>>>>>>>>>> deliveries are done >>>>>>>>>>>>>>>>
 452 changed uid/gid: post-delivery tidying
 453   uid=EXIM_UID gid=EXIM_GID pid=pppp
 454 set_process_info: pppp tidying up after delivering 10HmaY-0005vi-00
 455 Processing retry items
 456 Succeeded addresses:
 457 2@b: no retry items
 458 Failed addresses:
 459 Deferred addresses:
 460 end of retry processing
 461 LOG: MAIN
 462   Completed
 463 end delivery of 10HmaY-0005vi-00
 464 search_tidyup called
 465 search_tidyup called
 466 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
 467 smtp_setup_msg entered
 468 SMTP<< quit
 469 SMTP>> 221 myhost.test.ex closing connection
 470 LOG: smtp_connection MAIN
 471   SMTP connection from CALLER closed by QUIT
 472 search_tidyup called
 473 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>