Shorten long daemon-startup log lines
[users/jgh/exim.git] / src / src / dkim.c
index e027a23b3213d227d3c12cf4659e0844eb14e31e..f510214439b23605335945a27a40911ade2da981 100644 (file)
@@ -2,7 +2,7 @@
 *     Exim - an Internet mail transport agent    *
 *************************************************/
 
-/* Copyright (c) University of Cambridge, 1995 - 2016 */
+/* Copyright (c) University of Cambridge, 1995 - 2017 */
 /* See the file NOTICE for conditions of use and distribution. */
 
 /* Code for DKIM support. Other DKIM relevant code is in
@@ -18,6 +18,7 @@ int dkim_verify_oldpool;
 pdkim_ctx *dkim_verify_ctx = NULL;
 pdkim_signature *dkim_signatures = NULL;
 pdkim_signature *dkim_cur_sig = NULL;
+static const uschar * dkim_collect_error = NULL;
 
 static int
 dkim_exim_query_dns_txt(char *name, char *answer)
@@ -69,7 +70,7 @@ pdkim_init();
 
 
 void
-dkim_exim_verify_init(void)
+dkim_exim_verify_init(BOOL dot_stuffing)
 {
 /* There is a store-reset between header & body reception
 so cannot use the main pool. Any allocs done by Exim
@@ -85,8 +86,12 @@ if (dkim_verify_ctx)
 
 /* Create new context */
 
-dkim_verify_ctx = pdkim_init_verify(&dkim_exim_query_dns_txt);
+dkim_verify_ctx = pdkim_init_verify(&dkim_exim_query_dns_txt, dot_stuffing);
 dkim_collect_input = !!dkim_verify_ctx;
+dkim_collect_error = NULL;
+
+/* Start feed up with any cached data */
+receive_get_cache();
 
 store_pool = dkim_verify_oldpool;
 }
@@ -99,10 +104,11 @@ int rc;
 
 store_pool = POOL_PERM;
 if (  dkim_collect_input
-   && (rc = pdkim_feed(dkim_verify_ctx, (char *)data, len)) != PDKIM_OK)
+   && (rc = pdkim_feed(dkim_verify_ctx, CS data, len)) != PDKIM_OK)
   {
+  dkim_collect_error = pdkim_errstr(rc);
   log_write(0, LOG_MAIN,
-            "DKIM: validation error: %.100s", pdkim_errstr(rc));
+            "DKIM: validation error: %.100s", dkim_collect_error);
   dkim_collect_input = FALSE;
   }
 store_pool = dkim_verify_oldpool;
@@ -112,27 +118,22 @@ store_pool = dkim_verify_oldpool;
 void
 dkim_exim_verify_finish(void)
 {
-pdkim_signature *sig = NULL;
-int dkim_signers_size = 0;
-int dkim_signers_ptr = 0;
-dkim_signers = NULL;
-int rc;
+pdkim_signature * sig = NULL;
+int dkim_signers_size = 0, dkim_signers_ptr = 0, rc;
+const uschar * errstr;
 
 store_pool = POOL_PERM;
 
 /* Delete eventual previous signature chain */
 
+dkim_signers = NULL;
 dkim_signatures = NULL;
 
-/* If we have arrived here with dkim_collect_input == FALSE, it
-means there was a processing error somewhere along the way.
-Log the incident and disable futher verification. */
-
-if (!dkim_collect_input)
+if (dkim_collect_error)
   {
   log_write(0, LOG_MAIN,
-            "DKIM: Error while running this message through validation,"
-            " disabling signature verification.");
+      "DKIM: Error during validation, disabling signature verification: %.100s",
+      dkim_collect_error);
   dkim_disable_verify = TRUE;
   goto out;
   }
@@ -141,46 +142,49 @@ dkim_collect_input = FALSE;
 
 /* Finish DKIM operation and fetch link to signatures chain */
 
-if ((rc = pdkim_feed_finish(dkim_verify_ctx, &dkim_signatures)) != PDKIM_OK)
+rc = pdkim_feed_finish(dkim_verify_ctx, &dkim_signatures, &errstr);
+if (rc != PDKIM_OK)
   {
-  log_write(0, LOG_MAIN,
-            "DKIM: validation error: %.100s", pdkim_errstr(rc));
+  log_write(0, LOG_MAIN, "DKIM: validation error: %.100s%s%s", pdkim_errstr(rc),
+           errstr ? ": " : "", errstr ? errstr : US"");
   goto out;
   }
 
 for (sig = dkim_signatures; sig; sig = sig->next)
   {
-  int size = 0;
-  int ptr = 0;
+  int size = 0, ptr = 0;
+  uschar * logmsg = NULL, * s;
 
   /* Log a line for each signature */
 
-  uschar *logmsg = string_append(NULL, &size, &ptr, 5,
-       string_sprintf("d=%s s=%s c=%s/%s a=%s b=%d ",
-             sig->domain,
-             sig->selector,
-             sig->canon_headers == PDKIM_CANON_SIMPLE ? "simple" : "relaxed",
-             sig->canon_body == PDKIM_CANON_SIMPLE ? "simple" : "relaxed",
-             sig->algo == PDKIM_ALGO_RSA_SHA256
-             ? "rsa-sha256"
-             : sig->algo == PDKIM_ALGO_RSA_SHA1 ? "rsa-sha1" : "err",
-             (int)sig->sigdata.len > -1 ? sig->sigdata.len * 8 : 0
-             ),
-
-       sig->identity ? string_sprintf("i=%s ", sig->identity) : US"",
-       sig->created > 0 ? string_sprintf("t=%lu ", sig->created) : US"",
-       sig->expires > 0 ? string_sprintf("x=%lu ", sig->expires) : US"",
-       sig->bodylength > -1 ? string_sprintf("l=%lu ", sig->bodylength) : US""
-       );
+  if (!(s = sig->domain)) s = US"<UNSET>";
+  logmsg = string_append(logmsg, &size, &ptr, 2, "d=", s);
+  if (!(s = sig->selector)) s = US"<UNSET>";
+  logmsg = string_append(logmsg, &size, &ptr, 2, " s=", s);
+  logmsg = string_append(logmsg, &size, &ptr, 7, 
+       " c=", sig->canon_headers == PDKIM_CANON_SIMPLE ? "simple" : "relaxed",
+       "/",   sig->canon_body    == PDKIM_CANON_SIMPLE ? "simple" : "relaxed",
+       " a=", sig->algo == PDKIM_ALGO_RSA_SHA256
+               ? "rsa-sha256"
+               : sig->algo == PDKIM_ALGO_RSA_SHA1 ? "rsa-sha1" : "err",
+       string_sprintf(" b=%d",
+                       (int)sig->sighash.len > -1 ? sig->sighash.len * 8 : 0));
+  if ((s= sig->identity)) string_append(logmsg, &size, &ptr, 2, " i=", s);
+  if (sig->created > 0) string_append(logmsg, &size, &ptr, 1,
+                                     string_sprintf(" t=%lu", sig->created));
+  if (sig->expires > 0) string_append(logmsg, &size, &ptr, 1,
+                                     string_sprintf(" x=%lu", sig->expires));
+  if (sig->bodylength > -1) string_append(logmsg, &size, &ptr, 1,
+                                     string_sprintf(" l=%lu", sig->bodylength));
 
   switch (sig->verify_status)
     {
     case PDKIM_VERIFY_NONE:
-      logmsg = string_append(logmsg, &size, &ptr, 1, "[not verified]");
+      logmsg = string_append(logmsg, &size, &ptr, 1, " [not verified]");
       break;
 
     case PDKIM_VERIFY_INVALID:
-      logmsg = string_append(logmsg, &size, &ptr, 1, "[invalid - ");
+      logmsg = string_append(logmsg, &size, &ptr, 1, " [invalid - ");
       switch (sig->verify_ext_status)
        {
        case PDKIM_VERIFY_INVALID_PUBKEY_UNAVAILABLE:
@@ -217,7 +221,7 @@ for (sig = dkim_signatures; sig; sig = sig->next)
 
     case PDKIM_VERIFY_FAIL:
       logmsg =
-       string_append(logmsg, &size, &ptr, 1, "[verification failed - ");
+       string_append(logmsg, &size, &ptr, 1, " [verification failed - ");
       switch (sig->verify_ext_status)
        {
        case PDKIM_VERIFY_FAIL_BODY:
@@ -237,7 +241,7 @@ for (sig = dkim_signatures; sig; sig = sig->next)
 
     case PDKIM_VERIFY_PASS:
       logmsg =
-       string_append(logmsg, &size, &ptr, 1, "[verification succeeded]");
+       string_append(logmsg, &size, &ptr, 1, " [verification succeeded]");
       break;
     }
 
@@ -246,27 +250,15 @@ for (sig = dkim_signatures; sig; sig = sig->next)
 
   /* Build a colon-separated list of signing domains (and identities, if present) in dkim_signers */
 
-  dkim_signers = string_append(dkim_signers,
-                               &dkim_signers_size,
-                               &dkim_signers_ptr, 2, sig->domain, ":");
+  if (sig->domain)
+    dkim_signers = string_append_listele(dkim_signers, ':', sig->domain);
 
   if (sig->identity)
-    dkim_signers = string_append(dkim_signers,
-                                 &dkim_signers_size,
-                                 &dkim_signers_ptr, 2, sig->identity, ":");
+    dkim_signers = string_append_listele(dkim_signers, ':', sig->identity);
 
   /* Process next signature */
   }
 
-/* NULL-terminate and chop the last colon from the domain list */
-
-if (dkim_signers)
-  {
-  dkim_signers[dkim_signers_ptr] = '\0';
-  if (Ustrlen(dkim_signers) > 0)
-  dkim_signers[Ustrlen(dkim_signers) - 1] = '\0';
-  }
-
 out:
 store_pool = dkim_verify_oldpool;
 }
@@ -303,7 +295,7 @@ for (sig = dkim_signatures; sig; sig = sig->next)
 
     dkim_signing_domain = US sig->domain;
     dkim_signing_selector = US sig->selector;
-    dkim_key_length = sig->sigdata.len * 8;
+    dkim_key_length = sig->sighash.len * 8;
     return;
     }
 }
@@ -457,10 +449,9 @@ switch (what)
 
 
 uschar *
-dkim_exim_sign(int dkim_fd, uschar * dkim_private_key,
-               const uschar * dkim_domain, uschar * dkim_selector,
-               uschar * dkim_canon, uschar * dkim_sign_headers)
+dkim_exim_sign(int dkim_fd, struct ob_dkim * dkim, const uschar ** errstr)
 {
+const uschar * dkim_domain;
 int sep = 0;
 uschar *seen_items = NULL;
 int seen_items_size = 0;
@@ -484,7 +475,7 @@ int old_pool = store_pool;
 
 store_pool = POOL_MAIN;
 
-if (!(dkim_domain = expand_cstring(dkim_domain)))
+if (!(dkim_domain = expand_cstring(dkim->dkim_domain)))
   {
   /* expansion error, do not send message. */
   log_write(0, LOG_MAIN | LOG_PANIC, "failed to expand "
@@ -522,7 +513,7 @@ while ((dkim_signing_domain = string_nextinlist(&dkim_domain, &sep,
 
   /* Set up $dkim_selector expansion variable. */
 
-  if (!(dkim_signing_selector = expand_string(dkim_selector)))
+  if (!(dkim_signing_selector = expand_string(dkim->dkim_selector)))
     {
     log_write(0, LOG_MAIN | LOG_PANIC, "failed to expand "
               "dkim_selector: %s", expand_string_message);
@@ -531,7 +522,8 @@ while ((dkim_signing_domain = string_nextinlist(&dkim_domain, &sep,
 
   /* Get canonicalization to use */
 
-  dkim_canon_expanded = dkim_canon ? expand_string(dkim_canon) : US"relaxed";
+  dkim_canon_expanded = dkim->dkim_canon
+    ? expand_string(dkim->dkim_canon) : US"relaxed";
   if (!dkim_canon_expanded)
     {
     /* expansion error, do not send message. */
@@ -553,8 +545,8 @@ while ((dkim_signing_domain = string_nextinlist(&dkim_domain, &sep,
     }
 
   dkim_sign_headers_expanded = NULL;
-  if (dkim_sign_headers)
-    if (!(dkim_sign_headers_expanded = expand_string(dkim_sign_headers)))
+  if (dkim->dkim_sign_headers)
+    if (!(dkim_sign_headers_expanded = expand_string(dkim->dkim_sign_headers)))
       {
       log_write(0, LOG_MAIN | LOG_PANIC, "failed to expand "
                 "dkim_sign_headers: %s", expand_string_message);
@@ -564,7 +556,7 @@ while ((dkim_signing_domain = string_nextinlist(&dkim_domain, &sep,
 
   /* Get private key to use. */
 
-  if (!(dkim_private_key_expanded = expand_string(dkim_private_key)))
+  if (!(dkim_private_key_expanded = expand_string(dkim->dkim_private_key)))
     {
     log_write(0, LOG_MAIN | LOG_PANIC, "failed to expand "
               "dkim_private_key: %s", expand_string_message);
@@ -579,13 +571,13 @@ while ((dkim_signing_domain = string_nextinlist(&dkim_domain, &sep,
 
   if (dkim_private_key_expanded[0] == '/')
     {
-    int privkey_fd = 0;
+    int privkey_fd, off = 0, len;
 
     /* Looks like a filename, load the private key. */
 
     memset(big_buffer, 0, big_buffer_size);
-    privkey_fd = open(CS dkim_private_key_expanded, O_RDONLY);
-    if (privkey_fd < 0)
+
+    if ((privkey_fd = open(CS dkim_private_key_expanded, O_RDONLY)) < 0)
       {
       log_write(0, LOG_MAIN | LOG_PANIC, "unable to open "
                 "private key file for reading: %s",
@@ -593,30 +585,43 @@ while ((dkim_signing_domain = string_nextinlist(&dkim_domain, &sep,
       goto bad;
       }
 
-    if (read(privkey_fd, big_buffer, big_buffer_size - 2) < 0)
+    do
       {
-      log_write(0, LOG_MAIN|LOG_PANIC, "unable to read private key file: %s",
-                dkim_private_key_expanded);
-      goto bad;
+      if ((len = read(privkey_fd, big_buffer + off, big_buffer_size - 2 - off)) < 0)
+       {
+       (void) close(privkey_fd);
+       log_write(0, LOG_MAIN|LOG_PANIC, "unable to read private key file: %s",
+                  dkim_private_key_expanded);
+       goto bad;
+       }
+      off += len;
       }
+    while (len > 0);
 
     (void) close(privkey_fd);
+    big_buffer[off] = '\0';
     dkim_private_key_expanded = big_buffer;
     }
 
-  ctx = pdkim_init_sign( CS dkim_signing_domain,
-                        CS dkim_signing_selector,
-                        CS dkim_private_key_expanded,
-                        PDKIM_ALGO_RSA_SHA256);
+  if (!(ctx = pdkim_init_sign(CS dkim_signing_domain,
+                       CS dkim_signing_selector,
+                       CS dkim_private_key_expanded,
+                       PDKIM_ALGO_RSA_SHA256,
+                       dkim->dot_stuffed,
+                       &dkim_exim_query_dns_txt,
+                       errstr
+                       )))
+    goto bad;
+  dkim_private_key_expanded[0] = '\0';
   pdkim_set_optional(ctx,
-                     (char *) dkim_sign_headers_expanded,
+                     CS dkim_sign_headers_expanded,
                      NULL,
                      pdkim_canon,
                      pdkim_canon, -1, 0, 0);
 
   lseek(dkim_fd, 0, SEEK_SET);
 
-  while ((sread = read(dkim_fd, &buf, 4096)) > 0)
+  while ((sread = read(dkim_fd, &buf, sizeof(buf))) > 0)
     if ((pdkim_rc = pdkim_feed(ctx, buf, sread)) != PDKIM_OK)
       goto pk_bad;
 
@@ -628,7 +633,7 @@ while ((dkim_signing_domain = string_nextinlist(&dkim_domain, &sep,
     goto bad;
     }
 
-  if ((pdkim_rc = pdkim_feed_finish(ctx, &signature)) != PDKIM_OK)
+  if ((pdkim_rc = pdkim_feed_finish(ctx, &signature, errstr)) != PDKIM_OK)
     goto pk_bad;
 
   sigbuf = string_append(sigbuf, &sigsize, &sigptr, 2,