<html><head>
<meta http-equiv="Content-Type" content="text/html; charset=utf-8">
</head>
<body>
<p>A fresh day, and a fresh idea - I just spun up a completely new
instance of named, listening on its own port, with a stripped down
config. Now the behavior is even stranger.</p>
<p>I can see the "no valid signature found" line in the server log,
but my 'dig' still gets an answer. What I can see in the logs
tells me that named has determined the answer is invalid, but then
it proceeds to deliver that answer to my client. I can't figure
out why.<br>
</p>
<p>I feel like I am too far down into the weeds, and there is
something basic I'm overlooking. Can anyone help re-orient me?</p>
<p><br>
</p>
<p>The .conf is pretty small, and looks like:</p>
<p> </p>
<blockquote type="cite"><font face="monospace">controls {<br>
inet 127.0.0.1 port 1953 allow {<br>
127.0.0.1/32;<br>
} keys {<br>
"ns88-testPrimary-key";<br>
};<br>
};<br>
options {<br>
directory "/var/opt/testPrimary/named/data";<br>
dump-file "cache_dump.db";<br>
listen-on port 1053 {<br>
127.0.0.1/32;<br>
};<br>
querylog yes;<br>
dnssec-validation auto;<br>
empty-zones-enable no;<br>
recursion yes;<br>
};<br>
key "ns88-testPrimary-key" {<br>
algorithm "hmac-sha256";<br>
secret "????????????????????????????????????????????";<br>
};</font></blockquote>
<p>When I launch it in the foreground, the output looks like:</p>
<p> </p>
<blockquote type="cite"><font face="monospace">17-Apr-2024
08:17:46.934 starting BIND 9.18.24 (Extended Support Version)
<id:6d7674f><br>
17-Apr-2024 08:17:46.934 running on Linux x86_64
5.14.0-362.18.1.el9_3.x86_64 #1 SMP PREEMPT_DYNAMIC Mon Jan 29
07:05:48 EST 2024<br>
17-Apr-2024 08:17:46.934 built with
'--build=x86_64-redhat-linux-gnu'
'--host=x86_64-redhat-linux-gnu' '--program-prefix='
'--disable-dependency-tracking'
'--prefix=/opt/isc/isc-bind/root/usr'
'--exec-prefix=/opt/isc/isc-bind/root/usr'
'--bindir=/opt/isc/isc-bind/root/usr/bin'
'--sbindir=/opt/isc/isc-bind/root/usr/sbin'
'--sysconfdir=/etc/opt/isc/scls/isc-bind'
'--datadir=/opt/isc/isc-bind/root/usr/share'
'--includedir=/opt/isc/isc-bind/root/usr/include'
'--libdir=/opt/isc/isc-bind/root/usr/lib64'
'--libexecdir=/opt/isc/isc-bind/root/usr/libexec'
'--localstatedir=/var/opt/isc/scls/isc-bind'
'--sharedstatedir=/var/opt/isc/scls/isc-bind/lib'
'--mandir=/opt/isc/isc-bind/root/usr/share/man'
'--infodir=/opt/isc/isc-bind/root/usr/share/info'
'--enable-warn-error' '--disable-static' '--enable-dnstap'
'--with-pic' '--with-gssapi' '--with-json-c' '--with-libxml2'
'--without-lmdb' 'build_alias=x86_64-redhat-linux-gnu'
'host_alias=x86_64-redhat-linux-gnu' 'CC=gcc' 'CFLAGS=-O2
-flto=auto -ffat-lto-objects -fexceptions -g
-grecord-gcc-switches -pipe -Wall -Werror=format-security
-Wp,-D_FORTIFY_SOURCE=2 -Wp,-D_GLIBCXX_ASSERTIONS
-specs=/usr/lib/rpm/redhat/redhat-hardened-cc1
-fstack-protector-strong
-specs=/usr/lib/rpm/redhat/redhat-annobin-cc1 -m64
-march=x86-64-v2 -mtune=generic -fasynchronous-unwind-tables
-fstack-clash-protection -fcf-protection
-fno-omit-frame-pointer' 'LDFLAGS=-Wl,-z,relro -Wl,--as-needed
-Wl,-z,now -specs=/usr/lib/rpm/redhat/redhat-hardened-ld
-specs=/usr/lib/rpm/redhat/redhat-annobin-cc1
-L/opt/isc/isc-bind/root/usr/lib64' 'CPPFLAGS=
-I/opt/isc/isc-bind/root/usr/include'
'LT_SYS_LIBRARY_PATH=/usr/lib64'
'PKG_CONFIG_PATH=:/opt/isc/isc-bind/root/usr/lib64/pkgconfig:/opt/isc/isc-bind/root/usr/share/pkgconfig'
'SPHINX_BUILD=/builddir/build/BUILD/bind-9.18.24/sphinx/bin/sphinx-build'<br>
17-Apr-2024 08:17:46.934 running as: named -g -4 -D testPrimary
-n 1 -u named -c /etc/opt/testPrimary/named.conf<br>
17-Apr-2024 08:17:46.934 compiled by GCC 11.4.1 20230605 (Red
Hat 11.4.1-2)<br>
17-Apr-2024 08:17:46.934 compiled with OpenSSL version: OpenSSL
3.0.7 1 Nov 2022<br>
17-Apr-2024 08:17:46.934 linked to OpenSSL version: OpenSSL
3.0.7 1 Nov 2022<br>
17-Apr-2024 08:17:46.934 compiled with libuv version: 1.44.2<br>
17-Apr-2024 08:17:46.934 linked to libuv version: 1.44.2<br>
17-Apr-2024 08:17:46.934 compiled with libxml2 version: 2.9.13<br>
17-Apr-2024 08:17:46.934 linked to libxml2 version: 20913<br>
17-Apr-2024 08:17:46.934 compiled with json-c version: 0.14<br>
17-Apr-2024 08:17:46.934 linked to json-c version: 0.14<br>
17-Apr-2024 08:17:46.934 compiled with zlib version: 1.2.11<br>
17-Apr-2024 08:17:46.935 linked to zlib version: 1.2.11<br>
17-Apr-2024 08:17:46.935
----------------------------------------------------<br>
17-Apr-2024 08:17:46.935 BIND 9 is maintained by Internet
Systems Consortium,<br>
17-Apr-2024 08:17:46.935 Inc. (ISC), a non-profit 501(c)(3)
public-benefit<br>
17-Apr-2024 08:17:46.935 corporation. Support and training for
BIND 9 are<br>
17-Apr-2024 08:17:46.935 available at <a class="moz-txt-link-freetext" href="https://www.isc.org/support">https://www.isc.org/support</a><br>
17-Apr-2024 08:17:46.935
----------------------------------------------------<br>
17-Apr-2024 08:17:46.935 adjusted limit on open files from
524288 to 1048576<br>
17-Apr-2024 08:17:46.935 found 1 CPU, using 1 worker thread<br>
17-Apr-2024 08:17:46.935 using 1 UDP listener per interface<br>
17-Apr-2024 08:17:46.936 DNSSEC algorithms: RSASHA256 RSASHA512
ECDSAP256SHA256 ECDSAP384SHA384 ED25519 ED448<br>
17-Apr-2024 08:17:46.936 DS algorithms: SHA-1 SHA-256 SHA-384<br>
17-Apr-2024 08:17:46.936 HMAC algorithms: HMAC-MD5 HMAC-SHA1
HMAC-SHA224 HMAC-SHA256 HMAC-SHA384 HMAC-SHA512<br>
17-Apr-2024 08:17:46.936 TKEY mode 2 support (Diffie-Hellman):
yes<br>
17-Apr-2024 08:17:46.936 TKEY mode 3 support (GSS-API): yes<br>
17-Apr-2024 08:17:46.938 loading configuration from
'/etc/opt/testPrimary/named.conf'<br>
17-Apr-2024 08:17:46.938 unable to open
'/etc/opt/isc/scls/isc-bind/bind.keys'; using built-in keys
instead<br>
17-Apr-2024 08:17:46.940 using default UDP/IPv4 port range:
[32768, 60999]<br>
17-Apr-2024 08:17:46.941 listening on IPv4 interface lo,
127.0.0.1#1053<br>
17-Apr-2024 08:17:46.941 generating session key for dynamic DNS<br>
17-Apr-2024 08:17:46.941 sizing zone task pool based on 0 zones<br>
17-Apr-2024 08:17:46.941 none:98: 'max-cache-size 90%' - setting
to 1558MB (out of 1732MB)<br>
17-Apr-2024 08:17:46.942 using built-in root key for view
_default<br>
17-Apr-2024 08:17:46.942 set up managed keys zone for view
_default, file 'managed-keys.bind'<br>
17-Apr-2024 08:17:46.943 command channel listening on
127.0.0.1#1953<br>
17-Apr-2024 08:17:46.943 not using config file logging statement
for logging due to -g option<br>
17-Apr-2024 08:17:46.945 managed-keys-zone: loaded serial 2<br>
17-Apr-2024 08:17:46.945 all zones loaded<br>
17-Apr-2024 08:17:46.945 running<br>
17-Apr-2024 08:17:46.979 managed-keys-zone: Key 20326 for zone .
is now trusted (acceptance timer complete)<br>
17-Apr-2024 08:17:46.981 resolver priming query complete:
success<br>
</font></blockquote>
<br>
<p>And when I query it (gratuitous flush) with</p>
<p> </p>
<blockquote type="cite"><font face="monospace">rndc -k rndc.key -s
localhost -p 1953 flush && dig -4 -p 1053 @localhost <a class="moz-txt-link-abbreviated" href="http://www.dnssec-failed.org">www.dnssec-failed.org</a>.</font></blockquote>
<p>This is what is logged<br>
</p>
<p> </p>
<blockquote type="cite"><font face="monospace">17-Apr-2024
08:20:13.008 received control channel command 'flush'<br>
17-Apr-2024 08:20:13.010 flushing caches in all views succeeded<br>
17-Apr-2024 08:20:13.030 client @0x7feda09ce768 127.0.0.1#36320
(<a class="moz-txt-link-abbreviated" href="http://www.dnssec-failed.org">www.dnssec-failed.org</a>):
query: <a class="moz-txt-link-abbreviated" href="http://www.dnssec-failed.org">www.dnssec-failed.org</a>
IN A +E(0)K (127.0.0.1)<br>
17-Apr-2024 08:20:13.132 resolver priming query complete:
success<br>
17-Apr-2024 08:20:13.485 validating <a class="moz-txt-link-abbreviated" href="http://www.dnssec-failed.org/A">www.dnssec-failed.org/A</a>:
no valid signature found</font><br>
</blockquote>
<p>And this is the output of dig</p>
<p> </p>
<blockquote type="cite"><font face="monospace">; <<>>
DiG 9.18.24 <<>> -4 -p 1053 @localhost <a class="moz-txt-link-abbreviated" href="http://www.dnssec-failed.org">www.dnssec-failed.org</a>.<br>
; (2 servers found)<br>
;; global options: +cmd<br>
;; Got answer:<br>
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id:
9625<br>
;; flags: qr rd ra; QUERY: 1, ANSWER: 2, AUTHORITY: 0,
ADDITIONAL: 1<br>
<br>
;; OPT PSEUDOSECTION:<br>
; EDNS: version: 0, flags:; udp: 1232<br>
; COOKIE: 9e74c986c617414a01000000661ff6bd07eca9a95d995f7f
(good)<br>
;; QUESTION SECTION:<br>
;www.dnssec-failed.org. IN A<br>
<br>
;; ANSWER SECTION:<br>
<a class="moz-txt-link-abbreviated" href="http://www.dnssec-failed.org">www.dnssec-failed.org</a>.
7200 IN A 68.87.109.242<br>
<a class="moz-txt-link-abbreviated" href="http://www.dnssec-failed.org">www.dnssec-failed.org</a>.
7200 IN A 69.252.193.191<br>
<br>
;; Query time: 515 msec<br>
;; SERVER: 127.0.0.1#1053(localhost) (UDP)<br>
;; WHEN: Wed Apr 17 08:20:13 AKDT 2024<br>
;; MSG SIZE rcvd: 110</font><br>
</blockquote>
<br>
<p>When I crank the dnssec logging severity to debug-7, I see the
following:<br>
</p>
<p> </p>
<blockquote type="cite"><font face="monospace">17-Apr-2024
08:39:25.601 managed-keys-zone: Creating key fetch in
zone_refreshkeys() for '.'<br>
17-Apr-2024 08:39:25.696 managed-keys-zone: Returned from key
fetch in keyfetch_done() for '.': success<br>
17-Apr-2024 08:39:25.696 managed-keys-zone: Verifying DNSKEY set
for zone '.' using DS 20326/8: success<br>
17-Apr-2024 08:39:25.696 managed-keys-zone: Key 20326 for zone .
is now trusted (acceptance timer complete)<br>
17-Apr-2024 08:39:25.697 validating ./NS: starting<br>
17-Apr-2024 08:39:25.698 validating ./NS: attempting positive
response validation<br>
17-Apr-2024 08:39:25.698 validating ./DNSKEY: starting<br>
17-Apr-2024 08:39:25.698 validating ./DNSKEY: attempting
positive response validation<br>
17-Apr-2024 08:39:25.698 validating ./DNSKEY: verify rdataset
(keyid=20326): success<br>
17-Apr-2024 08:39:25.698 validating ./DNSKEY: marking as
secure (DS)<br>
17-Apr-2024 08:39:25.698 validator @0x7fb8722b7000:
dns_validator_destroy<br>
17-Apr-2024 08:39:25.698 validating ./NS: in
validator_callback_dnskey<br>
17-Apr-2024 08:39:25.698 validating ./NS: keyset with trust
secure<br>
17-Apr-2024 08:39:25.698 validating ./NS: resuming validate<br>
17-Apr-2024 08:39:25.698 validating ./NS: verify rdataset
(keyid=5613): success<br>
17-Apr-2024 08:39:25.698 validating ./NS: marking as secure,
noqname proof not needed<br>
17-Apr-2024 08:39:25.698 validator @0x7fb872276c00:
dns_validator_destroy<br>
17-Apr-2024 08:40:39.814 validating ./NS: starting<br>
17-Apr-2024 08:40:39.815 validating ./NS: attempting positive
response validation<br>
17-Apr-2024 08:40:39.882 validating ./DNSKEY: starting<br>
17-Apr-2024 08:40:39.882 validating ./DNSKEY: attempting
positive response validation<br>
17-Apr-2024 08:40:39.883 validating ./DNSKEY: verify rdataset
(keyid=20326): success<br>
17-Apr-2024 08:40:39.883 validating ./DNSKEY: marking as secure
(DS)<br>
17-Apr-2024 08:40:39.883 validator @0x7fb8722ba200:
dns_validator_destroy<br>
17-Apr-2024 08:40:39.883 validating ./NS: in
fetch_callback_dnskey<br>
17-Apr-2024 08:40:39.883 validating ./NS: keyset with trust
secure<br>
17-Apr-2024 08:40:39.883 validating ./NS: resuming validate<br>
17-Apr-2024 08:40:39.883 validating ./NS: verify rdataset
(keyid=5613): success<br>
17-Apr-2024 08:40:39.883 validating ./NS: marking as secure,
noqname proof not needed<br>
17-Apr-2024 08:40:39.883 validator @0x7fb8722b7000:
dns_validator_destroy<br>
17-Apr-2024 08:40:40.288 validating <a class="moz-txt-link-abbreviated" href="http://www.dnssec-failed.org/A">www.dnssec-failed.org/A</a>:
starting<br>
17-Apr-2024 08:40:40.288 validating <a class="moz-txt-link-abbreviated" href="http://www.dnssec-failed.org/A">www.dnssec-failed.org/A</a>:
attempting positive response validation<br>
17-Apr-2024 08:40:40.288 validating <a class="moz-txt-link-abbreviated" href="http://www.dnssec-failed.org/A">www.dnssec-failed.org/A</a>:
no valid signature found<br>
17-Apr-2024 08:40:40.288 validating <a class="moz-txt-link-abbreviated" href="http://www.dnssec-failed.org/A">www.dnssec-failed.org/A</a>:
falling back to insecurity proof<br>
17-Apr-2024 08:40:40.288 validating <a class="moz-txt-link-abbreviated" href="http://www.dnssec-failed.org/A">www.dnssec-failed.org/A</a>:
checking existence of DS at 'org'<br>
17-Apr-2024 08:40:40.288 validating org/DS: starting<br>
17-Apr-2024 08:40:40.288 validating org/DS: attempting
positive response validation<br>
17-Apr-2024 08:40:40.288 validating org/DS: keyset with trust
secure<br>
17-Apr-2024 08:40:40.288 validating org/DS: verify rdataset
(keyid=5613): success<br>
17-Apr-2024 08:40:40.289 validating org/DS: marking as secure,
noqname proof not needed<br>
17-Apr-2024 08:40:40.289 validator @0x7fb8722b7a00:
dns_validator_destroy<br>
17-Apr-2024 08:40:40.289 validating <a class="moz-txt-link-abbreviated" href="http://www.dnssec-failed.org/A">www.dnssec-failed.org/A</a>:
in validator_callback_ds<br>
17-Apr-2024 08:40:40.289 validating <a class="moz-txt-link-abbreviated" href="http://www.dnssec-failed.org/A">www.dnssec-failed.org/A</a>:
dsset with trust secure<br>
17-Apr-2024 08:40:40.289 validating <a class="moz-txt-link-abbreviated" href="http://www.dnssec-failed.org/A">www.dnssec-failed.org/A</a>:
resuming proveunsecure<br>
17-Apr-2024 08:40:40.289 validating <a class="moz-txt-link-abbreviated" href="http://www.dnssec-failed.org/A">www.dnssec-failed.org/A</a>:
checking existence of DS at 'dnssec-failed.org'<br>
17-Apr-2024 08:40:40.289 validating dnssec-failed.org/DS:
starting<br>
17-Apr-2024 08:40:40.289 validating dnssec-failed.org/DS:
attempting positive response validation<br>
17-Apr-2024 08:40:40.322 validating org/DNSKEY: starting<br>
17-Apr-2024 08:40:40.322 validating org/DNSKEY: attempting
positive response validation<br>
17-Apr-2024 08:40:40.322 validating org/DNSKEY: verify rdataset
(keyid=26974): success<br>
17-Apr-2024 08:40:40.322 validating org/DNSKEY: marking as
secure (DS)<br>
17-Apr-2024 08:40:40.322 validator @0x7fb8722b7000:
dns_validator_destroy<br>
17-Apr-2024 08:40:40.323 validating dnssec-failed.org/DS: in
fetch_callback_dnskey<br>
17-Apr-2024 08:40:40.323 validating dnssec-failed.org/DS:
keyset with trust secure<br>
17-Apr-2024 08:40:40.323 validating dnssec-failed.org/DS:
resuming validate<br>
17-Apr-2024 08:40:40.323 validating dnssec-failed.org/DS:
verify rdataset (keyid=3093): success<br>
17-Apr-2024 08:40:40.323 validating dnssec-failed.org/DS:
marking as secure, noqname proof not needed<br>
17-Apr-2024 08:40:40.323 validator @0x7fb8722b7a00:
dns_validator_destroy<br>
17-Apr-2024 08:40:40.323 validating <a class="moz-txt-link-abbreviated" href="http://www.dnssec-failed.org/A">www.dnssec-failed.org/A</a>:
in validator_callback_ds<br>
17-Apr-2024 08:40:40.323 validating <a class="moz-txt-link-abbreviated" href="http://www.dnssec-failed.org/A">www.dnssec-failed.org/A</a>:
dsset with trust secure<br>
17-Apr-2024 08:40:40.323 validating <a class="moz-txt-link-abbreviated" href="http://www.dnssec-failed.org/A">www.dnssec-failed.org/A</a>:
resuming proveunsecure<br>
17-Apr-2024 08:40:40.323 validating <a class="moz-txt-link-abbreviated" href="http://www.dnssec-failed.org/A">www.dnssec-failed.org/A</a>:
no supported algorithm/digest (dnssec-failed.org/DS)<br>
17-Apr-2024 08:40:40.323 validating <a class="moz-txt-link-abbreviated" href="http://www.dnssec-failed.org/A">www.dnssec-failed.org/A</a>:
marking as answer (proveunsecure (2))<br>
17-Apr-2024 08:40:40.323 validator @0x7fb8722b8e00:
dns_validator_destroy</font><br>
</blockquote>
<br>
<p><br>
<br>
</p>
<pre class="moz-signature" cols="72">--
Do things because you should, not just because you can.
John Thurston 907-465-8591
<a class="moz-txt-link-abbreviated moz-txt-link-freetext" href="mailto:John.Thurston@alaska.gov">John.Thurston@alaska.gov</a>
Department of Administration
State of Alaska</pre>
<div class="moz-cite-prefix">On 4/17/2024 12:26 AM, Nick Tait via
bind-users wrote:<br>
</div>
<blockquote type="cite" cite="mid:a401fd80-6987-45e5-9381-1817b0c5ffbe@tait.net.nz">If you
have just a single process listening on port 53, then I'd suggest
using "tail -f" to watch your BIND logs</blockquote>
</body>
</html>