Fix error logging for dynamically-loaded modules. Bug 2507
[users/jgh/exim.git] / src / src / dkim.c
index 4fe4a11ab41ff48ba4d810464822cb8c03514706..5c9d2279e165767715385013862a330b81023c9d 100644 (file)
@@ -26,35 +26,39 @@ builtin_macro_create_var(US"_DKIM_SIGN_HEADERS", US PDKIM_DEFAULT_SIGN_HEADERS);
 
 
 
+pdkim_ctx dkim_sign_ctx;
 
 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;
 
+#define DKIM_MAX_SIGNATURES 20
 
 
-/*XXX the caller only uses the first record if we return multiple.
+
+/* Look up the DKIM record in DNS for the given hostname.
+Will use the first found if there are multiple.
+The return string is tainted, having come from off-site.
 */
 
-static uschar *
-dkim_exim_query_dns_txt(char * name)
+uschar *
+dkim_exim_query_dns_txt(const uschar * name)
 {
-dns_answer dnsa;
+dns_answer * dnsa = store_get_dns_answer();
 dns_scan dnss;
-dns_record *rr;
+rmark reset_point = store_mark();
 gstring * g = NULL;
 
 lookup_dnssec_authenticated = NULL;
-if (dns_lookup(&dnsa, US name, T_TXT, NULL) != DNS_SUCCEED)
+if (dns_lookup(dnsa, name, T_TXT, NULL) != DNS_SUCCEED)
   return NULL; /*XXX better error detail?  logging? */
 
 /* Search for TXT record */
 
-for (rr = dns_next_rr(&dnsa, &dnss, RESET_ANSWERS);
+for (dns_record * rr = dns_next_rr(dnsa, &dnss, RESET_ANSWERS);
      rr;
-     rr = dns_next_rr(&dnsa, &dnss, RESET_NEXT))
+     rr = dns_next_rr(dnsa, &dnss, RESET_NEXT))
   if (rr->type == T_TXT)
     {
     int rr_offset = 0;
@@ -75,7 +79,7 @@ for (rr = dns_next_rr(&dnsa, &dnss, RESET_ANSWERS);
     /* check if this looks like a DKIM record */
     if (Ustrncmp(g->s, "v=", 2) != 0 || strncasecmp(CS g->s, "v=dkim", 6) == 0)
       {
-      store_reset(g->s + g->ptr + 1);
+      gstring_release_unused(g);
       return string_from_gstring(g);
       }
 
@@ -83,7 +87,7 @@ for (rr = dns_next_rr(&dnsa, &dnss, RESET_ANSWERS);
     }
 
 bad:
-if (g) store_reset(g);
+store_reset(reset_point);
 return NULL;   /*XXX better error detail?  logging? */
 }
 
@@ -91,6 +95,8 @@ return NULL;  /*XXX better error detail?  logging? */
 void
 dkim_exim_init(void)
 {
+if (f.dkim_init_done) return;
+f.dkim_init_done = TRUE;
 pdkim_init();
 }
 
@@ -99,6 +105,8 @@ pdkim_init();
 void
 dkim_exim_verify_init(BOOL dot_stuffing)
 {
+dkim_exim_init();
+
 /* There is a store-reset between header & body reception
 so cannot use the main pool. Any allocs done by Exim
 memory-handling must use the perm pool. */
@@ -114,7 +122,7 @@ if (dkim_verify_ctx)
 /* Create new context */
 
 dkim_verify_ctx = pdkim_init_verify(&dkim_exim_query_dns_txt, dot_stuffing);
-dkim_collect_input = !!dkim_verify_ctx;
+dkim_collect_input = dkim_verify_ctx ? DKIM_MAX_SIGNATURES : 0;
 dkim_collect_error = NULL;
 
 /* Start feed up with any cached data */
@@ -136,7 +144,7 @@ if (  dkim_collect_input
   dkim_collect_error = pdkim_errstr(rc);
   log_write(0, LOG_MAIN,
             "DKIM: validation error: %.100s", dkim_collect_error);
-  dkim_collect_input = FALSE;
+  dkim_collect_input = 0;
   }
 store_pool = dkim_verify_oldpool;
 }
@@ -190,19 +198,18 @@ if (!(s = sig->domain)) s = US"<UNSET>";
 logmsg = string_append(logmsg, 2, "d=", s);
 if (!(s = sig->selector)) s = US"<UNSET>";
 logmsg = string_append(logmsg, 2, " s=", s);
-logmsg = string_append(logmsg, 7,
-  " c=", sig->canon_headers == PDKIM_CANON_SIMPLE ? "simple" : "relaxed",
-  "/",   sig->canon_body    == PDKIM_CANON_SIMPLE ? "simple" : "relaxed",
-  " a=", dkim_sig_to_a_tag(sig),
-string_sprintf(" b=" SIZE_T_FMT,
-               (int)sig->sighash.len > -1 ? sig->sighash.len * 8 : 0));
+logmsg = string_fmt_append(logmsg, " c=%s/%s a=%s b=" SIZE_T_FMT,
+         sig->canon_headers == PDKIM_CANON_SIMPLE ? "simple" : "relaxed",
+         sig->canon_body    == PDKIM_CANON_SIMPLE ? "simple" : "relaxed",
+         dkim_sig_to_a_tag(sig),
+         (int)sig->sighash.len > -1 ? sig->sighash.len * 8 : (size_t)0);
 if ((s= sig->identity)) logmsg = string_append(logmsg, 2, " i=", s);
-if (sig->created > 0) logmsg = string_cat(logmsg,
-                             string_sprintf(" t=%lu", sig->created));
-if (sig->expires > 0) logmsg = string_cat(logmsg,
-                             string_sprintf(" x=%lu", sig->expires));
-if (sig->bodylength > -1) logmsg = string_cat(logmsg,
-                             string_sprintf(" l=%lu", sig->bodylength));
+if (sig->created > 0) logmsg = string_fmt_append(logmsg, " t=%lu",
+                                   sig->created);
+if (sig->expires > 0) logmsg = string_fmt_append(logmsg, " x=%lu",
+                                   sig->expires);
+if (sig->bodylength > -1) logmsg = string_fmt_append(logmsg, " l=%lu",
+                                   sig->bodylength);
 
 if (sig->verify_status & PDKIM_VERIFY_POLICY)
   logmsg = string_append(logmsg, 5,
@@ -279,15 +286,14 @@ return;
 void
 dkim_exim_verify_log_all(void)
 {
-pdkim_signature * sig;
-for (sig = dkim_signatures; sig; sig = sig->next) dkim_exim_verify_log_sig(sig);
+for (pdkim_signature * sig = dkim_signatures; sig; sig = sig->next)
+  dkim_exim_verify_log_sig(sig);
 }
 
 
 void
 dkim_exim_verify_finish(void)
 {
-pdkim_signature * sig;
 int rc;
 gstring * g = NULL;
 const uschar * errstr = NULL;
@@ -304,21 +310,22 @@ if (dkim_collect_error)
   log_write(0, LOG_MAIN,
       "DKIM: Error during validation, disabling signature verification: %.100s",
       dkim_collect_error);
-  dkim_disable_verify = TRUE;
+  f.dkim_disable_verify = TRUE;
   goto out;
   }
 
-dkim_collect_input = FALSE;
+dkim_collect_input = 0;
 
 /* Finish DKIM operation and fetch link to signatures chain */
 
-rc = pdkim_feed_finish(dkim_verify_ctx, &dkim_signatures, &errstr);
+rc = pdkim_feed_finish(dkim_verify_ctx, (pdkim_signature **)&dkim_signatures,
+                       &errstr);
 if (rc != PDKIM_OK && errstr)
   log_write(0, LOG_MAIN, "DKIM: validation error: %s", errstr);
 
 /* Build a colon-separated list of signing domains (and identities, if present) in dkim_signers */
 
-for (sig = dkim_signatures; sig; sig = sig->next)
+for (pdkim_signature * sig = dkim_signatures; sig; sig = sig->next)
   {
   if (sig->domain)   g = string_append_listele(g, ':', sig->domain);
   if (sig->identity) g = string_append_listele(g, ':', sig->identity);
@@ -370,7 +377,6 @@ int
 dkim_exim_acl_run(uschar * id, gstring ** res_ptr,
   uschar ** user_msgptr, uschar ** log_msgptr)
 {
-pdkim_signature * sig;
 uschar * cmp_val;
 int rc = -1;
 
@@ -378,12 +384,12 @@ dkim_verify_status = US"none";
 dkim_verify_reason = US"";
 dkim_cur_signer = id;
 
-if (dkim_disable_verify || !id || !dkim_verify_ctx)
+if (f.dkim_disable_verify || !id || !dkim_verify_ctx)
   return OK;
 
 /* Find signatures to run ACL on */
 
-for (sig = dkim_signatures; sig; sig = sig->next)
+for (pdkim_signature * sig = dkim_signatures; sig; sig = sig->next)
   if (  (cmp_val = Ustrchr(id, '@') != NULL ? US sig->identity : US sig->domain)
      && strcmpic(cmp_val, id) == 0
      )
@@ -394,7 +400,7 @@ for (sig = dkim_signatures; sig; sig = sig->next)
     them here. This is easy since a domain and selector is guaranteed
     to be in a signature. The other dkim_* expansion items are
     dynamically fetched from dkim_cur_sig at expansion time (see
-    function below). */
+    dkim_exim_expand_query() below). */
 
     dkim_cur_sig = sig;
     dkim_signing_domain = US sig->domain;
@@ -450,7 +456,7 @@ switch (what)
 uschar *
 dkim_exim_expand_query(int what)
 {
-if (!dkim_verify_ctx || dkim_disable_verify || !dkim_cur_sig)
+if (!dkim_verify_ctx || f.dkim_disable_verify || !dkim_cur_sig)
   return dkim_exim_expand_defaults(what);
 
 switch (what)
@@ -563,6 +569,18 @@ switch (what)
 }
 
 
+void
+dkim_exim_sign_init(void)
+{
+int old_pool = store_pool;
+
+dkim_exim_init();
+store_pool = POOL_MAIN;
+pdkim_init_context(&dkim_sign_ctx, FALSE, &dkim_exim_query_dns_txt);
+store_pool = old_pool;
+}
+
+
 /* Generate signatures for the given file.
 If a prefix is given, prepend it to the file for the calculations.
 
@@ -575,10 +593,9 @@ gstring *
 dkim_exim_sign(int fd, off_t off, uschar * prefix,
   struct ob_dkim * dkim, const uschar ** errstr)
 {
-const uschar * dkim_domain;
+const uschar * dkim_domain = NULL;
 int sep = 0;
 gstring * seen_doms = NULL;
-pdkim_ctx ctx;
 pdkim_signature * sig;
 gstring * sigbuf;
 int pdkim_rc;
@@ -587,18 +604,21 @@ uschar buf[4096];
 int save_errno = 0;
 int old_pool = store_pool;
 uschar * errwhen;
+const uschar * s;
 
-store_pool = POOL_MAIN;
+if (dkim->dot_stuffed)
+  dkim_sign_ctx.flags |= PDKIM_DOT_TERM;
 
-pdkim_init_context(&ctx, dkim->dot_stuffed, &dkim_exim_query_dns_txt);
+store_pool = POOL_MAIN;
 
-if (!(dkim_domain = expand_cstring(dkim->dkim_domain)))
+if ((s = dkim->dkim_domain) && !(dkim_domain = expand_cstring(s)))
   /* expansion error, do not send message. */
   { errwhen = US"dkim_domain"; goto expand_bad; }
 
 /* Set $dkim_domain expansion variable to each unique domain in list. */
 
-while ((dkim_signing_domain = string_nextinlist(&dkim_domain, &sep, NULL, 0)))
+if (dkim_domain)
+  while ((dkim_signing_domain = string_nextinlist(&dkim_domain, &sep, NULL, 0)))
   {
   const uschar * dkim_sel;
   int sel_sep = 0;
@@ -609,6 +629,7 @@ while ((dkim_signing_domain = string_nextinlist(&dkim_domain, &sep, NULL, 0)))
   /* Only sign once for each domain, no matter how often it
   appears in the expanded list. */
 
+  dkim_signing_domain = string_copylc(dkim_signing_domain);
   if (match_isinlist(dkim_signing_domain, CUSS &seen_doms,
       0, NULL, NULL, MCL_STRING, TRUE, NULL) == OK)
     continue;
@@ -619,7 +640,6 @@ while ((dkim_signing_domain = string_nextinlist(&dkim_domain, &sep, NULL, 0)))
   for this domain. */
 
   if (!(dkim_sel = expand_string(dkim->dkim_selector)))
-  if (!(dkim_signing_selector = expand_string(dkim->dkim_selector)))
     { errwhen = US"dkim_selector"; goto expand_bad; }
 
   while ((dkim_signing_selector = string_nextinlist(&dkim_sel, &sel_sep,
@@ -631,6 +651,8 @@ while ((dkim_signing_domain = string_nextinlist(&dkim_domain, &sep, NULL, 0)))
     uschar * dkim_private_key_expanded;
     uschar * dkim_hash_expanded;
     uschar * dkim_identity_expanded = NULL;
+    uschar * dkim_timestamps_expanded = NULL;
+    unsigned long tval = 0, xval = 0;
 
     /* Get canonicalization to use */
 
@@ -667,39 +689,10 @@ while ((dkim_signing_domain = string_nextinlist(&dkim_domain, &sep, NULL, 0)))
        )
       continue;                /* don't sign, but no error */
 
-    if (dkim_private_key_expanded[0] == '/')
-      {
-      int privkey_fd, off = 0, len;
-
-      /* Looks like a filename, load the private key. */
-
-      memset(big_buffer, 0, big_buffer_size);
-
-      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",
-                  dkim_private_key_expanded);
-       goto bad;
-       }
-
-      do
-       {
-       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;
-      }
+    if (  dkim_private_key_expanded[0] == '/'
+       && !(dkim_private_key_expanded =
+            expand_file_big_buffer(dkim_private_key_expanded)))
+      goto bad;
 
     if (!(dkim_hash_expanded = expand_string(dkim->dkim_hash)))
       { errwhen = US"dkim_hash"; goto expand_bad; }
@@ -710,10 +703,14 @@ while ((dkim_signing_domain = string_nextinlist(&dkim_domain, &sep, NULL, 0)))
       else if (!*dkim_identity_expanded)
        dkim_identity_expanded = NULL;
 
-  /*XXX so we currently nail signing to RSA + this hash.
-  Need to extract algo from privkey and check for disallowed combos. */
+    if (dkim->dkim_timestamps)
+      if (!(dkim_timestamps_expanded = expand_string(dkim->dkim_timestamps)))
+       { errwhen = US"dkim_timestamps"; goto expand_bad; }
+      else
+       xval = (tval = (unsigned long) time(NULL))
+             + strtoul(CCS dkim_timestamps_expanded, NULL, 10);
 
-    if (!(sig = pdkim_init_sign(&ctx, dkim_signing_domain,
+    if (!(sig = pdkim_init_sign(&dkim_sign_ctx, dkim_signing_domain,
                          dkim_signing_selector,
                          dkim_private_key_expanded,
                          dkim_hash_expanded,
@@ -726,53 +723,63 @@ while ((dkim_signing_domain = string_nextinlist(&dkim_domain, &sep, NULL, 0)))
                        CS dkim_sign_headers_expanded,
                        CS dkim_identity_expanded,
                        pdkim_canon,
-                       pdkim_canon, -1, 0, 0);
+                       pdkim_canon, -1, tval, xval);
 
-    if (!pdkim_set_bodyhash(&ctx, sig))
+    if (!pdkim_set_sig_bodyhash(&dkim_sign_ctx, sig))
       goto bad;
 
-    if (!ctx.sig)              /* link sig to context chain */
-      ctx.sig = sig;
+    if (!dkim_sign_ctx.sig)            /* link sig to context chain */
+      dkim_sign_ctx.sig = sig;
     else
       {
-      pdkim_signature * n = ctx.sig;
+      pdkim_signature * n = dkim_sign_ctx.sig;
       while (n->next) n = n->next;
       n->next = sig;
       }
     }
   }
-if (!ctx.sig)
+
+/* We may need to carry on with the data-feed even if there are no DKIM sigs to
+produce, if some other package (eg. ARC) is signing. */
+
+if (!dkim_sign_ctx.sig && !dkim->force_bodyhash)
   {
   DEBUG(D_transport) debug_printf("DKIM: no viable signatures to use\n");
   sigbuf = string_get(1);      /* return a zero-len string */
-  goto CLEANUP;
   }
-
-if (prefix && (pdkim_rc = pdkim_feed(&ctx, prefix, Ustrlen(prefix))) != PDKIM_OK)
-  goto pk_bad;
-
-if (lseek(fd, off, SEEK_SET) < 0)
-  sread = -1;
 else
-  while ((sread = read(fd, &buf, sizeof(buf))) > 0)
-    if ((pdkim_rc = pdkim_feed(&ctx, buf, sread)) != PDKIM_OK)
-      goto pk_bad;
-
-/* Handle failed read above. */
-if (sread == -1)
   {
-  debug_printf("DKIM: Error reading -K file.\n");
-  save_errno = errno;
-  goto bad;
-  }
+  if (prefix && (pdkim_rc = pdkim_feed(&dkim_sign_ctx, prefix, Ustrlen(prefix))) != PDKIM_OK)
+    goto pk_bad;
 
-/* Build string of headers, one per signature */
+  if (lseek(fd, off, SEEK_SET) < 0)
+    sread = -1;
+  else
+    while ((sread = read(fd, &buf, sizeof(buf))) > 0)
+      if ((pdkim_rc = pdkim_feed(&dkim_sign_ctx, buf, sread)) != PDKIM_OK)
+       goto pk_bad;
+
+  /* Handle failed read above. */
+  if (sread == -1)
+    {
+    debug_printf("DKIM: Error reading -K file.\n");
+    save_errno = errno;
+    goto bad;
+    }
+
+  /* Build string of headers, one per signature */
 
-if ((pdkim_rc = pdkim_feed_finish(&ctx, &sig, errstr)) != PDKIM_OK)
-  goto pk_bad;
+  if ((pdkim_rc = pdkim_feed_finish(&dkim_sign_ctx, &sig, errstr)) != PDKIM_OK)
+    goto pk_bad;
 
-for (sigbuf = NULL; sig; sig = sig->next)
-  sigbuf = string_append(sigbuf, 2, US sig->signature_header, US"\r\n");
+  if (!sig)
+    {
+    DEBUG(D_transport) debug_printf("DKIM: no signatures to use\n");
+    sigbuf = string_get(1);    /* return a zero-len string */
+    }
+  else for (sigbuf = NULL; sig; sig = sig->next)
+    sigbuf = string_append(sigbuf, 2, US sig->signature_header, US"\r\n");
+  }
 
 CLEANUP:
   (void) string_from_gstring(sigbuf);
@@ -782,14 +789,15 @@ CLEANUP:
 
 pk_bad:
   log_write(0, LOG_MAIN|LOG_PANIC,
-               "DKIM: signing failed: %.100s", pdkim_errstr(pdkim_rc));
+               "DKIM: signing failed: %.100s", pdkim_errstr(pdkim_rc));
 bad:
   sigbuf = NULL;
   goto CLEANUP;
 
 expand_bad:
-  log_write(0, LOG_MAIN | LOG_PANIC, "failed to expand %s: %s",
-             errwhen, expand_string_message);
+  *errstr = string_sprintf("failed to expand %s: %s",
+              errwhen, expand_string_message);
+  log_write(0, LOG_MAIN | LOG_PANIC, "%s", *errstr);
   goto bad;
 }
 
@@ -799,11 +807,13 @@ expand_bad:
 gstring *
 authres_dkim(gstring * g)
 {
-pdkim_signature * sig;
+int start = 0;         /* compiler quietening */
 
-for (sig = dkim_signatures; sig; sig = sig->next)
+DEBUG(D_acl) start = g->ptr;
+
+for (pdkim_signature * sig = dkim_signatures; sig; sig = sig->next)
   {
-  g = string_catn(g, US";\\n\\tdkim=", 10);
+  g = string_catn(g, US";\n\tdkim=", 8);
 
   if (sig->verify_status & PDKIM_VERIFY_POLICY)
     g = string_append(g, 5,
@@ -815,21 +825,21 @@ for (sig = dkim_signatures; sig; sig = sig->next)
       switch (sig->verify_ext_status)
        {
        case PDKIM_VERIFY_INVALID_PUBKEY_UNAVAILABLE:
-          g = string_cat(g, US"tmperror (pubkey unavailable)"); break;
+          g = string_cat(g, US"tmperror (pubkey unavailable)\n\t\t"); break;
         case PDKIM_VERIFY_INVALID_BUFFER_SIZE:
-          g = string_cat(g, US"permerror (overlong public key record)"); break;
+          g = string_cat(g, US"permerror (overlong public key record)\n\t\t"); break;
         case PDKIM_VERIFY_INVALID_PUBKEY_DNSRECORD:
         case PDKIM_VERIFY_INVALID_PUBKEY_IMPORT:
-          g = string_cat(g, US"neutral (syntax error in public key record)");
+          g = string_cat(g, US"neutral (public key record import problem)\n\t\t");
           break;
         case PDKIM_VERIFY_INVALID_SIGNATURE_ERROR:
-          g = string_cat(g, US"neutral (signature tag missing or invalid)");
+          g = string_cat(g, US"neutral (signature tag missing or invalid)\n\t\t");
           break;
         case PDKIM_VERIFY_INVALID_DKIM_VERSION:
-          g = string_cat(g, US"neutral (unsupported DKIM version)");
+          g = string_cat(g, US"neutral (unsupported DKIM version)\n\t\t");
           break;
         default:
-          g = string_cat(g, US"permerror (unspecified problem)"); break;
+          g = string_cat(g, US"permerror (unspecified problem)\n\t\t"); break;
        }
       break;
     case PDKIM_VERIFY_FAIL:
@@ -837,14 +847,14 @@ for (sig = dkim_signatures; sig; sig = sig->next)
        {
        case PDKIM_VERIFY_FAIL_BODY:
           g = string_cat(g,
-           US"fail (body hash mismatch; body probably modified in transit)");
+           US"fail (body hash mismatch; body probably modified in transit)\n\t\t");
          break;
         case PDKIM_VERIFY_FAIL_MESSAGE:
           g = string_cat(g,
-           US"fail (signature did not verify; headers probably modified in transit)");
+           US"fail (signature did not verify; headers probably modified in transit)\n\t\t");
          break;
         default:
-          g = string_cat(g, US"fail (unspecified reason)");
+          g = string_cat(g, US"fail (unspecified reason)\n\t\t");
          break;
        }
       break;
@@ -856,6 +866,12 @@ for (sig = dkim_signatures; sig; sig = sig->next)
   if (sig->selector) g = string_append(g, 2, US" header.s=", sig->selector);
   g = string_append(g, 2, US" header.a=", dkim_sig_to_a_tag(sig));
   }
+
+DEBUG(D_acl)
+  if (g->ptr == start)
+    debug_printf("DKIM: no authres\n");
+  else
+    debug_printf("DKIM: authres '%.*s'\n", g->ptr - start - 3, g->s + start + 3);
 return g;
 }