[exim-cvs] DKIM: logging for signing in transport. Bug 3062

Inizio della pagina
Delete this message
Reply to this message
Autore: Exim Git Commits Mailing List
Data:  
To: exim-cvs
Oggetto: [exim-cvs] DKIM: logging for signing in transport. Bug 3062
Gitweb: https://git.exim.org/exim.git/commitdiff/80bacd22c5aaacd7fca966af7384ac6f2679cb21
Commit:     80bacd22c5aaacd7fca966af7384ac6f2679cb21
Parent:     f78e417c3c2e7348ce58bb03efc7343bb6d32383
Author:     Jeremy Harris <jgh146exb@???>
AuthorDate: Fri Dec 29 12:40:22 2023 +0000
Committer:  Jeremy Harris <jgh146exb@???>
CommitDate: Fri Dec 29 12:40:22 2023 +0000


    DKIM: logging for signing in transport. Bug 3062
---
 doc/doc-docbook/spec.xfpt |  6 +++++-
 doc/doc-txt/NewStuff      |  2 ++
 src/src/deliver.c         | 26 +++++++++++++++++++++++++-
 src/src/dkim.c            |  3 +++
 src/src/dkim_transport.c  | 14 ++++++++++----
 src/src/globals.c         |  1 +
 src/src/globals.h         |  1 +
 src/src/structs.h         |  9 ++++++---
 test/log/4510             | 16 ++++++++--------
 test/log/4511             |  4 ++--
 test/log/4513             |  2 +-
 test/log/4514             |  2 +-
 test/log/4519             |  4 ++--
 test/log/4530             | 16 ++++++++--------
 test/log/4531             |  4 ++--
 test/log/4533             |  2 +-
 test/log/4534             |  2 +-
 test/log/4539             |  4 ++--
 test/log/4541             |  4 ++--
 test/log/4545             |  4 ++--
 test/log/4565             |  2 +-
 test/runtest              |  2 +-
 test/stderr/4510          |  2 +-
 test/stderr/4530          |  2 +-
 24 files changed, 89 insertions(+), 45 deletions(-)


diff --git a/doc/doc-docbook/spec.xfpt b/doc/doc-docbook/spec.xfpt
index ae3cc1748..2c90ec5f3 100644
--- a/doc/doc-docbook/spec.xfpt
+++ b/doc/doc-docbook/spec.xfpt
@@ -39061,7 +39061,7 @@ selection marked by asterisks:
 .irow &`deliver_time`&            &nbsp; "time taken to attempt delivery"
 .irow &`delivery_size`&            &nbsp; "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 6aef41e50..1a5dac27b 100644
--- 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 e96733f73..2cef3d731 100644
--- 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 ea82f34ea..59025608f 100644
--- 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 fae2f4891..38f849af6 100644
--- 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 bb5bd6b1a..c535ea121 100644
--- 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 fe4a1610a..ffc7150f2 100644
--- 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 256560ef8..b16a8a3f2 100644
--- 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 08f73d5b4..7632951d0 100644
--- a/test/log/4510
+++ b/test/log/4510
@@ -1,23 +1,23 @@
 1999-03-02 09:44:33 10HmaY-000000005vi-0000 <= CALLER@??? U=CALLER P=local S=sss for a@???
-1999-03-02 09:44:33 10HmaY-000000005vi-0000 => a@??? 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@??? 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@??? U=CALLER P=local S=sss for b@???
-1999-03-02 09:44:33 10HmbA-000000005vi-0000 => b@??? 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@??? 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@??? U=CALLER P=local S=sss for b10@???
-1999-03-02 09:44:33 10HmbC-000000005vi-0000 => b10@??? 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@??? 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@??? U=CALLER P=local S=sss for b12@???
-1999-03-02 09:44:33 10HmbE-000000005vi-0000 => b12@??? 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@??? 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@??? U=CALLER P=local S=sss for b20@???
-1999-03-02 09:44:33 10HmbG-000000005vi-0000 => b20@??? 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@??? 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@??? U=CALLER P=local S=sss for b22@???
-1999-03-02 09:44:33 10HmbI-000000005vi-0000 => b22@??? 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@??? 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@??? U=CALLER P=local S=sss for d@???
-1999-03-02 09:44:33 10HmbK-000000005vi-0000 => d@??? 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@??? 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@???
 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@??? 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@??? U=CALLER P=local S=sss for f@???
-1999-03-02 09:44:33 10HmbO-000000005vi-0000 => f@??? 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@??? 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 b45c16fbb..2b6340344 100644
--- a/test/log/4511
+++ b/test/log/4511
@@ -1,8 +1,8 @@
2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 <= sender@??? U=sender Ci=p1234 P=local S=sss for a@???
-2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 => a@??? 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@??? 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@??? U=sender Ci=p1235 P=local S=sss for b@???
-2017-07-30 18:51:05.712 10HmaZ-000000005vi-0000 => b@??? 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@??? 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 a3c53de81..c72693ca1 100644
--- a/test/log/4513
+++ b/test/log/4513
@@ -1,5 +1,5 @@
1999-03-02 09:44:33 10HmaX-000000005vi-0000 <= CALLER@??? U=CALLER P=local S=sss for a@???
-1999-03-02 09:44:33 10HmaX-000000005vi-0000 => a@??? 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@??? 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 6d489fb99..619023da0 100644
--- a/test/log/4514
+++ b/test/log/4514
@@ -1,5 +1,5 @@
1999-03-02 09:44:33 10HmaX-000000005vi-0000 <= CALLER@??? U=CALLER P=local S=sss for c@???
-1999-03-02 09:44:33 10HmaX-000000005vi-0000 => c@??? 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@??? 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 24aba0b1e..02ddaebff 100644
--- 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@???
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@??? 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@??? 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@??? H=(xxx) [127.0.0.1] P=esmtp K S=sss for y@???
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@???
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@??? 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@??? 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 bd0e40ae2..74713e09d 100644
--- a/test/log/4530
+++ b/test/log/4530
@@ -1,23 +1,23 @@
1999-03-02 09:44:33 10HmaY-000000005vi-0000 <= CALLER@??? U=CALLER P=local S=sss for a@???
-1999-03-02 09:44:33 10HmaY-000000005vi-0000 => a@??? 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@??? 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@??? U=CALLER P=local S=sss for b@???
-1999-03-02 09:44:33 10HmbA-000000005vi-0000 => b@??? 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@??? 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@??? U=CALLER P=local S=sss for b10@???
-1999-03-02 09:44:33 10HmbC-000000005vi-0000 => b10@??? 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@??? 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@??? U=CALLER P=local S=sss for b12@???
-1999-03-02 09:44:33 10HmbE-000000005vi-0000 => b12@??? 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@??? 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@??? U=CALLER P=local S=sss for b20@???
-1999-03-02 09:44:33 10HmbG-000000005vi-0000 => b20@??? 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@??? 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@??? U=CALLER P=local S=sss for b22@???
-1999-03-02 09:44:33 10HmbI-000000005vi-0000 => b22@??? 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@??? 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@??? U=CALLER P=local S=sss for d@???
-1999-03-02 09:44:33 10HmbK-000000005vi-0000 => d@??? 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@??? 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@???
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@??? 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@??? U=CALLER P=local S=sss for f@???
-1999-03-02 09:44:33 10HmbO-000000005vi-0000 => f@??? 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@??? 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 bd642b51f..45994c751 100644
--- a/test/log/4531
+++ b/test/log/4531
@@ -1,8 +1,8 @@
2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 <= sender@??? U=sender Ci=p1234 P=local S=sss for a@???
-2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 => a@??? 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@??? 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@??? U=sender Ci=p1235 P=local S=sss for b@???
-2017-07-30 18:51:05.712 10HmaZ-000000005vi-0000 => b@??? 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@??? 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 3e8343539..0483ddc08 100644
--- a/test/log/4533
+++ b/test/log/4533
@@ -1,5 +1,5 @@
1999-03-02 09:44:33 10HmaX-000000005vi-0000 <= CALLER@??? U=CALLER P=local S=sss for a@???
-1999-03-02 09:44:33 10HmaX-000000005vi-0000 => a@??? 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@??? 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 4f386c95c..d80dc7154 100644
--- a/test/log/4534
+++ b/test/log/4534
@@ -1,5 +1,5 @@
1999-03-02 09:44:33 10HmaX-000000005vi-0000 <= CALLER@??? U=CALLER P=local S=sss for c@???
-1999-03-02 09:44:33 10HmaX-000000005vi-0000 => c@??? 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@??? 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 9b0269b6c..5f503f6b2 100644
--- 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@???
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@??? 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@??? 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@??? H=(xxx) [127.0.0.1] P=smtps X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no K S=sss for y@???
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@???
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@??? 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@??? 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 bc998cc35..f2d4c325b 100644
--- a/test/log/4541
+++ b/test/log/4541
@@ -1,8 +1,8 @@
1999-03-02 09:44:33 10HmaX-000000005vi-0000 <= CALLER@??? U=CALLER P=local S=sss for a@???
-1999-03-02 09:44:33 10HmaX-000000005vi-0000 => a@??? 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@??? 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@??? U=CALLER P=local S=sss for b@???
-1999-03-02 09:44:33 10HmaZ-000000005vi-0000 => b@??? 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@??? 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 cb1918b2f..c983a7a96 100644
--- a/test/log/4545
+++ b/test/log/4545
@@ -1,8 +1,8 @@
1999-03-02 09:44:33 10HmaX-000000005vi-0000 <= CALLER@??? U=CALLER P=local S=sss for a@???
-1999-03-02 09:44:33 10HmaX-000000005vi-0000 => a@??? 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@??? 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@??? U=CALLER P=local S=sss for b@???
-1999-03-02 09:44:33 10HmaZ-000000005vi-0000 => b@??? 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@??? 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 4c74fc4d2..48efed49d 100644
--- 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@??? H=localhost (test.ex) [127.0.0.1] P=esmtp S=sss DKIM=test.ex ARC id=qwerty1234@??? for a@???
-1999-03-02 09:44:33 10HmaX-000000005vi-0000 => a@??? <za@???> 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@??? <za@???> 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 8628ff299..3f4004cc1 100755
--- 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 47bcef891..39224679a 100644
--- 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@??? R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] C="250 OK id=10HmbL-000000005vi-0000"
+  => d@??? 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 b0126b584..eeeee68c8 100644
--- 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@??? 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@??? 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 >>>>>>>>>>>>>>>>


--
## subscription configuration (requires account):
## https://lists.exim.org/mailman3/postorius/lists/exim-cvs.lists.exim.org/
## unsubscribe (doesn't require an account):
## exim-cvs-unsubscribe@???
## Exim details at http://www.exim.org/
## Please use the Wiki with this list - http://wiki.exim.org/