#35 Authentication-Results + DNS

[Ruga]

When receiving from a DKIM-enabled server, say google, we expect to see the Authentication-Results header with a dkim=pass flag. Instead, we get no header at all, and the log has info for us:

Sep 15 20:03:25 example opendkim[324]: 42CCCDB291BA: mail-wm0-f53.google.com [74.125.82.53] not internal
Sep 15 20:03:25 example opendkim[324]: 42CCCDB291BA: not authenticated
Sep 15 20:03:25 example opendkim[324]: 42CCCDB291BA: signature=fSALpjTU domain=gmail.com selector=20120113 result="key DNS query failed"
Sep 15 20:03:25 example opendkim[324]: 42CCCDB291BA: key retrieval failed (s=20120113, d=gmail.com): '20120113._domainkey.gmail.com' query failed

However, the DNSs are just fine:

unbound-host -rvD -tTXT 20120113._domainkey.gmail.com
20120113._domainkey.gmail.com has TXT record "k=rsa; p=MIIBIjANBgkqhkiG9w0BAQEFAAOCAQ8AMIIBCgKCAQEA1Kd87/UeJjenpabgbFwh+eBCsSTrqmwIYYvywlbhbqoo2DymndFkbjOVIPIldNs/m40KF+yzMn1skyoxcTUGCQs8g3FgD2Ap3ZB5DekAo5wMmk4wimDO+U8QzI3SD0" "7y2+07wlNWwIt8svnxgdxGkVbbhzY8i+RQ9DpSVpPbF7ykQxtKXkv/ahW3KjViiAH+ghvvIhkx4xYSIc9oSwVmAl5OctMEeWUwg8Istjqz8BZeTWbf41fbNhte7Y+YqZOwq1Sd0DbvYAD9NOZK9vlfuac0598HY+vtSBczUiKERHv1yRbcaQtZFh5wtiRrN04BLUTD21MycBX5jYchHjPY/wIDAQAB" (insecure)

Please send instructions on how to identify the problem.

[Ruga]

runtime configuration

[Ruga]

object dump

llvm-objdump -macho -dylib-id -dylibs-used $filename

[Ruga]

config options:

   --with-openssl=/usr/local
   --with-unbound=/usr/local --with-ldns=/usr/local 
   --with-libcurl=/usr/local
   --with-milter=/usr/local
   --enable-rpath 

> make check
[...]
============================================================================
Testsuite summary for OpenDKIM 2.10.3
============================================================================
# TOTAL: 159
# PASS:  159
# SKIP:  0
# XFAIL: 0
# FAIL:  0
# XPASS: 0
# ERROR: 0
============================================================================

[Ruga]

Results obtained for third-party incoming mail using "UnprotectedKey none"

e-mail without dkim signature:
header: "Authentication-Results: example.com; dkim=none" <------ OK
log: "not internal" and "not authenticated"

e-mail with dkim signature:
header: "Authentication-Results: example.com; dkim=[...]" is not included <------------ :-(
log: identical to the OP, with ""key DNS query failed" <----------------------------------------

Results obtained for third-party incoming mail using "UnprotectedKey neutral"

identical to the above

Results obtained for third-party incoming mail using "UnprotectedKey fail"

identical to the above

[Ruga]

>opendkim -b v -v -v -t ~/ham4.eml

[...]
opendkim: /Users/x/ham4.eml: line 56: mlfi_header() returned SMFIS_CONTINUE
opendkim: /Users/x/ham4.eml: line 57: mlfi_header() returned SMFIS_CONTINUE
opendkim: /Users/x/ham4.eml: mlfi_eoh() returned SMFIS_CONTINUE
opendkim: /Users/x/ham4.eml: mlfi_body() returned SMFIS_CONTINUE
### SETREPLY: rcode='451' xcode='4.7.5' replytxt='DKIM key retrieval failed'
opendkim: /Users/x/ham4.eml: mlfi_eom() returned SMFIS_ACCEPT
opendkim: /Users/x/ham4.eml: verification (s=20120113 d=gmail.com, 0-bit key, unknown) failed: key DNS query failed
opendkim: mlfi_close() returned SMFIS_CONTINUE

The above verification test (-b v) also prints a "DEBUG-i: no signin table match for 'example@gmail.com'", which fact is not supposed to happen.

[Ruga]

ldns test

>drill 20120113._domainkey.gmail.com TXT

; ->>HEADER<<- opcode: QUERY, rcode: NOERROR, id: 28482
;; flags: qr rd ra ; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 0 
;; QUESTION SECTION:
;; 20120113._domainkey.gmail.com.   IN  TXT

;; ANSWER SECTION:
20120113._domainkey.gmail.com.  300 IN  TXT "k=rsa; p=MIIBIjANBgkqhkiG9w0BAQEFAAOCAQ8AMIIBCgKCAQEA1Kd87/UeJjenpabgbFwh+eBCsSTrqmwIYYvywlbhbqoo2DymndFkbjOVIPIldNs/m40KF+yzMn1skyoxcTUGCQs8g3FgD2Ap3ZB5DekAo5wMmk4wimDO+U8QzI3SD0" "7y2+07wlNWwIt8svnxgdxGkVbbhzY8i+RQ9DpSVpPbF7ykQxtKXkv/ahW3KjViiAH+ghvvIhkx4xYSIc9oSwVmAl5OctMEeWUwg8Istjqz8BZeTWbf41fbNhte7Y+YqZOwq1Sd0DbvYAD9NOZK9vlfuac0598HY+vtSBczUiKERHv1yRbcaQtZFh5wtiRrN04BLUTD21MycBX5jYchHjPY/wIDAQAB"

;; AUTHORITY SECTION:

;; ADDITIONAL SECTION:

;; Query time: 72 msec
;; SERVER: 127.0.0.1
;; WHEN: Sat Sep 17 10:01:14 2016
;; MSG SIZE  rcvd: 462

[Ruga]

opendkim/test.c line 742:

fprintf(stdout,
   "%s: %s: verification (s=%s d=%s, %d-bit key, %s) failed: %s\n",
   progname, file, selector, domain, keysize, dnssec, err);
fprintf(stdout, 
     "%s: %s: flags: %u; DKIM_SIGFLAG_PASSED:%d; bh:%u; DKIM_SIGBH_MISMATCH:%d; errcode:%d; DKIM_SIGERROR_OK:%d; dnsseccode:%d \n", progname, file, flags, DKIM_SIGFLAG_PASSED, bh, DKIM_SIGBH_MISMATCH, errcode, DKIM_SIGERROR_OK, dnsseccode );

result:

>opendkim -b v -v -v -t ~/ham4.eml
[...]
opendkim: /Users/x/ham4.eml: mlfi_eoh() returned SMFIS_CONTINUE
opendkim: /Users/x/ham4.eml: mlfi_body() returned SMFIS_CONTINUE
### SETREPLY: rcode='451' xcode='4.7.5' replytxt='DKIM key retrieval failed'
opendkim: /Users/x/ham4.eml: mlfi_eom() returned SMFIS_ACCEPT
opendkim: /Users/x/ham4.eml: verification (s=20120113 d=gmail.com, 0-bit key, unknown) failed: key DNS query failed
opendkim: /Users/x/ham4.eml: flags: 2; DKIM_SIGFLAG_PASSED:4; bh:4294967295; DKIM_SIGBH_MISMATCH:1; errcode:24; DKIM_SIGERROR_OK:0; dnsseccode:-1
opendkim: mlfi_close() returned SMFIS_CONTINUE

The verification test fails with "key DNS query failed", because "DKIM_SIGBH_MISMATCH:1".
The same test also logs "DEBUG-i: no signin table match for 'example@gmail.com'".

So, is it a DNS query error, a BH mismatch, or the ill attempt to sign during a verification test?

[Ruga]

opendkim/opendkim-dns.c

#ifdef USE_UNBOUND
/*
**  DKIMF_UNBOUND_CB -- callback to handle result of DNS query
[...]
static void
dkimf_unbound_cb(void *mydata, int err, struct ub_result *result)
{
    struct dkimf_unbound_cb_data *ubdata;
+  fprintf(stderr, "debug: dkimf_unbound_cb call=%s\n", true);

The resulting execution shows that the above function is not executed.
The DNS query error is an error local to opendkim.

[Ruga]

**  DKIMF_UB_QUERY -- function passed to libopendkim to handle new requests
[...]
static int
dkimf_ub_query(void *srv, int type, unsigned char *query,
               unsigned char *buf, size_t buflen, void **qh)
{
[...]
   ubdata = (struct dkimf_unbound_cb_data *) malloc(sizeof *ubdata);
+ fprintf(stderr, "debug: ub=%s ubdata=%s\n", ub, ubdata);
  if (ubdata == NULL)
        return DKIM_DNS_ERROR;

[...]
debug: ub= ubdata=
[...]
opendkim: /Users/x/ham4.eml: verification (s=20120113 d=gmail.com, 0-bit key, unknown) failed: key DNS query failed
opendkim: /Users/x/ham4.eml: flags: 2; DKIM_SIGFLAG_PASSED:4; bh:4294967295; DKIM_SIGBH_MISMATCH:1; errcode:24; DKIM_SIGERROR_OK:0; dnsseccode:-1
opendkim: mlfi_close() returned SMFIS_CONTINUE

[Sami Farin]

With "MilterDebug 99" I get nothing useful as to why it does not even send the query for 20161025.domainkey.gmail.com.
Yes my nameserver at 127.0.0.1 works when I query it.

3719  10:28:20.253860 read(7, "\0\0\0\1E", 5) = 5 <0.000008>
3719  10:28:20.254101 sendto(4, "<19>Apr 22 10:28:20 opendkim[3714]: 21E445FAB6: key retrieval failed (s=20161025, d=gmail.com): '20161025._domainkey.gmail.com' query failed", 140, MSG_NOSIGNAL, NULL, 0) = 140 <0.000014>

[Ruga]

Created: 2016-09-15
Today: 2018-01-29

Problem pending, and no comment from the developers.