Debugging: millisecond timestamps. Bug 2102
[users/jgh/exim.git] / test / stderr / 0487
index 07628551ab81ee5cdd854cd25ef8c34313219b0c..56e21b60e409727a4e4094b4551cec3b1d0d6602 100644 (file)
@@ -1,31 +1,43 @@
 Exim version x.yz ....
 changed uid/gid: forcing real = effective
   uid=uuuu gid=CALLER_GID pid=pppp
 Exim version x.yz ....
 changed uid/gid: forcing real = effective
   uid=uuuu gid=CALLER_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
 changed uid/gid: privilege not needed
   uid=EXIM_UID gid=EXIM_GID pid=pppp
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
 changed uid/gid: privilege not needed
   uid=EXIM_UID gid=EXIM_GID pid=pppp
-finduser used cached passwd data for CALLER
+DSN: r1 propagating DSN
+seeking password data for user "CALLER": using cached result
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = NULL
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = NULL
+set_process_info: pppp accepting a local SMTP message from <CALLER>
  in hosts_connection_nolog? no (option unset)
 LOG: smtp_connection MAIN
   SMTP connection from CALLER
 SMTP>> 220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000
 smtp_setup_msg entered
 SMTP<< ehlo x.y
  in hosts_connection_nolog? no (option unset)
 LOG: smtp_connection MAIN
   SMTP connection from CALLER
 SMTP>> 220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000
 smtp_setup_msg entered
 SMTP<< ehlo x.y
+ in dsn_advertise_hosts? no (option unset)
  in pipelining_advertise_hosts? yes (matched "*")
  in pipelining_advertise_hosts? yes (matched "*")
+ in chunking_advertise_hosts? no (end of list)
 SMTP>> 250-myhost.test.ex Hello CALLER at x.y
 250-SIZE 52428800
 SMTP>> 250-myhost.test.ex Hello CALLER at x.y
 250-SIZE 52428800
+250-8BITMIME
 250-PIPELINING
 250 HELP
 SMTP<< mail from:<x@y>
 250-PIPELINING
 250 HELP
 SMTP<< mail from:<x@y>
+spool directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100 msg_size = 0
+log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
 SMTP>> 250 OK
 SMTP<< rcpt to:<userx@test.ex>
 processing "accept"
 SMTP>> 250 OK
 SMTP<< rcpt to:<userx@test.ex>
 processing "accept"
-accept: condition test succeeded
+accept: condition test succeeded in inline ACL
+end of inline ACL: ACCEPT
 SMTP>> 250 Accepted
 SMTP>> 250 Accepted
+DSN: orcpt: NULL  flags: 0
 SMTP<< data
 SMTP>> 354 Enter message, ending with "." on a line by itself
 search_tidyup called
 SMTP<< data
 SMTP>> 354 Enter message, ending with "." on a line by itself
 search_tidyup called
@@ -40,6 +52,7 @@ F From: unqualified
 I Message-Id: <E10HmaX-0005vi-00@myhost.test.ex>
   Date: Tue, 2 Mar 1999 09:44:33 +0000
 
 I Message-Id: <E10HmaX-0005vi-00@myhost.test.ex>
   Date: Tue, 2 Mar 1999 09:44:33 +0000
 
+Data file name: TESTSUITE/spool//input//10HmaX-0005vi-00-D
 Data file written for message 10HmaX-0005vi-00
 >>Generated Received: header line
 P Received: from CALLER (helo=x.y)
 Data file written for message 10HmaX-0005vi-00
 >>Generated Received: header line
 P Received: from CALLER (helo=x.y)
@@ -49,7 +62,12 @@ P Received: from CALLER (helo=x.y)
        for userx@test.ex; Tue, 2 Mar 1999 09:44:33 +0000
 calling local_scan(); timeout=300
 local_scan() returned 0 NULL
        for userx@test.ex; Tue, 2 Mar 1999 09:44:33 +0000
 calling local_scan(); timeout=300
 local_scan() returned 0 NULL
-Writing spool header file
+Writing spool header file: TESTSUITE/spool//input//hdr.pppp
+DSN: Write SPOOL :-dsn_envid NULL
+DSN: Write SPOOL :-dsn_ret 0
+DSN: Flags :0
+DSN: **** SPOOL_OUT - address: |userx@test.ex| errorsto: |NULL| orcpt: |NULL| dsn_flags: 0
+Renaming spool header file: TESTSUITE/spool//input//10HmaX-0005vi-00-H
 Size of headers = sss
 LOG: MAIN
   <= x@y U=CALLER P=local-esmtp S=sss
 Size of headers = sss
 LOG: MAIN
   <= x@y U=CALLER P=local-esmtp S=sss
@@ -60,12 +78,17 @@ exec TESTSUITE/eximdir/exim -DEXIM_PATH=TESTSUITE/eximdir/exim -C TESTSUITE/test
 Exim version x.yz ....
 changed uid/gid: forcing real = effective
   uid=uuuu gid=EXIM_GID pid=pppp
 Exim version x.yz ....
 changed uid/gid: forcing real = effective
   uid=uuuu gid=EXIM_GID pid=pppp
+seeking password data for user "CALLER": cache not available
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
-finduser used cached passwd data for CALLER
+DSN: r1 propagating DSN
+seeking password data for user "CALLER": using cached result
+getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 set_process_info: pppp delivering specified messages
 set_process_info: pppp delivering 10HmaX-0005vi-00
 set_process_info: pppp delivering specified messages
 set_process_info: pppp delivering 10HmaX-0005vi-00
+Trying spool file TESTSUITE/spool//input//10HmaX-0005vi-00-D
 reading spool file 10HmaX-0005vi-00-H
 user=CALLER uid=CALLER_UID gid=CALLER_GID sender=x@y
 sender_local=0 ident=CALLER
 reading spool file 10HmaX-0005vi-00-H
 user=CALLER uid=CALLER_UID gid=CALLER_GID sender=x@y
 sender_local=0 ident=CALLER
@@ -73,14 +96,17 @@ Non-recipients:
 Empty Tree
 ---- End of tree ----
 recipients_count=1
 Empty Tree
 ---- End of tree ----
 recipients_count=1
+**** SPOOL_IN - No additional fields
 body_linecount=1 message_linecount=8
 body_linecount=1 message_linecount=8
+DSN: set orcpt: NULL  flags: 0
 Delivery address list:
   userx@test.ex 
 locking TESTSUITE/spool/db/retry.lockfile
 Delivery address list:
   userx@test.ex 
 locking TESTSUITE/spool/db/retry.lockfile
-locked TESTSUITE/spool/db/retry.lockfile
-EXIM_DBOPEN(TESTSUITE/spool/db/retry)
-returned from EXIM_DBOPEN
+locked  TESTSUITE/spool/db/retry.lockfile
+EXIM_DBOPEN: file <TESTSUITE/spool/db/retry> dir <TESTSUITE/spool/db> flags 0x0
+returned from EXIM_DBOPEN: (nil)
 ensuring TESTSUITE/spool/db/retry.lockfile is owned by exim
 ensuring TESTSUITE/spool/db/retry.lockfile is owned by exim
+failed to open DB file TESTSUITE/spool/db/retry.lockfile: No such file or directory
 no retry data available
 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
 Considering: userx@test.ex
 no retry data available
 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
 Considering: userx@test.ex
@@ -114,9 +140,10 @@ search_tidyup called
 >>>>>>>>>>>>>>>> Local deliveries >>>>>>>>>>>>>>>>
 --------> userx@test.ex <--------
 locking TESTSUITE/spool/db/retry.lockfile
 >>>>>>>>>>>>>>>> Local deliveries >>>>>>>>>>>>>>>>
 --------> userx@test.ex <--------
 locking TESTSUITE/spool/db/retry.lockfile
-locked TESTSUITE/spool/db/retry.lockfile
-EXIM_DBOPEN(TESTSUITE/spool/db/retry)
-returned from EXIM_DBOPEN
+locked  TESTSUITE/spool/db/retry.lockfile
+EXIM_DBOPEN: file <TESTSUITE/spool/db/retry> dir <TESTSUITE/spool/db> flags 0x0
+returned from EXIM_DBOPEN: (nil)
+failed to open DB file TESTSUITE/spool/db/retry: No such file or directory
 no retry data available
 search_tidyup called
 changed uid/gid: local delivery to userx <userx@test.ex> transport=t1
 no retry data available
 search_tidyup called
 changed uid/gid: local delivery to userx <userx@test.ex> transport=t1
@@ -135,11 +162,12 @@ hitch name: TESTSUITE/test-mail/userx.lock.test.ex.dddddddd.pppppppp
 lock file created
 mailbox TESTSUITE/test-mail/userx is locked
 writing to file TESTSUITE/test-mail/userx
 lock file created
 mailbox TESTSUITE/test-mail/userx is locked
 writing to file TESTSUITE/test-mail/userx
-writing data block fd=6 size=sss timeout=0
+writing data block fd=dddd size=sss timeout=0
 rewrite_one_header: type=F:
   From: unqualified
 rewrite_one_header: type=F:
   From: unqualified
-writing data block fd=6 size=sss timeout=0
-writing data block fd=6 size=sss timeout=0
+cannot use sendfile for body: spoolfile not wireformat
+writing data block fd=dddd size=sss timeout=0
+writing data block fd=dddd size=sss timeout=0
 appendfile yields 0 with errno=dd more_errno=dd
 search_tidyup called
 journalling userx@test.ex
 appendfile yields 0 with errno=dd more_errno=dd
 search_tidyup called
 journalling userx@test.ex
@@ -154,10 +182,18 @@ changed uid/gid: post-delivery tidying
 set_process_info: pppp tidying up after delivering 10HmaX-0005vi-00
 Processing retry items
 Succeeded addresses:
 set_process_info: pppp tidying up after delivering 10HmaX-0005vi-00
 Processing retry items
 Succeeded addresses:
-userx@test.ex: no retry items
+ userx@test.ex: no retry items
 Failed addresses:
 Deferred addresses:
 end of retry processing
 Failed addresses:
 Deferred addresses:
 end of retry processing
+DSN: processing router : r1
+DSN: processing successful delivery address: userx@test.ex
+DSN: Sender_address: x@y
+DSN: orcpt: NULL  flags: 0
+DSN: envid: NULL  ret: 0
+DSN: Final recipient: userx@test.ex
+DSN: Remote SMTP server supports DSN: 0
+DSN: not sending DSN success message
 LOG: MAIN
   Completed
 end delivery of 10HmaX-0005vi-00
 LOG: MAIN
   Completed
 end delivery of 10HmaX-0005vi-00