DKIM: logging for signing in transport. Bug 3062

diff --git a/doc/doc-docbook/spec.xfpt b/doc/doc-docbook/spec.xfpt
index ae3cc17489d67a00a4d8f0a0d2392fb80d3fbb4d..2c90ec5f3ef4bf877f999beddf30fd60e5c9e688 100644 (file)
--- a/doc/doc-docbook/spec.xfpt
+++ b/doc/doc-docbook/spec.xfpt
@@ -39061,7 +39061,7 @@ selection marked by asterisks:
 .irow &`deliver_time`&                   "time taken to attempt delivery"
 .irow &`delivery_size`&                          "add &`S=`&&'nnn'& to => lines"
 .irow &`dkim`&                         *       "DKIM verified domain on <= lines"
-.irow &`dkim_verbose`&                 &nbsp; "separate full DKIM verification result line, per signature"
+.irow &`dkim_verbose`&                 &nbsp; "separate full DKIM verification result line, per signature; DKIM signing"
 .irow &`dnslist_defer`&                        *       "defers of DNS list (aka RBL) lookups"
 .irow &`dnssec`&                       &nbsp; "DNSSEC secured lookups"
 .irow &`etrn`&                         *       "ETRN commands"
@@ -39187,6 +39187,10 @@ verifies successfully a tag of DKIM is added, with one of the verified domains.
 .cindex log "DKIM verification"
 .cindex DKIM "verification logging"
 &%dkim_verbose%&: A log entry is written for each attempted DKIM verification.
+.new
+Also, on message delivery lines signing information (domain and selector)
+is added, tagged with DKIM=.
+.wen
 .next
 .cindex "log" "dnslist defer"
 .cindex "DNS list" "logging defer"

diff --git a/doc/doc-txt/NewStuff b/doc/doc-txt/NewStuff
index 6aef41e50b53022180e0bdc9b1e4ce7aa8cfe2ef..1a5dac27bcb2524ef89e72bbb49193d0c1778cf1 100644 (file)
--- a/doc/doc-txt/NewStuff
+++ b/doc/doc-txt/NewStuff
@@ -10,6 +10,8 @@ Version 4.98
 ------------
  1. The dkim_status ACL condition may now be used in data ACLs
 
+ 2. The dkim_verbose logging control also enables logging of signing
+
 Version 4.97
 ------------
 

diff --git a/src/src/deliver.c b/src/src/deliver.c
index e96733f73c8e684bce9f0075fa17c442a6d271e7..2cef3d73168a2bff9151633a7673c92585cb7cde 100644 (file)
--- a/src/src/deliver.c
+++ b/src/src/deliver.c
@@ -1245,6 +1245,14 @@ else
     g = string_catn(g, US" K", 2);
   }
 
+#ifndef DISABLE_DKIM
+  if (addr->dkim_used && LOGGING(dkim_verbose))
+    {
+    g = string_catn(g, US" DKIM=", 6);
+    g = string_cat(g, addr->dkim_used);
+    }
+#endif
+
 /* confirmation message (SMTP (host_used) and LMTP (driver_name)) */
 
 if (  LOGGING(smtp_confirmation)
@@ -3571,7 +3579,14 @@ while (!done)
 
       switch (*subid)
        {
-       case 3:         /* explicit notification of continued-connection (non)use;
+#ifndef DISABLE_DKIM
+       case '4':       /* DKIM information */
+         addr->dkim_used = string_copy(ptr);
+         while(*ptr++);
+         break;
+#endif
+
+       case '3':       /* explicit notification of continued-connection (non)use;
                        overrides caller's knowlege. */
          if (*ptr & BIT(1))      setflag(addr, af_new_conn);
          else if (*ptr & BIT(2)) setflag(addr, af_cont_conn);
@@ -4886,6 +4901,15 @@ all pipes, so I do not see a reason to use non-blocking IO here
         rmt_dlv_checked_write(fd, 'R', '0', big_buffer, ptr - big_buffer);
         }
 
+#ifndef DISABLE_DKIM
+      if (addr->dkim_used && LOGGING(dkim_verbose))
+       {
+       DEBUG(D_deliver) debug_printf("dkim used: %s\n", addr->dkim_used);
+       ptr = big_buffer + sprintf(CS big_buffer, "%.128s", addr->dkim_used) + 1;
+        rmt_dlv_checked_write(fd, 'A', '4', big_buffer, ptr - big_buffer);
+       }
+#endif
+
       if (testflag(addr, af_new_conn) || testflag(addr, af_cont_conn))
        {
        DEBUG(D_deliver) debug_printf("%scontinued-connection\n",

diff --git a/src/src/dkim.c b/src/src/dkim.c
index ea82f34eab673d3be03407449656426aed568d1f..59025608feb82c74e1d0c594c5dbeb887444eefa 100644 (file)
--- a/src/src/dkim.c
+++ b/src/src/dkim.c
@@ -741,6 +741,9 @@ if (dkim_domain)
     if (!pdkim_set_sig_bodyhash(&dkim_sign_ctx, sig))
       goto bad;
 
+    dkim_signing_record = string_append_listele(dkim_signing_record, ':', dkim_signing_domain);
+    dkim_signing_record = string_append_listele(dkim_signing_record, ':', dkim_signing_selector);
+
     if (!dkim_sign_ctx.sig)            /* link sig to context chain */
       dkim_sign_ctx.sig = sig;
     else

diff --git a/src/src/dkim_transport.c b/src/src/dkim_transport.c
index fae2f4891c27f4a7f2d7f6cbce527c4005cf08fd..38f849af673ee44b8803f80536f50feec8cb9cf3 100644 (file)
--- a/src/src/dkim_transport.c
+++ b/src/src/dkim_transport.c
@@ -384,6 +384,8 @@ BOOL
 dkim_transport_write_message(transport_ctx * tctx,
   struct ob_dkim * dkim, const uschar ** err)
 {
+BOOL yield;
+
 /* If we can't sign, just call the original function. */
 
 if (  !(dkim->dkim_private_key && dkim->dkim_domain && dkim->dkim_selector)
@@ -398,12 +400,16 @@ if (  !transport_filter_argv
    || !*transport_filter_argv
    || !**transport_filter_argv
    )
-  return dkt_direct(tctx, dkim, err);
+  yield = dkt_direct(tctx, dkim, err);
+
+else
+  /* Use the transport path to write a file, calculate a dkim signature,
+  send the signature and then send the file. */
 
-/* Use the transport path to write a file, calculate a dkim signature,
-send the signature and then send the file. */
+  yield = dkt_via_kfile(tctx, dkim, err);
 
-return dkt_via_kfile(tctx, dkim, err);
+tctx->addr->dkim_used = string_from_gstring(dkim_signing_record);
+return yield;
 }
 
 #endif /* whole file */

diff --git a/src/src/globals.c b/src/src/globals.c
index bb5bd6b1adeb3403fcbbe8eacb68c782a546c118..c535ea12195651262f9a8332f9c906c6142760da 100644 (file)
--- a/src/src/globals.c
+++ b/src/src/globals.c
@@ -864,6 +864,7 @@ void   *dkim_signatures              = NULL;
 uschar *dkim_signers             = NULL;
 uschar *dkim_signing_domain      = NULL;
 uschar *dkim_signing_selector    = NULL;
+gstring *dkim_signing_record    = NULL;
 uschar *dkim_verify_hashes       = US"sha256:sha512";
 uschar *dkim_verify_keytypes     = US"ed25519:rsa";
 uschar *dkim_verify_min_keysizes = US"rsa=1024 ed25519=250";

diff --git a/src/src/globals.h b/src/src/globals.h
index fe4a1610a6240118be67700f574079df4a52b0b4..ffc7150f27f67a2e9bec3322a386cffb2867801b 100644 (file)
--- a/src/src/globals.h
+++ b/src/src/globals.h
@@ -541,6 +541,7 @@ extern uschar *dkim_cur_signer;        /* Expansion variable, holds the current
 extern int     dkim_key_length;        /* Expansion variable, length of signing key in bits */
 extern void   *dkim_signatures;               /* Actually a (pdkim_signature *) but most files do not need to know */
 extern uschar *dkim_signers;           /* Expansion variable, holds colon-separated list of domains and identities that have signed a message */
+extern gstring *dkim_signing_record;   /* domains+selectors used */
 extern uschar *dkim_signing_domain;    /* Expansion variable, domain used for signing a message. */
 extern uschar *dkim_signing_selector;  /* Expansion variable, selector used for signing a message. */
 extern uschar *dkim_verify_hashes;     /* Preference order for signatures */

diff --git a/src/src/structs.h b/src/src/structs.h
index 256560ef897dd7fb59aa14dbbbe9e57bdb894ea1..b16a8a3f2a39131b3b33de05926e357cafdd21b6 100644 (file)
--- a/src/src/structs.h
+++ b/src/src/structs.h
@@ -586,6 +586,9 @@ typedef struct address_item {
   uschar *self_hostname;          /* after self=pass */
   uschar *shadow_message;         /* info about shadow transporting */
 
+  uid_t   uid;                    /* uid for transporting */
+  gid_t   gid;                    /* gid for transporting */
+
 #ifndef DISABLE_TLS
   const uschar *tlsver;           /* version used for transport */
   uschar *cipher;                 /* Cipher used for transport */
@@ -608,9 +611,9 @@ typedef struct address_item {
   int     dsn_flags;              /* DSN flags */
   int     dsn_aware;              /* DSN aware flag */
 
-  uid_t   uid;                    /* uid for transporting */
-  gid_t   gid;                    /* gid for transporting */
-
+#ifndef DISABLE_DKIM
+  const uschar * dkim_used;      /* DKIM info, or NULL */
+#endif
                                  /* flags */
   struct {
     BOOL af_allow_file:1;              /* allow file in generated address */

diff --git a/test/log/4510 b/test/log/4510
index 08f73d5b46add46f0616ef9560297dba861b43e0..7632951d026e69d7e15a58131a6319262e35cbb9 100644 (file)
--- a/test/log/4510
+++ b/test/log/4510
@@ -1,23 +1,23 @@
 1999-03-02 09:44:33 10HmaY-000000005vi-0000 <= CALLER@myhost.test.ex U=CALLER P=local S=sss for a@test.ex
-1999-03-02 09:44:33 10HmaY-000000005vi-0000 => a@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] C="250 OK id=10HmaZ-000000005vi-0000"
+1999-03-02 09:44:33 10HmaY-000000005vi-0000 => a@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] DKIM=test.ex:sel C="250 OK id=10HmaZ-000000005vi-0000"
 1999-03-02 09:44:33 10HmaY-000000005vi-0000 Completed
 1999-03-02 09:44:33 10HmbA-000000005vi-0000 <= CALLER@myhost.test.ex U=CALLER P=local S=sss for b@test.ex
-1999-03-02 09:44:33 10HmbA-000000005vi-0000 => b@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] C="250 OK id=10HmbB-000000005vi-0000"
+1999-03-02 09:44:33 10HmbA-000000005vi-0000 => b@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] DKIM=test.ex:sel C="250 OK id=10HmbB-000000005vi-0000"
 1999-03-02 09:44:33 10HmbA-000000005vi-0000 Completed
 1999-03-02 09:44:33 10HmbC-000000005vi-0000 <= CALLER@myhost.test.ex U=CALLER P=local S=sss for b10@test.ex
-1999-03-02 09:44:33 10HmbC-000000005vi-0000 => b10@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] C="250 OK id=10HmbD-000000005vi-0000"
+1999-03-02 09:44:33 10HmbC-000000005vi-0000 => b10@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] DKIM=test.ex:sel C="250 OK id=10HmbD-000000005vi-0000"
 1999-03-02 09:44:33 10HmbC-000000005vi-0000 Completed
 1999-03-02 09:44:33 10HmbE-000000005vi-0000 <= CALLER@myhost.test.ex U=CALLER P=local S=sss for b12@test.ex
-1999-03-02 09:44:33 10HmbE-000000005vi-0000 => b12@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] C="250 OK id=10HmbF-000000005vi-0000"
+1999-03-02 09:44:33 10HmbE-000000005vi-0000 => b12@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] DKIM=test.ex:sel C="250 OK id=10HmbF-000000005vi-0000"
 1999-03-02 09:44:33 10HmbE-000000005vi-0000 Completed
 1999-03-02 09:44:33 10HmbG-000000005vi-0000 <= CALLER@myhost.test.ex U=CALLER P=local S=sss for b20@test.ex
-1999-03-02 09:44:33 10HmbG-000000005vi-0000 => b20@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] C="250 OK id=10HmbH-000000005vi-0000"
+1999-03-02 09:44:33 10HmbG-000000005vi-0000 => b20@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] DKIM=test.ex:sel C="250 OK id=10HmbH-000000005vi-0000"
 1999-03-02 09:44:33 10HmbG-000000005vi-0000 Completed
 1999-03-02 09:44:33 10HmbI-000000005vi-0000 <= CALLER@myhost.test.ex U=CALLER P=local S=sss for b22@test.ex
-1999-03-02 09:44:33 10HmbI-000000005vi-0000 => b22@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] C="250 OK id=10HmbJ-000000005vi-0000"
+1999-03-02 09:44:33 10HmbI-000000005vi-0000 => b22@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] DKIM=test.ex:sel C="250 OK id=10HmbJ-000000005vi-0000"
 1999-03-02 09:44:33 10HmbI-000000005vi-0000 Completed
 1999-03-02 09:44:33 10HmbK-000000005vi-0000 <= CALLER@myhost.test.ex U=CALLER P=local S=sss for d@test.ex
-1999-03-02 09:44:33 10HmbK-000000005vi-0000 => d@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] C="250 OK id=10HmbL-000000005vi-0000"
+1999-03-02 09:44:33 10HmbK-000000005vi-0000 => d@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] DKIM=test.ex:sel_bad C="250 OK id=10HmbL-000000005vi-0000"
 1999-03-02 09:44:33 10HmbK-000000005vi-0000 Completed
 1999-03-02 09:44:33 10HmaX-000000005vi-0000 <= <> U=CALLER P=local S=sss for e0@test.ex
 1999-03-02 09:44:33 10HmaX-000000005vi-0000 failed to expand dkim_timestamps: unknown variable in "${bogus}"
@@ -31,7 +31,7 @@
 1999-03-02 09:44:33 10HmbM-000000005vi-0000 => e@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] C="250 OK id=10HmbN-000000005vi-0000"
 1999-03-02 09:44:33 10HmbM-000000005vi-0000 Completed
 1999-03-02 09:44:33 10HmbO-000000005vi-0000 <= CALLER@myhost.test.ex U=CALLER P=local S=sss for f@test.ex
-1999-03-02 09:44:33 10HmbO-000000005vi-0000 => f@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] C="250 OK id=10HmbP-000000005vi-0000"
+1999-03-02 09:44:33 10HmbO-000000005vi-0000 => f@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] DKIM=test.ex:sel C="250 OK id=10HmbP-000000005vi-0000"
 1999-03-02 09:44:33 10HmbO-000000005vi-0000 Completed
 
 ******** SERVER ********

diff --git a/test/log/4511 b/test/log/4511
index b45c16fbb8849d1761a1b9bfffd1ea20964bd2e8..2b634034414fe9529cc452d430d7eb0d734f8ed5 100644 (file)
--- a/test/log/4511
+++ b/test/log/4511
@@ -1,8 +1,8 @@
 2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 <= sender@testhost.test.ex U=sender Ci=p1234 P=local S=sss for a@test.ex
-2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 => a@test.ex R=to_server T=remote_smtp_dkim H=127.0.0.1 [127.0.0.1] K C="250- 6nn byte chunk, total 6nn\\n250 OK id=10HmaY-000000005vi-0000"
+2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 => a@test.ex R=to_server T=remote_smtp_dkim H=127.0.0.1 [127.0.0.1] K DKIM=test.ex:sel C="250- 6nn byte chunk, total 6nn\\n250 OK id=10HmaY-000000005vi-0000"
 2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 Completed
 2017-07-30 18:51:05.712 10HmaZ-000000005vi-0000 <= sender@testhost.test.ex U=sender Ci=p1235 P=local S=sss for b@test.ex
-2017-07-30 18:51:05.712 10HmaZ-000000005vi-0000 => b@test.ex R=to_server T=remote_smtp_dkim H=127.0.0.1 [127.0.0.1] K C="250- 8nn byte chunk, total 8nn\\n250 OK id=10HmbA-000000005vi-0000"
+2017-07-30 18:51:05.712 10HmaZ-000000005vi-0000 => b@test.ex R=to_server T=remote_smtp_dkim H=127.0.0.1 [127.0.0.1] K DKIM=test.ex:sel C="250- 8nn byte chunk, total 8nn\\n250 OK id=10HmbA-000000005vi-0000"
 2017-07-30 18:51:05.712 10HmaZ-000000005vi-0000 Completed
 
 ******** SERVER ********

diff --git a/test/log/4513 b/test/log/4513
index a3c53de81051cc0c692741078f3147bf1f7824a6..c72693ca16b84fa36f1629b67d68550427b28154 100644 (file)
--- a/test/log/4513
+++ b/test/log/4513
@@ -1,5 +1,5 @@
 1999-03-02 09:44:33 10HmaX-000000005vi-0000 <= CALLER@myhost.test.ex U=CALLER P=local S=sss for a@test.ex
-1999-03-02 09:44:33 10HmaX-000000005vi-0000 => a@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] C="250 OK id=10HmaY-000000005vi-0000"
+1999-03-02 09:44:33 10HmaX-000000005vi-0000 => a@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] DKIM=test.ex:sel C="250 OK id=10HmaY-000000005vi-0000"
 1999-03-02 09:44:33 10HmaX-000000005vi-0000 Completed
 
 ******** SERVER ********

diff --git a/test/log/4514 b/test/log/4514
index 6d489fb99f7949070c27f8198428e83481ca255d..619023da071b8a24bb98cf5d8ecbf3c6ee672794 100644 (file)
--- a/test/log/4514
+++ b/test/log/4514
@@ -1,5 +1,5 @@
 1999-03-02 09:44:33 10HmaX-000000005vi-0000 <= CALLER@myhost.test.ex U=CALLER P=local S=sss for c@test.ex
-1999-03-02 09:44:33 10HmaX-000000005vi-0000 => c@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] C="250 OK id=10HmaY-000000005vi-0000"
+1999-03-02 09:44:33 10HmaX-000000005vi-0000 => c@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] DKIM=test.ex:ses:test.ex:sel C="250 OK id=10HmaY-000000005vi-0000"
 1999-03-02 09:44:33 10HmaX-000000005vi-0000 Completed
 
 ******** SERVER ********

diff --git a/test/log/4519 b/test/log/4519
index 24aba0b1eb9159451711750ce307b4b5d02e7cfb..02ddaebffe35c1fa133bd2e0e2130329e220fb21 100644 (file)
--- a/test/log/4519
+++ b/test/log/4519
@@ -11,11 +11,11 @@
 1999-03-02 09:44:33 10HmaX-000000005vi-0000 DKIM: d=test.ex s=sel c=relaxed/relaxed a=rsa-sha256 b=1024 [verification succeeded]
 1999-03-02 09:44:33 10HmaX-000000005vi-0000 <= <> H=localhost (testhost.test.ex) [127.0.0.1] P=esmtp K S=sss DKIM=test.ex for z@test.ex
 1999-03-02 09:44:33 10HmaX-000000005vi-0000 no immediate delivery: queued by ACL
-1999-03-02 09:44:33 10HmaZ-000000005vi-0000 => z@test.ex R=to_server T=remote_smtp_dkim H=127.0.0.1 [127.0.0.1] K C="250- 6nn byte chunk, total 6nn\\n250 OK id=10HmaX-000000005vi-0000"
+1999-03-02 09:44:33 10HmaZ-000000005vi-0000 => z@test.ex R=to_server T=remote_smtp_dkim H=127.0.0.1 [127.0.0.1] K DKIM=test.ex:sel C="250- 6nn byte chunk, total 6nn\\n250 OK id=10HmaX-000000005vi-0000"
 1999-03-02 09:44:33 10HmaZ-000000005vi-0000 Completed
 1999-03-02 09:44:33 10HmbA-000000005vi-0000 <= CALLER@bloggs.com H=(xxx) [127.0.0.1] P=esmtp K S=sss for y@test.ex
 1999-03-02 09:44:33 10HmaY-000000005vi-0000 DKIM: d=test.ex s=sel c=relaxed/relaxed a=rsa-sha256 b=1024 [verification succeeded]
 1999-03-02 09:44:33 10HmaY-000000005vi-0000 <= <> H=localhost (testhost.test.ex) [127.0.0.1] P=esmtp K S=sss DKIM=test.ex for y@test.ex
 1999-03-02 09:44:33 10HmaY-000000005vi-0000 no immediate delivery: queued by ACL
-1999-03-02 09:44:33 10HmbA-000000005vi-0000 => y@test.ex R=to_server T=remote_smtp_dkim H=127.0.0.1 [127.0.0.1] K C="250- 6nn byte chunk, total 6nn\\n250 OK id=10HmaY-000000005vi-0000"
+1999-03-02 09:44:33 10HmbA-000000005vi-0000 => y@test.ex R=to_server T=remote_smtp_dkim H=127.0.0.1 [127.0.0.1] K DKIM=test.ex:sel C="250- 6nn byte chunk, total 6nn\\n250 OK id=10HmaY-000000005vi-0000"
 1999-03-02 09:44:33 10HmbA-000000005vi-0000 Completed

diff --git a/test/log/4530 b/test/log/4530
index bd0e40ae24eefbf3b7a239319f73537a1b4a032f..74713e09ded3adb7dad8667e0e58dcdc59c2b9e9 100644 (file)
--- a/test/log/4530
+++ b/test/log/4530
@@ -1,23 +1,23 @@
 1999-03-02 09:44:33 10HmaY-000000005vi-0000 <= CALLER@myhost.test.ex U=CALLER P=local S=sss for a@test.ex
-1999-03-02 09:44:33 10HmaY-000000005vi-0000 => a@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes C="250 OK id=10HmaZ-000000005vi-0000"
+1999-03-02 09:44:33 10HmaY-000000005vi-0000 => a@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes DKIM=test.ex:sel C="250 OK id=10HmaZ-000000005vi-0000"
 1999-03-02 09:44:33 10HmaY-000000005vi-0000 Completed
 1999-03-02 09:44:33 10HmbA-000000005vi-0000 <= CALLER@myhost.test.ex U=CALLER P=local S=sss for b@test.ex
-1999-03-02 09:44:33 10HmbA-000000005vi-0000 => b@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes C="250 OK id=10HmbB-000000005vi-0000"
+1999-03-02 09:44:33 10HmbA-000000005vi-0000 => b@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes DKIM=test.ex:sel C="250 OK id=10HmbB-000000005vi-0000"
 1999-03-02 09:44:33 10HmbA-000000005vi-0000 Completed
 1999-03-02 09:44:33 10HmbC-000000005vi-0000 <= CALLER@myhost.test.ex U=CALLER P=local S=sss for b10@test.ex
-1999-03-02 09:44:33 10HmbC-000000005vi-0000 => b10@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes C="250 OK id=10HmbD-000000005vi-0000"
+1999-03-02 09:44:33 10HmbC-000000005vi-0000 => b10@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes DKIM=test.ex:sel C="250 OK id=10HmbD-000000005vi-0000"
 1999-03-02 09:44:33 10HmbC-000000005vi-0000 Completed
 1999-03-02 09:44:33 10HmbE-000000005vi-0000 <= CALLER@myhost.test.ex U=CALLER P=local S=sss for b12@test.ex
-1999-03-02 09:44:33 10HmbE-000000005vi-0000 => b12@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes C="250 OK id=10HmbF-000000005vi-0000"
+1999-03-02 09:44:33 10HmbE-000000005vi-0000 => b12@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes DKIM=test.ex:sel C="250 OK id=10HmbF-000000005vi-0000"
 1999-03-02 09:44:33 10HmbE-000000005vi-0000 Completed
 1999-03-02 09:44:33 10HmbG-000000005vi-0000 <= CALLER@myhost.test.ex U=CALLER P=local S=sss for b20@test.ex
-1999-03-02 09:44:33 10HmbG-000000005vi-0000 => b20@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes C="250 OK id=10HmbH-000000005vi-0000"
+1999-03-02 09:44:33 10HmbG-000000005vi-0000 => b20@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes DKIM=test.ex:sel C="250 OK id=10HmbH-000000005vi-0000"
 1999-03-02 09:44:33 10HmbG-000000005vi-0000 Completed
 1999-03-02 09:44:33 10HmbI-000000005vi-0000 <= CALLER@myhost.test.ex U=CALLER P=local S=sss for b22@test.ex
-1999-03-02 09:44:33 10HmbI-000000005vi-0000 => b22@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes C="250 OK id=10HmbJ-000000005vi-0000"
+1999-03-02 09:44:33 10HmbI-000000005vi-0000 => b22@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes DKIM=test.ex:sel C="250 OK id=10HmbJ-000000005vi-0000"
 1999-03-02 09:44:33 10HmbI-000000005vi-0000 Completed
 1999-03-02 09:44:33 10HmbK-000000005vi-0000 <= CALLER@myhost.test.ex U=CALLER P=local S=sss for d@test.ex
-1999-03-02 09:44:33 10HmbK-000000005vi-0000 => d@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes C="250 OK id=10HmbL-000000005vi-0000"
+1999-03-02 09:44:33 10HmbK-000000005vi-0000 => d@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes DKIM=test.ex:sel_bad C="250 OK id=10HmbL-000000005vi-0000"
 1999-03-02 09:44:33 10HmbK-000000005vi-0000 Completed
 1999-03-02 09:44:33 10HmaX-000000005vi-0000 <= <> U=CALLER P=local S=sss for e0@test.ex
 1999-03-02 09:44:33 10HmaX-000000005vi-0000 failed to expand dkim_timestamps: unknown variable in "${bogus}"
@@ -31,7 +31,7 @@
 1999-03-02 09:44:33 10HmbM-000000005vi-0000 => e@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes C="250 OK id=10HmbN-000000005vi-0000"
 1999-03-02 09:44:33 10HmbM-000000005vi-0000 Completed
 1999-03-02 09:44:33 10HmbO-000000005vi-0000 <= CALLER@myhost.test.ex U=CALLER P=local S=sss for f@test.ex
-1999-03-02 09:44:33 10HmbO-000000005vi-0000 => f@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes C="250 OK id=10HmbP-000000005vi-0000"
+1999-03-02 09:44:33 10HmbO-000000005vi-0000 => f@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes DKIM=test.ex:sel C="250 OK id=10HmbP-000000005vi-0000"
 1999-03-02 09:44:33 10HmbO-000000005vi-0000 Completed
 
 ******** SERVER ********

diff --git a/test/log/4531 b/test/log/4531
index bd642b51f693f3f1bfccc37628b6303ad94f8b45..45994c7511136def313c3fc07c001d4ac1878a77 100644 (file)
--- a/test/log/4531
+++ b/test/log/4531
@@ -1,8 +1,8 @@
 2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 <= sender@testhost.test.ex U=sender Ci=p1234 P=local S=sss for a@test.ex
-2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 => a@test.ex R=to_server T=remote_smtp_dkim H=127.0.0.1 [127.0.0.1] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes K C="250- 6nn byte chunk, total 6nn\\n250 OK id=10HmaY-000000005vi-0000"
+2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 => a@test.ex R=to_server T=remote_smtp_dkim H=127.0.0.1 [127.0.0.1] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes K DKIM=test.ex:sel C="250- 6nn byte chunk, total 6nn\\n250 OK id=10HmaY-000000005vi-0000"
 2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 Completed
 2017-07-30 18:51:05.712 10HmaZ-000000005vi-0000 <= sender@testhost.test.ex U=sender Ci=p1235 P=local S=sss for b@test.ex
-2017-07-30 18:51:05.712 10HmaZ-000000005vi-0000 => b@test.ex R=to_server T=remote_smtp_dkim H=127.0.0.1 [127.0.0.1] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes K C="250- 8nn byte chunk, total 8nn\\n250 OK id=10HmbA-000000005vi-0000"
+2017-07-30 18:51:05.712 10HmaZ-000000005vi-0000 => b@test.ex R=to_server T=remote_smtp_dkim H=127.0.0.1 [127.0.0.1] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes K DKIM=test.ex:sel C="250- 8nn byte chunk, total 8nn\\n250 OK id=10HmbA-000000005vi-0000"
 2017-07-30 18:51:05.712 10HmaZ-000000005vi-0000 Completed
 
 ******** SERVER ********

diff --git a/test/log/4533 b/test/log/4533
index 3e8343539800c4d0c200e131d38995d6b36c71ca..0483ddc084d714444a08a445b78a7f062c57ba30 100644 (file)
--- a/test/log/4533
+++ b/test/log/4533
@@ -1,5 +1,5 @@
 1999-03-02 09:44:33 10HmaX-000000005vi-0000 <= CALLER@myhost.test.ex U=CALLER P=local S=sss for a@test.ex
-1999-03-02 09:44:33 10HmaX-000000005vi-0000 => a@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes C="250 OK id=10HmaY-000000005vi-0000"
+1999-03-02 09:44:33 10HmaX-000000005vi-0000 => a@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes DKIM=test.ex:sel C="250 OK id=10HmaY-000000005vi-0000"
 1999-03-02 09:44:33 10HmaX-000000005vi-0000 Completed
 
 ******** SERVER ********

diff --git a/test/log/4534 b/test/log/4534
index 4f386c95c84143c2629ca9510e80e5412893255b..d80dc7154c0cc9c3eed7abaae5e4bd314dbaa3df 100644 (file)
--- a/test/log/4534
+++ b/test/log/4534
@@ -1,5 +1,5 @@
 1999-03-02 09:44:33 10HmaX-000000005vi-0000 <= CALLER@myhost.test.ex U=CALLER P=local S=sss for c@test.ex
-1999-03-02 09:44:33 10HmaX-000000005vi-0000 => c@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes C="250 OK id=10HmaY-000000005vi-0000"
+1999-03-02 09:44:33 10HmaX-000000005vi-0000 => c@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes DKIM=test.ex:ses:test.ex:sel C="250 OK id=10HmaY-000000005vi-0000"
 1999-03-02 09:44:33 10HmaX-000000005vi-0000 Completed
 
 ******** SERVER ********

diff --git a/test/log/4539 b/test/log/4539
index 9b0269b6c52e4297817762eb3de88f9d459a9562..5f503f6b2f6967d2e3a1e599deb62e8bfccda7c8 100644 (file)
--- a/test/log/4539
+++ b/test/log/4539
@@ -11,11 +11,11 @@
 1999-03-02 09:44:33 10HmaX-000000005vi-0000 DKIM: d=test.ex s=sel c=relaxed/relaxed a=rsa-sha256 b=1024 [verification succeeded]
 1999-03-02 09:44:33 10HmaX-000000005vi-0000 <= <> H=localhost (testhost.test.ex) [127.0.0.1] P=esmtps X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no K S=sss DKIM=test.ex for z@test.ex
 1999-03-02 09:44:33 10HmaX-000000005vi-0000 no immediate delivery: queued by ACL
-1999-03-02 09:44:33 10HmaZ-000000005vi-0000 => z@test.ex R=to_server T=remote_smtp_dkim H=127.0.0.1 [127.0.0.1] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes K C="250- 7nn byte chunk, total 7nn\\n250 OK id=10HmaX-000000005vi-0000"
+1999-03-02 09:44:33 10HmaZ-000000005vi-0000 => z@test.ex R=to_server T=remote_smtp_dkim H=127.0.0.1 [127.0.0.1] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes K DKIM=test.ex:sel C="250- 7nn byte chunk, total 7nn\\n250 OK id=10HmaX-000000005vi-0000"
 1999-03-02 09:44:33 10HmaZ-000000005vi-0000 Completed
 1999-03-02 09:44:33 10HmbA-000000005vi-0000 <= CALLER@bloggs.com H=(xxx) [127.0.0.1] P=smtps X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no K S=sss for y@test.ex
 1999-03-02 09:44:33 10HmaY-000000005vi-0000 DKIM: d=test.ex s=sel c=relaxed/relaxed a=rsa-sha256 b=1024 [verification succeeded]
 1999-03-02 09:44:33 10HmaY-000000005vi-0000 <= <> H=localhost (testhost.test.ex) [127.0.0.1] P=esmtps X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no K S=sss DKIM=test.ex for y@test.ex
 1999-03-02 09:44:33 10HmaY-000000005vi-0000 no immediate delivery: queued by ACL
-1999-03-02 09:44:33 10HmbA-000000005vi-0000 => y@test.ex R=to_server T=remote_smtp_dkim H=127.0.0.1 [127.0.0.1] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes K C="250- 7nn byte chunk, total 7nn\\n250 OK id=10HmaY-000000005vi-0000"
+1999-03-02 09:44:33 10HmbA-000000005vi-0000 => y@test.ex R=to_server T=remote_smtp_dkim H=127.0.0.1 [127.0.0.1] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes K DKIM=test.ex:sel C="250- 7nn byte chunk, total 7nn\\n250 OK id=10HmaY-000000005vi-0000"
 1999-03-02 09:44:33 10HmbA-000000005vi-0000 Completed

diff --git a/test/log/4541 b/test/log/4541
index bc998cc3583006612494bb7b73f51a2b8ff8a425..f2d4c325b791db1136cc08ae29afbbcfbc64ddd0 100644 (file)
--- a/test/log/4541
+++ b/test/log/4541
@@ -1,8 +1,8 @@
 1999-03-02 09:44:33 10HmaX-000000005vi-0000 <= CALLER@myhost.test.ex U=CALLER P=local S=sss for a@test.ex
-1999-03-02 09:44:33 10HmaX-000000005vi-0000 => a@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] C="250 OK id=10HmaY-000000005vi-0000"
+1999-03-02 09:44:33 10HmaX-000000005vi-0000 => a@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] DKIM=test.ex:sel:test.ex:sed C="250 OK id=10HmaY-000000005vi-0000"
 1999-03-02 09:44:33 10HmaX-000000005vi-0000 Completed
 1999-03-02 09:44:33 10HmaZ-000000005vi-0000 <= CALLER@myhost.test.ex U=CALLER P=local S=sss for b@test.ex
-1999-03-02 09:44:33 10HmaZ-000000005vi-0000 => b@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] C="250 OK id=10HmbA-000000005vi-0000"
+1999-03-02 09:44:33 10HmaZ-000000005vi-0000 => b@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] DKIM=test.ex:sel:test.ex:sed C="250 OK id=10HmbA-000000005vi-0000"
 1999-03-02 09:44:33 10HmaZ-000000005vi-0000 Completed
 
 ******** SERVER ********

diff --git a/test/log/4545 b/test/log/4545
index cb1918b2f195c9356d7d19075ecc9464673a2bd9..c983a7a969c1866d09d268a888fc104b03240341 100644 (file)
--- a/test/log/4545
+++ b/test/log/4545
@@ -1,8 +1,8 @@
 1999-03-02 09:44:33 10HmaX-000000005vi-0000 <= CALLER@myhost.test.ex U=CALLER P=local S=sss for a@test.ex
-1999-03-02 09:44:33 10HmaX-000000005vi-0000 => a@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] C="250 OK id=10HmaY-000000005vi-0000"
+1999-03-02 09:44:33 10HmaX-000000005vi-0000 => a@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] DKIM=test.ex:sed C="250 OK id=10HmaY-000000005vi-0000"
 1999-03-02 09:44:33 10HmaX-000000005vi-0000 Completed
 1999-03-02 09:44:33 10HmaZ-000000005vi-0000 <= CALLER@myhost.test.ex U=CALLER P=local S=sss for b@test.ex
-1999-03-02 09:44:33 10HmaZ-000000005vi-0000 => b@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] C="250 OK id=10HmbA-000000005vi-0000"
+1999-03-02 09:44:33 10HmaZ-000000005vi-0000 => b@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] DKIM=test.ex:sed:test.ex:sel C="250 OK id=10HmbA-000000005vi-0000"
 1999-03-02 09:44:33 10HmaZ-000000005vi-0000 Completed
 
 ******** SERVER ********

diff --git a/test/log/4565 b/test/log/4565
index 4c74fc4d2caaa519ec0679c64c4d5b162ab8068f..48efed49d8b6041d8bd109da89ec74aa6c8c8c99 100644 (file)
--- a/test/log/4565
+++ b/test/log/4565
@@ -13,7 +13,7 @@
 1999-03-02 09:44:33 10HmaY-000000005vi-0000 arc_oldest_pass <1>
 1999-03-02 09:44:33 10HmaY-000000005vi-0000 domains:        <test.ex>
 1999-03-02 09:44:33 10HmaY-000000005vi-0000 <= CALLER@bloggs.com H=localhost (test.ex) [127.0.0.1] P=esmtp S=sss DKIM=test.ex ARC id=qwerty1234@disco-zombie.net for a@test.ex
-1999-03-02 09:44:33 10HmaX-000000005vi-0000 => a@test.ex <za@test.ex> R=fwd T=tsmtp H=127.0.0.1 [127.0.0.1] C="250 OK id=10HmaY-000000005vi-0000"
+1999-03-02 09:44:33 10HmaX-000000005vi-0000 => a@test.ex <za@test.ex> R=fwd T=tsmtp H=127.0.0.1 [127.0.0.1] DKIM=test.ex:sel C="250 OK id=10HmaY-000000005vi-0000"
 1999-03-02 09:44:33 10HmaX-000000005vi-0000 Completed
 1999-03-02 09:44:33 End queue run: pid=p1235
 1999-03-02 09:44:33 Start queue run: pid=p1236

diff --git a/test/runtest b/test/runtest
index 8628ff29905e3f8e73c2e861d9c0a8da41ce576f..3f4004cc18438d9e8aa6e651f5765e41c2734022 100755 (executable)
--- a/test/runtest
+++ b/test/runtest
@@ -1565,7 +1565,7 @@ RESET_AFTER_EXTRA_LINE_READ:
     next if / Berkeley DB error: /;
 
     # CHUNKING: exact sizes depend on hostnames in headers
-    s/(=>.* K C="250- \d)\d+ (byte chunk, total \d)\d+/$1nn $2nn/;
+    s/(=>.* K (?:DKIM=\S+ )?C="250- \d)\d+ (byte chunk, total \d)\d+/$1nn $2nn/;
 
     # OpenSSL version variances
     s/(TLS error on connection [^:]*: error:)[0-9A-F]{8}(:system library):(?:fopen|func\(4095\)|):(No such file or directory)$/$1xxxxxxxx$2:fopen:$3/;

diff --git a/test/stderr/4510 b/test/stderr/4510
index 47bcef891bfd8cc355c02ce251d4957ece153d48..39224679a9b4ceeb1f465846bc1aa13a7d8d854d 100644 (file)
--- a/test/stderr/4510
+++ b/test/stderr/4510
@@ -56,7 +56,7 @@ cmd buf flush ddd bytes (more expected)
   SMTP(close)>>
 cmdlog: '220:EHLO:250-:MAIL|:RCPT|:DATA:250:250:354:.:QUIT+:250:221'
 LOG: MAIN
-  => d@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] C="250 OK id=10HmbL-000000005vi-0000"
+  => d@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] DKIM=test.ex:sel_bad C="250 OK id=10HmbL-000000005vi-0000"
 LOG: MAIN
   Completed
 >>>>>>>>>>>>>>>> Exim pid=p1236 (local-accept-delivery) terminating with rc=0 >>>>>>>>>>>>>>>>

diff --git a/test/stderr/4530 b/test/stderr/4530
index b0126b584370a233b3cc393547ca163fd4b00356..eeeee68c8f2f0a8eb8574b68edba3c62d79c6159 100644 (file)
--- a/test/stderr/4530
+++ b/test/stderr/4530
@@ -66,7 +66,7 @@ cmd buf flush ddd bytes
   SMTP(close)>>
 cmdlog: '220:EHLO:250-:STARTTLS:220:EHLO:250-:MAIL|:RCPT|:DATA:250:250:354:.:QUIT:250:221'
 LOG: MAIN
-  => d@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes C="250 OK id=10HmbL-000000005vi-0000"
+  => d@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes DKIM=test.ex:sel_bad C="250 OK id=10HmbL-000000005vi-0000"
 LOG: MAIN
   Completed
 >>>>>>>>>>>>>>>> Exim pid=p1236 (local-accept-delivery) terminating with rc=0 >>>>>>>>>>>>>>>>