ISC Open Source Projects issueshttps://gitlab.isc.org/groups/isc-projects/-/issues2024-03-27T12:56:42Zhttps://gitlab.isc.org/isc-projects/kea/-/issues/2979RAI based flex-id reservations2024-03-27T12:56:42ZPeter DaviesRAI based flex-id reservationsRAI based flex-id reservations:
When providing dhcp services for customer equipment, maintaining a consistent IP
address is often desired even when customers replace their equipment.
Host reservations may be defined using a ...RAI based flex-id reservations:
When providing dhcp services for customer equipment, maintaining a consistent IP
address is often desired even when customers replace their equipment.
Host reservations may be defined using a flex-id host identifier based on some
RAI options; however, the lease data will typically contain the hw-address as
the identifier.
This works well until the customer replaces his equipment and there is an active
lease on the reserved address with the old client's hw-address. In this case,
Kea will regard this as an address conflict.
Enabling the "replace-client-id" flex-id flag can mitigate this; however, changing
the value of this flag on a running Kea server will cause address conflicts.
Is there a way to address this problem?
[RT #20140](https://support.isc.org/Ticket/Display.html?id=20140)kea2.5.8https://gitlab.isc.org/isc-projects/kea/-/issues/2976Implement the ISC DHCP stash-agent-options in Kea2024-03-28T14:24:33ZFrancis DupontImplement the ISC DHCP stash-agent-options in KeaSee #218 for details but the idea is to handle v4 renew/rebind queries as they went thought a relay. As far as I can remember the idea is to use the hint (requested or client address) from the query to look up the lease and extract the R...See #218 for details but the idea is to handle v4 renew/rebind queries as they went thought a relay. As far as I can remember the idea is to use the hint (requested or client address) from the query to look up the lease and extract the RAI from its user context. Requires some design but on the paper this should do the job...
Note this is for v4 only because v6 requires a specific setup on both the client and the server for direct unicast queries so the problem never occurs in the real world.kea2.5.8https://gitlab.isc.org/isc-projects/kea/-/issues/2957dhcpdb_create.pgsql erroneously creates dhcp4_server_modification_ts index on...2024-03-22T13:05:49ZJohn W. O'Briendhcpdb_create.pgsql erroneously creates dhcp4_server_modification_ts index on dhcp6_server table---
name: Bug report
about: Create a report to help us improve
---
**Describe the bug**
dhcpdb_create.pgsql erroneously creates the dhcp4_server_modification_ts index on the dhcp6_server table
**To Reproduce**
Steps to reproduce the b...---
name: Bug report
about: Create a report to help us improve
---
**Describe the bug**
dhcpdb_create.pgsql erroneously creates the dhcp4_server_modification_ts index on the dhcp6_server table
**To Reproduce**
Steps to reproduce the behavior:
1. Initialize a PostgreSQL database using dhcpdb_create.pgsql
2. Inspect the dhcp4_server_modification_ts index
3. See that it is associated with the dhcp6_server table
**Expected behavior**
A clear and concise description of what you expected to happen:
The dhcp4_server_modification_ts index should be associated with the dhcp4_server table.
**Environment:**
- Kea version: 2.2.0
- OS: FreeBSD 13.2-RELEASE amd64
- Compiled with pgsql backend
- Loaded hooks: pgsql_cb
**Additional Information**
```
kea=> \di dhcp4_server_modification_ts
List of relations
Schema | Name | Type | Owner | Table
--------+------------------------------+-------+-------+--------------
public | dhcp4_server_modification_ts | index | kea | dhcp6_server
(1 row)
```
This appears to have been introduced as a [copy/paste error in version 7.0 of the schema](https://gitlab.isc.org/isc-projects/kea/-/blob/Kea-2.3.8/src/share/database/scripts/pgsql/dhcpdb_create.pgsql#L1398). I could identify no correspond bug in the MySQL schema.
**Contacting you**
* SMS/Signal: (available upon request)
* GitHub/GitLab: neirbowj
* Mastodon: [@neirbowj@mastodon.online](https://mastodon.online/@neirbowj)kea2.5.8https://gitlab.isc.org/isc-projects/kea/-/issues/2820Optionally log transaction ID with log messages2024-03-27T12:55:48ZDarren AnkneyOptionally log transaction ID with log messagesIt could be useful to have a `%` parameter available for the pattern in the loggers section to add the transaction id to each message logged. It's already logged on some messages but not all.
Example:
```
2023-03-30 20:26:27.518 DEBUG ...It could be useful to have a `%` parameter available for the pattern in the loggers section to add the transaction id to each message logged. It's already logged on some messages but not all.
Example:
```
2023-03-30 20:26:27.518 DEBUG [kea-dhcp4.hosts/283769.281473780088704] HOSTS_CFG_GET_ONE_SUBNET_ID_ADDRESS4 get one host with reservation for subnet id 1 and IPv4 address 192.168.115.202
```
vs.
```
2023-03-30 20:26:27.518 DEBUG [kea-dhcp4.alloc-engine/283769.281473780088704] ALLOC_ENGINE_V4_REQUEST_ALLOC_REQUESTED [hwtype=1 00:0c:01:02:03:06], cid=[01:00:0c:01:02:03:06], tid=0x3: trying to allocate requested address 192.168.115.202
```
Having a way to log it consistently before the start of the message would be helpful when trying to find all of the messages that occurred with a particular exchange. It could even be useful to match these up to packets in a pcap.
[RT21953](https://support.isc.org/Ticket/Display.html?id=21953)kea2.5.8https://gitlab.isc.org/isc-projects/bind9/-/issues/4586Don't count expired / future RRSIGs in verification failure quota2024-02-24T08:17:15ZMark AndrewsDon't count expired / future RRSIGs in verification failure quotaExpired / future RRSIGs don't trigger a public key verification.Expired / future RRSIGs don't trigger a public key verification.May 2024 (9.18.27, 9.18.27-S1, 9.19.24)https://gitlab.isc.org/isc-projects/bind9/-/issues/4554Signature expiration calculation backwards compatibility bug2024-02-24T07:53:48ZMatthijs Mekkingmatthijs@isc.orgSignature expiration calculation backwards compatibility bugThe `signatures-refresh` option determines when RRSIG records need to be refreshed. Signatures that expire within this time are refreshed.
However, the code is also using this to determine the jitter. It uses a jitter range of 0 to `sig...The `signatures-refresh` option determines when RRSIG records need to be refreshed. Signatures that expire within this time are refreshed.
However, the code is also using this to determine the jitter. It uses a jitter range of 0 to `signatures-validity - signatures-refresh`) which is wrong: it should be using a range of 0 to `signatures-refresh`.
The `sig-validity-interval` that was used for `auto-dnssec` defined two parameters, the first being the signatures validity (same as `dnssec-policy`'s `signatures-validity`), the optional second one being the minimum bound of the signatures validity. It also serves as a signatures refresh. Basically the refresh value is the difference between the first and second parameter.
So the second parameter actually has two meanings: It serves as a jitter and a refresh value.
With `dnssec-policy` there is not yet a way to define `jitter`. The `signatures-refresh` is actually defined as the.
Two things need to be done:
- [x] Add a configuration option to `dnssec-policy` to set desired jitter.
- [x] Ensure resign interval is used correctly.May 2024 (9.18.27, 9.18.27-S1, 9.19.24)Matthijs Mekkingmatthijs@isc.orgMatthijs Mekkingmatthijs@isc.orghttps://gitlab.isc.org/isc-projects/bind9/-/issues/4517dnssec-verify reports errors in NSEC3 chain2024-02-24T07:53:57ZLibor Peltandnssec-verify reports errors in NSEC3 chain### Summary
Please see the attached zone file. The output of dnssec-verify is:
```
$ faketime '2023-12-10' dnssec-verify -o 6DA7ffbF. 6DA7ffbF.rndzone
Loading zone '6DA7ffbF.' from file '6DA7ffbF.rndzone'
Verifying the zone using the f...### Summary
Please see the attached zone file. The output of dnssec-verify is:
```
$ faketime '2023-12-10' dnssec-verify -o 6DA7ffbF. 6DA7ffbF.rndzone
Loading zone '6DA7ffbF.' from file '6DA7ffbF.rndzone'
Verifying the zone using the following algorithms:
- ECDSAP256SHA256
Bad NSEC3 record for fadb1aa3f.6DA7ffbF, bit map mismatch
Expected and found NSEC3 chains not equal
Break in NSEC3 chain at: VKGD3TE5QRGB6S0KJH6UV3FKS9FUMRIV
Expected: 01EAMK8ES71TN6TKHOK512LQMCORC5O9
Found: 0R6S95GSLHH7HT7MFN2N1NJGNFS7Q2CQ
DNSSEC completeness test failed (failure).
```
I'd say that the NSEC3 chain is however correct.
Some notes:
- opt-out is not used
- `fadb1aa3f.6da7ffbf.` -> `01eamk8es71tn6tkhok512lqmcorc5o9.6da7ffbf.` (first NSEC3 lexicographically, but this probably doesnt care)
- `427e09.owa.6da7ffbf.` -> `vkgd3te5qrgb6s0kjh6uv3fks9fumriv.6da7ffbf.` (last NSEC3 lexicographically)
- node `fadb1aa3f.6da7ffbf.` is "weird" in the way that it's a delegation with non-authoritative data: MX and even DNSKEY(!), but this shouldn't influence the chaining of NSEC3, moreover, it relates to the bitmap at 01EAMK... and not VKGD3T...
### BIND version affected
```
$ dnssec-verify -V
dnssec-verify 9.18.18-0ubuntu0.22.04.1-Ubuntu
```
### Steps to reproduce
Use faketime as the RRSIGs are expired already. It doesn't matter since the errors are related to NSEC3s and not signatures.
The zone file in question is attached.
Just call `$ faketime '2023-12-10' dnssec-verify -o 6DA7ffbF. 6DA7ffbF.rndzone`
### What is the current *bug* behavior?
Verify reports errors in the attached zone's NSEC3 chain.
### What is the expected *correct* behavior?
No errors reported.May 2024 (9.18.27, 9.18.27-S1, 9.19.24)Mark AndrewsMark Andrewshttps://gitlab.isc.org/isc-projects/bind9/-/issues/4475Data races in isc_buffer_peekuint8, rdataset_settrust, and memmove2024-02-24T07:54:00ZMichal NowakData races in isc_buffer_peekuint8, rdataset_settrust, and memmoveJob [#3848477](https://gitlab.isc.org/isc-projects/bind9/-/jobs/3848477) failed for c4fcdbefc5ac65e62f8d16ba78737aa6174c9592.
There are three new types of TSAN errors in the failed `respdiff-long:tsan` CI job.
I did not happen [yesterd...Job [#3848477](https://gitlab.isc.org/isc-projects/bind9/-/jobs/3848477) failed for c4fcdbefc5ac65e62f8d16ba78737aa6174c9592.
There are three new types of TSAN errors in the failed `respdiff-long:tsan` CI job.
I did not happen [yesterday](https://gitlab.isc.org/isc-projects/bind9/-/jobs/3843810) on 64ef6968f379fa220c2a2d76311705b4e248e286, so should this be caused by a new code, the only theoretically relevant MR is !8515.
```
WARNING: ThreadSanitizer: data race
Read of size 1 at 0x000000000001 by main thread:
#0 isc_buffer_peekuint8 ../../lib/isc/include/isc/buffer.h:847
#1 isc_buffer_getuint8 ../../lib/isc/include/isc/buffer.h:854
#2 dns_ncache_getsigrdataset lib/dns/ncache.c:630
#3 validate_ncache lib/dns/validator.c:2388
#4 validate_nx lib/dns/validator.c:2431
#5 validator_start lib/dns/validator.c:2994
#6 isc__async_cb lib/isc/async.c:111
#7 uv__async_io /usr/src/libuv-v1.47.0/src/unix/async.c:176
#8 thread_body lib/isc/thread.c:85
#9 isc_thread_main lib/isc/thread.c:116
#10 isc_loopmgr_run lib/isc/loop.c:454
#11 main bin/named/main.c:1574
Previous write of size 1 at 0x000000000001 by thread T0001:
#0 rdataset_settrust lib/dns/ncache.c:499
#1 dns_rdataset_settrust lib/dns/rdataset.c:597
#2 marksecure lib/dns/validator.c:202
#3 validate_answer lib/dns/validator.c:1528
#4 validator_start lib/dns/validator.c:2935
#5 isc__async_cb lib/isc/async.c:111
#6 uv__async_io /usr/src/libuv-v1.47.0/src/unix/async.c:176
#7 thread_body lib/isc/thread.c:85
#8 thread_run lib/isc/thread.c:100
Location is heap block of size 1015 at 0x000000000020 allocated by main thread:
#0 malloc ../../../../src/libsanitizer/tsan/tsan_interceptors_posix.cpp:647
#1 mallocx lib/isc/jemalloc_shim.h:67
#2 mem_get lib/isc/mem.c:303
#3 isc__mem_get lib/isc/mem.c:675
#4 dns_rdataslab_fromrdataset lib/dns/rdataslab.c:332
#5 dns__rbtdb_addrdataset lib/dns/rbtdb.c:3153
#6 dns__db_addrdataset lib/dns/db.c:681
#7 addoptout lib/dns/ncache.c:283
#8 dns_ncache_add lib/dns/ncache.c:103
#9 ncache_adderesult lib/dns/resolver.c:6358
#10 validated lib/dns/resolver.c:5385
#11 validator_done_cb lib/dns/validator.c:210
#12 isc__async_cb lib/isc/async.c:111
#13 uv__async_io /usr/src/libuv-v1.47.0/src/unix/async.c:176
#14 thread_body lib/isc/thread.c:85
#15 isc_thread_main lib/isc/thread.c:116
#16 isc_loopmgr_run lib/isc/loop.c:454
#17 main bin/named/main.c:1574
Thread T0001 'isc-loop-0002' (running) created by main thread at:
#0 pthread_create ../../../../src/libsanitizer/tsan/tsan_interceptors_posix.cpp:1001
#1 isc_thread_create lib/isc/thread.c:139
#2 isc_loopmgr_run lib/isc/loop.c:448
#3 main bin/named/main.c:1574
SUMMARY: ThreadSanitizer: data race ../../lib/isc/include/isc/buffer.h:847 in isc_buffer_peekuint8
```
```
WARNING: ThreadSanitizer: data race
Write of size 1 at 0x000000000001 by main thread:
#0 rdataset_settrust lib/dns/ncache.c:499
#1 dns_rdataset_settrust lib/dns/rdataset.c:597
#2 marksecure lib/dns/validator.c:202
#3 validate_answer lib/dns/validator.c:1528
#4 validator_start lib/dns/validator.c:2935
#5 isc__async_cb lib/isc/async.c:111
#6 uv__async_io /usr/src/libuv-v1.47.0/src/unix/async.c:176
#7 thread_body lib/isc/thread.c:85
#8 isc_thread_main lib/isc/thread.c:116
#9 isc_loopmgr_run lib/isc/loop.c:454
#10 main bin/named/main.c:1574
Previous write of size 1 at 0x000000000001 by thread T0001:
#0 rdataset_settrust lib/dns/ncache.c:499
#1 dns_rdataset_settrust lib/dns/rdataset.c:597
#2 marksecure lib/dns/validator.c:202
#3 validate_answer lib/dns/validator.c:1528
#4 validator_start lib/dns/validator.c:2935
#5 isc__async_cb lib/isc/async.c:111
#6 uv__async_io /usr/src/libuv-v1.47.0/src/unix/async.c:176
#7 thread_body lib/isc/thread.c:85
#8 thread_run lib/isc/thread.c:100
Location is heap block of size 1015 at 0x000000000014 allocated by thread T0002:
#0 malloc ../../../../src/libsanitizer/tsan/tsan_interceptors_posix.cpp:647
#1 mallocx lib/isc/jemalloc_shim.h:67
#2 mem_get lib/isc/mem.c:303
#3 isc__mem_get lib/isc/mem.c:675
#4 dns_rdataslab_fromrdataset lib/dns/rdataslab.c:332
#5 dns__rbtdb_addrdataset lib/dns/rbtdb.c:3153
#6 dns__db_addrdataset lib/dns/db.c:681
#7 addoptout lib/dns/ncache.c:283
#8 dns_ncache_add lib/dns/ncache.c:103
#9 ncache_adderesult lib/dns/resolver.c:6358
#10 validated lib/dns/resolver.c:5385
#11 validator_done_cb lib/dns/validator.c:210
#12 isc__async_cb lib/isc/async.c:111
#13 uv__async_io /usr/src/libuv-v1.47.0/src/unix/async.c:176
#14 thread_body lib/isc/thread.c:85
#15 thread_run lib/isc/thread.c:100
Thread T0001 'isc-loop-0001' (running) created by main thread at:
#0 pthread_create ../../../../src/libsanitizer/tsan/tsan_interceptors_posix.cpp:1001
#1 isc_thread_create lib/isc/thread.c:139
#2 isc_loopmgr_run lib/isc/loop.c:448
#3 main bin/named/main.c:1574
Thread T0002 'isc-loop-0002' (running) created by main thread at:
#0 pthread_create ../../../../src/libsanitizer/tsan/tsan_interceptors_posix.cpp:1001
#1 isc_thread_create lib/isc/thread.c:139
#2 isc_loopmgr_run lib/isc/loop.c:448
#3 main bin/named/main.c:1574
SUMMARY: ThreadSanitizer: data race lib/dns/ncache.c:499 in rdataset_settrust
```
```
WARNING: ThreadSanitizer: data race
Read of size 8 at 0x000000000001 by main thread:
#0 memmove ../../../../src/libsanitizer/sanitizer_common/sanitizer_common_interceptors.inc:810
#1 memmove ../../../../src/libsanitizer/sanitizer_common/sanitizer_common_interceptors.inc:808
#2 memmove /usr/include/x86_64-linux-gnu/bits/string_fortified.h:36
#3 dns_name_fromregion lib/dns/name.c:739
#4 dns_ncache_current lib/dns/ncache.c:701
#5 validate_ncache lib/dns/validator.c:2382
#6 validate_nx lib/dns/validator.c:2431
#7 validator_start lib/dns/validator.c:2994
#8 isc__async_cb lib/isc/async.c:111
#9 uv__async_io /usr/src/libuv-v1.47.0/src/unix/async.c:176
#10 thread_body lib/isc/thread.c:85
#11 isc_thread_main lib/isc/thread.c:116
#12 isc_loopmgr_run lib/isc/loop.c:454
#13 main bin/named/main.c:1574
Previous write of size 1 at 0x000000000014 by thread T0001:
#0 rdataset_settrust lib/dns/ncache.c:499
#1 dns_rdataset_settrust lib/dns/rdataset.c:597
#2 marksecure lib/dns/validator.c:200
#3 validate_answer lib/dns/validator.c:1528
#4 validator_start lib/dns/validator.c:2935
#5 isc__async_cb lib/isc/async.c:111
#6 uv__async_io /usr/src/libuv-v1.47.0/src/unix/async.c:176
#7 thread_body lib/isc/thread.c:85
#8 thread_run lib/isc/thread.c:100
Location is heap block of size 1047 at 0x000000000021 allocated by thread T0001:
#0 malloc ../../../../src/libsanitizer/tsan/tsan_interceptors_posix.cpp:647
#1 mallocx lib/isc/jemalloc_shim.h:67
#2 mem_get lib/isc/mem.c:303
#3 isc__mem_get lib/isc/mem.c:675
#4 dns_rdataslab_fromrdataset lib/dns/rdataslab.c:332
#5 dns__rbtdb_addrdataset lib/dns/rbtdb.c:3153
#6 dns__db_addrdataset lib/dns/db.c:681
#7 addoptout lib/dns/ncache.c:283
#8 dns_ncache_add lib/dns/ncache.c:103
#9 ncache_adderesult lib/dns/resolver.c:6358
#10 validated lib/dns/resolver.c:5385
#11 validator_done_cb lib/dns/validator.c:210
#12 isc__async_cb lib/isc/async.c:111
#13 uv__async_io /usr/src/libuv-v1.47.0/src/unix/async.c:176
#14 thread_body lib/isc/thread.c:85
#15 thread_run lib/isc/thread.c:100
Thread T0001 'isc-loop-0001' (running) created by main thread at:
#0 pthread_create ../../../../src/libsanitizer/tsan/tsan_interceptors_posix.cpp:1001
#1 isc_thread_create lib/isc/thread.c:139
#2 isc_loopmgr_run lib/isc/loop.c:448
#3 main bin/named/main.c:1574
SUMMARY: ThreadSanitizer: data race /usr/include/x86_64-linux-gnu/bits/string_fortified.h:36 in memmove
```
I restarted the job, and this is a [reproducible issue](https://gitlab.isc.org/isc-projects/bind9/-/jobs/3849392).May 2024 (9.18.27, 9.18.27-S1, 9.19.24)Mark AndrewsMark Andrewshttps://gitlab.isc.org/isc-projects/bind9/-/issues/4453Switching to a different dnssec-policy broke my zone.2024-02-24T07:54:16ZBjörn PerssonSwitching to a different dnssec-policy broke my zone.### Summary
My zone was previously signed with a KSK and a ZSK with unlimited lifetime. I switched the zone over to a dnssec-policy using CSKs and automatic key rotation. After the DS record was updated, most of the RRSIG records were r...### Summary
My zone was previously signed with a KSK and a ZSK with unlimited lifetime. I switched the zone over to a dnssec-policy using CSKs and automatic key rotation. After the DS record was updated, most of the RRSIG records were removed, leaving the zone broken to validating resolvers.
### BIND version used
```
# named -V
BIND 9.18.19-1~deb12u1-Debian (Extended Support Version) <id:>
running on Linux x86_64 5.10.0-26-amd64 #1 SMP Debian 5.10.197-1 (2023-09-29)
built by make with '--build=x86_64-linux-gnu' '--prefix=/usr' '--includedir=${prefix}/include' '--mandir=${prefix}/share/man' '--infodir=${prefix}/share/info' '--sysconfdir=/etc' '--localstatedir=/var' '--disable-option-checking' '--disable-silent-rules' '--libdir=${prefix}/lib/x86_64-linux-gnu' '--runstatedir=/run' '--disable-maintainer-mode' '--disable-dependency-tracking' '--libdir=/usr/lib/x86_64-linux-gnu' '--sysconfdir=/etc/bind' '--with-python=python3' '--localstatedir=/' '--enable-threads' '--enable-largefile' '--with-libtool' '--enable-shared' '--disable-static' '--with-gost=no' '--with-openssl=/usr' '--with-gssapi=yes' '--with-libidn2' '--with-json-c' '--with-lmdb=/usr' '--with-gnu-ld' '--with-maxminddb' '--with-atf=no' '--enable-ipv6' '--enable-rrl' '--enable-filter-aaaa' '--disable-native-pkcs11' '--enable-dnstap' 'build_alias=x86_64-linux-gnu' 'CFLAGS=-g -O2 -ffile-prefix-map=/build/reproducible-path/bind9-9.18.19=. -fstack-protector-strong -Wformat -Werror=format-security -fno-strict-aliasing -fno-delete-null-pointer-checks -DNO_VERSION_DATE -DDIG_SIGCHASE' 'LDFLAGS=-Wl,-z,relro -Wl,-z,now' 'CPPFLAGS=-Wdate-time -D_FORTIFY_SOURCE=2'
compiled by GCC 12.2.0
compiled with OpenSSL version: OpenSSL 3.0.10 1 Aug 2023
linked to OpenSSL version: OpenSSL 3.0.11 19 Sep 2023
compiled with libuv version: 1.44.2
linked to libuv version: 1.44.2
compiled with libnghttp2 version: 1.52.0
linked to libnghttp2 version: 1.52.0
compiled with libxml2 version: 2.9.14
linked to libxml2 version: 20914
compiled with json-c version: 0.16
linked to json-c version: 0.16
compiled with zlib version: 1.2.13
linked to zlib version: 1.2.13
linked to maxminddb version: 1.7.1
compiled with protobuf-c version: 1.4.1
linked to protobuf-c version: 1.4.1
threads support is enabled
DNSSEC algorithms: RSASHA1 NSEC3RSASHA1 RSASHA256 RSASHA512 ECDSAP256SHA256 ECDSAP384SHA384 ED25519 ED448
DS algorithms: SHA-1 SHA-256 SHA-384
HMAC algorithms: HMAC-MD5 HMAC-SHA1 HMAC-SHA224 HMAC-SHA256 HMAC-SHA384 HMAC-SHA512
TKEY mode 2 support (Diffie-Hellman): yes
TKEY mode 3 support (GSS-API): yes
default paths:
named configuration: /etc/bind/named.conf
rndc configuration: /etc/bind/rndc.conf
DNSSEC root key: /etc/bind/bind.keys
nsupdate session key: //run/named/session.key
named PID file: //run/named/named.pid
named lock file: //run/named/named.lock
geoip-directory: /usr/share/GeoIP
```
### Steps to reproduce
I have two zones that both exist in an external and an internal view. Each zone was previously signed with a KSK and a ZSK with unlimited lifetime. To proceed cautiously with the change to `dnssec-policy` I defined one policy that matched the existing keys and another that would use CSKs and automatic key rotation:
```
dnssec-policy "as_it_was" {
keys {
ksk lifetime unlimited algorithm rsasha256 2048;
zsk lifetime unlimited algorithm rsasha256 2048;
};
dnskey-ttl P1D;
purge-keys 0;
};
dnssec-policy "automation" {
keys {
csk lifetime P1M algorithm rsasha256 2048;
};
dnskey-ttl P1D;
max-zone-ttl P1D;
signatures-validity P1W;
signatures-refresh P2D;
};
```
First I switched the zones from "`auto-dnssec maintain;`" to "`dnssec-policy as_it_was;`". Bind continued using the existing keys. Once I had the exchange of CDS and DS records working between my zones and the parent zone, I switched one zone over to "`dnssec-policy automation;`" in both views.
The rollover from the old keys to a CSK seemed to go smoothly, but after a while I discovered that the zone was only partially signed in the external view. Several records lacked RRSIG records. Dynamic updates of the unsigned records caused corresponding RRSIG records to appear.
After that initial problem, the following rollover from one CSK to another worked fine, so I proceeded to switch the second zone over to "`dnssec-policy automation;`". This time I took notes and watched for missing signatures.
2023-11-18 16:05:49 a CSK was generated. DNSKEY, CDS and CDNSKEY were signed with both the old KSK and the CSK. SOA got a new signature by the old ZSK. All other records kept their existing signatures.
2023-11-19 17:10:49 CDS and CDNSKEY records for the CSK were published. DNSKEY, CDS and CDNSKEY got new signatures by the KSK and the CSK. SOA was signed with the ZSK and the CSK.
2023-11-20 17:10:49 Bind noticed that DS had been updated in the parent zone.
2023-11-20 18:15:49 the ZSK and all its signatures were removed. DNSKEY, CDS and CDNSKEY got new signatures by the CSK and the KSK. SOA got a new signature by the CSK. All other records were left without RRSIG records.
This time I fixed the external view with "`rndc sign xn--rombobjrn-67a.se IN external`". All the unsigned records were then signed with the CSK. DNSKEY, CDS, CDNSKEY and SOA had their signatures renewed. I left the internal view alone.
2023-11-21 19:10:50 the KSK was removed. DNSKEY, CDS, CDNSKEY and SOA got new signatures by the CSK. At the same time, many but not all other records in the internal view were finally signed with the CSK, having lacked signatures for 24 hours and 55 minutes. Some more records were signed a few minutes later.
As I'm posting this, one NS and one MX record in the internal view are still unsigned after more than four days.
### What is the current *bug* behavior?
The zone becomes only partially signed. Validating resolvers reject the unsigned records.
### What is the expected *correct* behavior?
All records should be signed with the new key before the old keys and signatures are removed.
### Relevant configuration files
See the policies above. After the changes, all the zone declarations look essentially like this:
```
zone "xn--rombobjrn-67a.se" {
type master;
file "/var/lib/bind/db.xn--rombobjrn-67a.se.external";
dnssec-policy automation;
parental-agents { ::1; };
inline-signing no;
update-policy { [omitted] };
};
```
### Relevant logs and/or screenshots
Excerpts from the system log:
```
2023-11-19T17:10:49.436468+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/external: reconfiguring zone keys
2023-11-19T17:10:49.437286+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/internal: reconfiguring zone keys
2023-11-19T17:10:49.488666+01:00 cutie named[443161]: keymgr: retire DNSKEY xn--rombobjrn-67a.se/RSASHA256/13398 (ZSK)
2023-11-19T17:10:49.489192+01:00 cutie named[443161]: keymgr: retire DNSKEY xn--rombobjrn-67a.se/RSASHA256/53584 (KSK)
2023-11-19T17:10:49.501444+01:00 cutie named[443161]: DNSKEY xn--rombobjrn-67a.se/RSASHA256/53584 (KSK) is now inactive
2023-11-19T17:10:49.502076+01:00 cutie named[443161]: CDS (SHA-256) for key xn--rombobjrn-67a.se/RSASHA256/53584 is now deleted
2023-11-19T17:10:49.502515+01:00 cutie named[443161]: CDNSKEY for key xn--rombobjrn-67a.se/RSASHA256/53584 is now deleted
2023-11-19T17:10:49.502904+01:00 cutie named[443161]: CDS for key xn--rombobjrn-67a.se/RSASHA256/17339 is now published
2023-11-19T17:10:49.503279+01:00 cutie named[443161]: CDNSKEY for key xn--rombobjrn-67a.se/RSASHA256/17339 is now published
2023-11-19T17:10:49.530343+01:00 cutie named[443161]: keymgr: retire DNSKEY xn--rombobjrn-67a.se/RSASHA256/13398 (ZSK)
2023-11-19T17:10:49.530897+01:00 cutie named[443161]: keymgr: retire DNSKEY xn--rombobjrn-67a.se/RSASHA256/53584 (KSK)
2023-11-19T17:10:49.534298+01:00 cutie named[443161]: DNSKEY xn--rombobjrn-67a.se/RSASHA256/53584 (KSK) is now inactive
2023-11-19T17:10:49.534962+01:00 cutie named[443161]: CDS (SHA-256) for key xn--rombobjrn-67a.se/RSASHA256/53584 is now deleted
2023-11-19T17:10:49.535337+01:00 cutie named[443161]: CDNSKEY for key xn--rombobjrn-67a.se/RSASHA256/53584 is now deleted
2023-11-19T17:10:49.535684+01:00 cutie named[443161]: CDS for key xn--rombobjrn-67a.se/RSASHA256/17339 is now published
2023-11-19T17:10:49.536038+01:00 cutie named[443161]: CDNSKEY for key xn--rombobjrn-67a.se/RSASHA256/17339 is now published
2023-11-19T17:10:49.637732+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/external: next key event: 19-Nov-2023 18:10:49.432
2023-11-19T17:10:49.638433+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/external: sending notifies (serial 2023092737)
2023-11-19T17:10:49.651717+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/internal: next key event: 19-Nov-2023 18:10:49.432
2023-11-19T17:10:49.673263+01:00 cutie named[443161]: client @0x7efdf9b21368 10.1.0.5#54619 (xn--rombobjrn-67a.se): view external: transfer of 'xn--rombobjrn-67a.se/IN': IXFR started (serial 2023092736 -> 2023092737)
2023-11-19T17:10:49.674244+01:00 cutie named[443161]: client @0x7efdf9b21368 10.1.0.5#54619 (xn--rombobjrn-67a.se): view external: transfer of 'xn--rombobjrn-67a.se/IN': IXFR ended: 1 messages, 23 records, 5465 bytes, 0.004 secs (1366250 bytes/sec) (serial 2023092737)
2023-11-19T17:10:50.192637+01:00 cutie named[443161]: client @0x7efdfa51af68 10.1.2.1#57043 (xn--rombobjrn-67a.se): view external: transfer of 'xn--rombobjrn-67a.se/IN': IXFR started (serial 2023092736 -> 2023092737)
2023-11-19T17:10:50.193661+01:00 cutie named[443161]: client @0x7efdfa51af68 10.1.2.1#57043 (xn--rombobjrn-67a.se): view external: transfer of 'xn--rombobjrn-67a.se/IN': IXFR ended: 1 messages, 23 records, 5465 bytes, 0.001 secs (5465000 bytes/sec) (serial 2023092737)
```
```
2023-11-20T17:10:49.472806+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/internal: reconfiguring zone keys
2023-11-20T17:10:49.473891+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/external: reconfiguring zone keys
2023-11-20T17:10:49.525113+01:00 cutie named[443161]: keymgr: retire DNSKEY xn--rombobjrn-67a.se/RSASHA256/13398 (ZSK)
2023-11-20T17:10:49.525655+01:00 cutie named[443161]: keymgr: retire DNSKEY xn--rombobjrn-67a.se/RSASHA256/53584 (KSK)
2023-11-20T17:10:49.529210+01:00 cutie named[443161]: DNSKEY xn--rombobjrn-67a.se/RSASHA256/53584 (KSK) is now inactive
2023-11-20T17:10:49.530341+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/internal: next key event: 20-Nov-2023 18:10:49.466
2023-11-20T17:10:49.557565+01:00 cutie named[443161]: keymgr: retire DNSKEY xn--rombobjrn-67a.se/RSASHA256/13398 (ZSK)
2023-11-20T17:10:49.558183+01:00 cutie named[443161]: keymgr: retire DNSKEY xn--rombobjrn-67a.se/RSASHA256/53584 (KSK)
2023-11-20T17:10:49.561418+01:00 cutie named[443161]: DNSKEY xn--rombobjrn-67a.se/RSASHA256/53584 (KSK) is now inactive
2023-11-20T17:10:49.562620+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/external: next key event: 20-Nov-2023 18:10:49.466
2023-11-20T17:10:49.617384+01:00 cutie named[443161]: keymgr: checkds DS for key xn--rombobjrn-67a.se/RSASHA256/17339 seen published at Mon Nov 20 17:10:49 2023
2023-11-20T17:10:49.621343+01:00 cutie named[443161]: keymgr: checkds DS for key xn--rombobjrn-67a.se/RSASHA256/53584 seen withdrawn at Mon Nov 20 17:10:49 2023
2023-11-20T17:10:49.624985+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/internal: reconfiguring zone keys
2023-11-20T17:10:49.667546+01:00 cutie named[443161]: keymgr: retire DNSKEY xn--rombobjrn-67a.se/RSASHA256/13398 (ZSK)
2023-11-20T17:10:49.668097+01:00 cutie named[443161]: keymgr: retire DNSKEY xn--rombobjrn-67a.se/RSASHA256/53584 (KSK)
2023-11-20T17:10:49.671602+01:00 cutie named[443161]: DNSKEY xn--rombobjrn-67a.se/RSASHA256/53584 (KSK) is now inactive
2023-11-20T17:10:49.672714+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/internal: next key event: 20-Nov-2023 18:15:49.618
2023-11-20T17:10:50.027333+01:00 cutie named[443161]: keymgr: checkds DS for key xn--rombobjrn-67a.se/RSASHA256/17339 seen published at Mon Nov 20 17:10:50 2023
2023-11-20T17:10:50.031352+01:00 cutie named[443161]: keymgr: checkds DS for key xn--rombobjrn-67a.se/RSASHA256/53584 seen withdrawn at Mon Nov 20 17:10:50 2023
2023-11-20T17:10:50.035151+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/external: reconfiguring zone keys
2023-11-20T17:10:50.077904+01:00 cutie named[443161]: keymgr: retire DNSKEY xn--rombobjrn-67a.se/RSASHA256/13398 (ZSK)
2023-11-20T17:10:50.078540+01:00 cutie named[443161]: keymgr: retire DNSKEY xn--rombobjrn-67a.se/RSASHA256/53584 (KSK)
2023-11-20T17:10:50.081828+01:00 cutie named[443161]: DNSKEY xn--rombobjrn-67a.se/RSASHA256/53584 (KSK) is now inactive
2023-11-20T17:10:50.083015+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/external: next key event: 20-Nov-2023 18:15:49.030
```
```
2023-11-20T18:15:49.036472+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/external: reconfiguring zone keys
2023-11-20T18:15:49.076389+01:00 cutie named[443161]: keymgr: retire DNSKEY xn--rombobjrn-67a.se/RSASHA256/13398 (ZSK)
2023-11-20T18:15:49.077010+01:00 cutie named[443161]: keymgr: retire DNSKEY xn--rombobjrn-67a.se/RSASHA256/53584 (KSK)
2023-11-20T18:15:49.088905+01:00 cutie named[443161]: Removing expired key xn--rombobjrn-67a.se/13398/RSASHA256 from DNSKEY RRset.
2023-11-20T18:15:49.089406+01:00 cutie named[443161]: DNSKEY xn--rombobjrn-67a.se/RSASHA256/13398 (ZSK) is now deleted
2023-11-20T18:15:49.089784+01:00 cutie named[443161]: DNSKEY xn--rombobjrn-67a.se/RSASHA256/53584 (KSK) is now inactive
2023-11-20T18:15:49.192756+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/external: next key event: 20-Nov-2023 18:20:49.033
2023-11-20T18:15:49.193416+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/external: sending notifies (serial 2023092738)
2023-11-20T18:15:49.275467+01:00 cutie named[443161]: client @0x7efdebdc6d68 10.1.0.5#41397 (xn--rombobjrn-67a.se): view external: transfer of 'xn--rombobjrn-67a.se/IN': IXFR started (serial 2023092737 -> 2023092739)
2023-11-20T18:15:49.278365+01:00 cutie named[443161]: client @0x7efdebdc6d68 10.1.0.5#41397 (xn--rombobjrn-67a.se): view external: transfer of 'xn--rombobjrn-67a.se/IN': IXFR ended: 3 messages, 128 records, 38648 bytes, 0.004 secs (9662000 bytes/sec) (serial 2023092739)
2023-11-20T18:15:49.622949+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/internal: reconfiguring zone keys
2023-11-20T18:15:49.664238+01:00 cutie named[443161]: keymgr: retire DNSKEY xn--rombobjrn-67a.se/RSASHA256/13398 (ZSK)
2023-11-20T18:15:49.664712+01:00 cutie named[443161]: keymgr: retire DNSKEY xn--rombobjrn-67a.se/RSASHA256/53584 (KSK)
2023-11-20T18:15:49.667624+01:00 cutie named[443161]: Removing expired key xn--rombobjrn-67a.se/13398/RSASHA256 from DNSKEY RRset.
2023-11-20T18:15:49.668019+01:00 cutie named[443161]: DNSKEY xn--rombobjrn-67a.se/RSASHA256/13398 (ZSK) is now deleted
2023-11-20T18:15:49.668373+01:00 cutie named[443161]: DNSKEY xn--rombobjrn-67a.se/RSASHA256/53584 (KSK) is now inactive
2023-11-20T18:15:49.764336+01:00 cutie named[443161]: client @0x7efdebdc5168 10.1.2.1#58091 (xn--rombobjrn-67a.se): view external: transfer of 'xn--rombobjrn-67a.se/IN': IXFR started (serial 2023092737 -> 2023092739)
2023-11-20T18:15:49.767341+01:00 cutie named[443161]: client @0x7efdebdc5168 10.1.2.1#58091 (xn--rombobjrn-67a.se): view external: transfer of 'xn--rombobjrn-67a.se/IN': IXFR ended: 3 messages, 128 records, 38648 bytes, 0.004 secs (9662000 bytes/sec) (serial 2023092739)
2023-11-20T18:15:49.779256+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/internal: next key event: 20-Nov-2023 18:20:49.621
2023-11-20T18:15:54.192437+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/external: sending notifies (serial 2023092739)
```
```
2023-11-21T13:15:40.402451+01:00 cutie named[443161]: received control channel command 'sign xn--rombobjrn-67a.se IN external'
2023-11-21T13:15:40.405362+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/external: reconfiguring zone keys
2023-11-21T13:15:40.431241+01:00 cutie named[443161]: keymgr: retire DNSKEY xn--rombobjrn-67a.se/RSASHA256/13398 (ZSK)
2023-11-21T13:15:40.431697+01:00 cutie named[443161]: keymgr: retire DNSKEY xn--rombobjrn-67a.se/RSASHA256/53584 (KSK)
2023-11-21T13:15:40.433742+01:00 cutie named[443161]: DNSKEY xn--rombobjrn-67a.se/RSASHA256/53584 (KSK) is now inactive
2023-11-21T13:15:40.528574+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/external: next key event: 21-Nov-2023 19:10:50.395
2023-11-21T13:15:40.529172+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/external: sending notifies (serial 2023092740)
2023-11-21T13:15:40.773096+01:00 cutie named[443161]: client @0x7efdfa51af68 10.1.0.5#33623 (xn--rombobjrn-67a.se): view external: transfer of 'xn--rombobjrn-67a.se/IN': IXFR started (serial 2023092739 -> 2023092742)
2023-11-21T13:15:40.774513+01:00 cutie named[443161]: client @0x7efdfa51af68 10.1.0.5#33623 (xn--rombobjrn-67a.se): view external: transfer of 'xn--rombobjrn-67a.se/IN': IXFR ended: 1 messages, 46 records, 12419 bytes, 0.004 secs (3104750 bytes/sec) (serial 2023092742)
2023-11-21T13:15:41.172719+01:00 cutie named[443161]: client @0x7efdf9b20568 10.1.2.1#33203 (xn--rombobjrn-67a.se): view external: transfer of 'xn--rombobjrn-67a.se/IN': IXFR started (serial 2023092739 -> 2023092745)
2023-11-21T13:15:41.174657+01:00 cutie named[443161]: client @0x7efdf9b20568 10.1.2.1#33203 (xn--rombobjrn-67a.se): view external: transfer of 'xn--rombobjrn-67a.se/IN': IXFR ended: 2 messages, 89 records, 24907 bytes, 0.004 secs (6226750 bytes/sec) (serial 2023092745)
2023-11-21T13:15:45.528370+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/external: sending notifies (serial 2023092750)
2023-11-21T13:15:45.561710+01:00 cutie named[443161]: client @0x7efdebdc6d68 10.1.0.5#52787 (xn--rombobjrn-67a.se): view external: transfer of 'xn--rombobjrn-67a.se/IN': IXFR started (serial 2023092742 -> 2023092750)
2023-11-21T13:15:45.564494+01:00 cutie named[443161]: client @0x7efdebdc6d68 10.1.0.5#52787 (xn--rombobjrn-67a.se): view external: transfer of 'xn--rombobjrn-67a.se/IN': IXFR ended: 2 messages, 114 records, 31108 bytes, 0.004 secs (7777000 bytes/sec) (serial 2023092750)
2023-11-21T13:15:46.078928+01:00 cutie named[443161]: client @0x7efdfa51bd68 10.1.2.1#60701 (xn--rombobjrn-67a.se): view external: transfer of 'xn--rombobjrn-67a.se/IN': IXFR started (serial 2023092745 -> 2023092750)
2023-11-21T13:15:46.080874+01:00 cutie named[443161]: client @0x7efdfa51bd68 10.1.2.1#60701 (xn--rombobjrn-67a.se): view external: transfer of 'xn--rombobjrn-67a.se/IN': IXFR ended: 2 messages, 71 records, 18769 bytes, 0.001 secs (18769000 bytes/sec) (serial 2023092750)
```
```
2023-11-21T19:10:50.400377+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/external: reconfiguring zone keys
2023-11-21T19:10:50.432532+01:00 cutie named[443161]: keymgr: retire DNSKEY xn--rombobjrn-67a.se/RSASHA256/13398 (ZSK)
2023-11-21T19:10:50.433038+01:00 cutie named[443161]: keymgr: retire DNSKEY xn--rombobjrn-67a.se/RSASHA256/53584 (KSK)
2023-11-21T19:10:50.443664+01:00 cutie named[443161]: Removing expired key xn--rombobjrn-67a.se/53584/RSASHA256 from DNSKEY RRset.
2023-11-21T19:10:50.444123+01:00 cutie named[443161]: DNSKEY xn--rombobjrn-67a.se/RSASHA256/53584 (KSK) is now deleted
2023-11-21T19:10:50.511795+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/external: next key event: 21-Nov-2023 19:15:50.396
2023-11-21T19:10:50.512265+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/external: sending notifies (serial 2023092751)
2023-11-21T19:10:50.576696+01:00 cutie named[443161]: client @0x7efdfa51af68 10.1.0.5#54307 (xn--rombobjrn-67a.se): view external: transfer of 'xn--rombobjrn-67a.se/IN': IXFR started (serial 2023092750 -> 2023092752)
2023-11-21T19:10:50.577645+01:00 cutie named[443161]: client @0x7efdfa51af68 10.1.0.5#54307 (xn--rombobjrn-67a.se): view external: transfer of 'xn--rombobjrn-67a.se/IN': IXFR ended: 1 messages, 27 records, 5832 bytes, 0.001 secs (5832000 bytes/sec) (serial 2023092752)
2023-11-21T19:10:50.626991+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/internal: reconfiguring zone keys
2023-11-21T19:10:50.660686+01:00 cutie named[443161]: keymgr: retire DNSKEY xn--rombobjrn-67a.se/RSASHA256/13398 (ZSK)
2023-11-21T19:10:50.661150+01:00 cutie named[443161]: keymgr: retire DNSKEY xn--rombobjrn-67a.se/RSASHA256/53584 (KSK)
2023-11-21T19:10:50.663077+01:00 cutie named[443161]: Removing expired key xn--rombobjrn-67a.se/53584/RSASHA256 from DNSKEY RRset.
2023-11-21T19:10:50.663489+01:00 cutie named[443161]: DNSKEY xn--rombobjrn-67a.se/RSASHA256/53584 (KSK) is now deleted
2023-11-21T19:10:50.738310+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/internal: next key event: 21-Nov-2023 19:15:50.624
2023-11-21T19:10:51.191122+01:00 cutie named[443161]: client @0x7efdf9b20568 10.1.2.1#43631 (xn--rombobjrn-67a.se): view external: transfer of 'xn--rombobjrn-67a.se/IN': IXFR started (serial 2023092750 -> 2023092752)
2023-11-21T19:10:51.191859+01:00 cutie named[443161]: client @0x7efdf9b20568 10.1.2.1#43631 (xn--rombobjrn-67a.se): view external: transfer of 'xn--rombobjrn-67a.se/IN': IXFR ended: 1 messages, 27 records, 5832 bytes, 0.001 secs (5832000 bytes/sec) (serial 2023092752)
2023-11-21T19:10:55.511787+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/external: sending notifies (serial 2023092752)
2023-11-21T19:15:50.404325+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/external: reconfiguring zone keys
2023-11-21T19:15:50.427941+01:00 cutie named[443161]: keymgr: retire DNSKEY xn--rombobjrn-67a.se/RSASHA256/13398 (ZSK)
2023-11-21T19:15:50.428397+01:00 cutie named[443161]: keymgr: retire DNSKEY xn--rombobjrn-67a.se/RSASHA256/53584 (KSK)
2023-11-21T19:15:50.440377+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/external: next key event: 21-Nov-2023 19:20:49.398
2023-11-21T19:15:50.630905+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/internal: reconfiguring zone keys
2023-11-21T19:15:50.656580+01:00 cutie named[443161]: keymgr: retire DNSKEY xn--rombobjrn-67a.se/RSASHA256/13398 (ZSK)
2023-11-21T19:15:50.657098+01:00 cutie named[443161]: keymgr: retire DNSKEY xn--rombobjrn-67a.se/RSASHA256/53584 (KSK)
2023-11-21T19:15:50.659929+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/internal: next key event: 21-Nov-2023 19:20:49.626
2023-11-21T19:20:49.405293+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/external: reconfiguring zone keys
2023-11-21T19:20:49.429191+01:00 cutie named[443161]: keymgr: retire DNSKEY xn--rombobjrn-67a.se/RSASHA256/13398 (ZSK)
2023-11-21T19:20:49.429646+01:00 cutie named[443161]: keymgr: retire DNSKEY xn--rombobjrn-67a.se/RSASHA256/53584 (KSK)
2023-11-21T19:20:49.438021+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/external: next key event: 21-Nov-2023 19:20:50.399
2023-11-21T19:20:49.630959+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/internal: reconfiguring zone keys
2023-11-21T19:20:49.656677+01:00 cutie named[443161]: keymgr: retire DNSKEY xn--rombobjrn-67a.se/RSASHA256/13398 (ZSK)
2023-11-21T19:20:49.657172+01:00 cutie named[443161]: keymgr: retire DNSKEY xn--rombobjrn-67a.se/RSASHA256/53584 (KSK)
2023-11-21T19:20:49.659897+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/internal: next key event: 21-Nov-2023 19:20:50.627
2023-11-21T19:20:50.401138+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/external: reconfiguring zone keys
2023-11-21T19:20:50.427552+01:00 cutie named[443161]: keymgr: retire DNSKEY xn--rombobjrn-67a.se/RSASHA256/13398 (ZSK)
2023-11-21T19:20:50.428010+01:00 cutie named[443161]: keymgr: retire DNSKEY xn--rombobjrn-67a.se/RSASHA256/53584 (KSK)
2023-11-21T19:20:50.434902+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/external: next key event: 21-Nov-2023 20:20:50.399
2023-11-21T19:20:50.629148+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/internal: reconfiguring zone keys
2023-11-21T19:20:50.654607+01:00 cutie named[443161]: keymgr: retire DNSKEY xn--rombobjrn-67a.se/RSASHA256/13398 (ZSK)
2023-11-21T19:20:50.655054+01:00 cutie named[443161]: keymgr: retire DNSKEY xn--rombobjrn-67a.se/RSASHA256/53584 (KSK)
2023-11-21T19:20:50.657686+01:00 cutie named[443161]: zone xn--rombobjrn-67a.se/IN/internal: next key event: 21-Nov-2023 20:20:50.627
```
Some possibly useful status data from when the zone lacked signatures:
```
# rndc dnssec -status xn--rombobjrn-67a.se IN external
dnssec-policy: automatik
current time: Tue Nov 21 12:57:26 2023
key: 17339 (RSASHA256), CSK
published: yes - since Sat Nov 18 16:05:49 2023
key signing: yes - since Sat Nov 18 16:05:49 2023
zone signing: yes - since Sat Nov 18 16:05:49 2023
Next rollover scheduled on Mon Dec 18 15:00:49 2023
- goal: omnipresent
- dnskey: omnipresent
- ds: rumoured
- zone rrsig: omnipresent
- key rrsig: omnipresent
key: 13398 (RSASHA256), ZSK
published: no
zone signing: no
Key has been removed from the zone
- goal: hidden
- dnskey: hidden
- zone rrsig: unretentive
key: 53584 (RSASHA256), KSK
published: yes - since Sun Nov 3 04:26:07 2019
key signing: yes - since Sun Nov 3 04:26:07 2019
Rollover is due since Sun Nov 19 18:05:49 2023
- goal: hidden
- dnskey: omnipresent
- ds: unretentive
- key rrsig: omnipresent
# rndc zonestatus xn--rombobjrn-67a.se IN external
name: xn--rombobjrn-67a.se
type: primary
files: /var/lib/bind/db.xn--rombobjrn-67a.se.external
serial: 2023092739
nodes: 42
last loaded: Tue, 24 Oct 2023 12:43:57 GMT
secure: no
key maintenance: automatic
next key event: Tue, 21 Nov 2023 18:10:50 GMT
dynamic: yes
frozen: no
reconfigurable via modzone: no
```
The output of `rndc zonestatus` changed when I ran `rndc sign`:
```
# rndc zonestatus xn--rombobjrn-67a.se IN external
name: xn--rombobjrn-67a.se
type: primary
files: /var/lib/bind/db.xn--rombobjrn-67a.se.external
serial: 2023092750
nodes: 42
last loaded: Tue, 24 Oct 2023 12:43:57 GMT
secure: yes
inline signing: no
key maintenance: automatic
next key event: Tue, 21 Nov 2023 18:10:50 GMT
next resign node: 7c2ecd07f155648431e0f94b89247d713c5786e1e73e953f2fe7eca3._openpgpkey.xn--rombobjrn-67a.se/NSEC
next resign time: Wed, 22 Nov 2023 22:55:09 GMT
dynamic: yes
frozen: no
reconfigurable via modzone: no
```May 2024 (9.18.27, 9.18.27-S1, 9.19.24)Matthijs Mekkingmatthijs@isc.orgMatthijs Mekkingmatthijs@isc.orghttps://gitlab.isc.org/isc-projects/bind9/-/issues/4423named starts up slow when many zones reference the same dnssec-policy2024-02-24T07:54:22ZMatthijs Mekkingmatthijs@isc.orgnamed starts up slow when many zones reference the same dnssec-policyWhile rolling out KASP to many zones, it is more efficient to use more DNSSEC policies in order to improve
reload/reconfig times.
When all zones or referenced by the same `dnssec-policy`, it takes quite some time to process all zones af...While rolling out KASP to many zones, it is more efficient to use more DNSSEC policies in order to improve
reload/reconfig times.
When all zones or referenced by the same `dnssec-policy`, it takes quite some time to process all zones after reload/reconfig and CPU usage of the named process remains at 100% and it takes quite a few minutes for named to start responding to queries after such a reload/reconfig request.
When spreading my zones to 10 identical policies, cpu usage goes well above 100% (using more threads I assume) and this is speeding
things up really nice.May 2024 (9.18.27, 9.18.27-S1, 9.19.24)Matthijs Mekkingmatthijs@isc.orgMatthijs Mekkingmatthijs@isc.orghttps://gitlab.isc.org/isc-projects/bind9/-/issues/4298ns1 shutdown hang in "tcp:checking that BIND 9 doesn't crash on long TCP mess...2024-02-24T07:51:48ZMichal Nowakns1 shutdown hang in "tcp:checking that BIND 9 doesn't crash on long TCP messages"Job [#3639436](https://gitlab.isc.org/isc-projects/bind9/-/jobs/3639436) failed for 028154d416c2a29bea41c4d9658066845539b82a.
jemalloc arenas were merged to `main` and 9.18, but they did not help with the "tcp:checking that BIND 9 doesn...Job [#3639436](https://gitlab.isc.org/isc-projects/bind9/-/jobs/3639436) failed for 028154d416c2a29bea41c4d9658066845539b82a.
jemalloc arenas were merged to `main` and 9.18, but they did not help with the "tcp:checking that BIND 9 doesn't crash on long TCP messages" check (isc-projects/bind9#4038) entirely (nor with the `isc_mem_benchmark` check of the `mem_test` unit test, see isc-projects/bind9#4286). Arguably, I've never seen the `tcp` check fail four times in a day:
- https://gitlab.isc.org/isc-projects/bind9/-/jobs/3639436
- https://gitlab.isc.org/isc-projects/bind9/-/jobs/3639704
- https://gitlab.isc.org/isc-projects/bind9/-/jobs/3639696
- https://gitlab.isc.org/isc-projects/bind9/-/jobs/3639687
However, the nature of the failure is different: `ns1` is not OOM-killed but it didn't terminate in time, that is 5 minutes wasn't enough to terminate and the process was aborted.
```
2023-09-06 00:20:22 INFO:tcp I:tcp_tmp_n9au2yez:checking that BIND 9 doesn't crash on long TCP messages (10)
2023-09-06 00:20:22 INFO:tcp I:tcp_tmp_n9au2yez:sending 300000 time(s): 00010000000100000000000003697363036f72670000fc0001
2023-09-06 00:20:22 INFO:tcp I:tcp_tmp_n9au2yez:............................................................................................................................................................................................................................................................................................................
2023-09-06 00:20:22 INFO:tcp I:tcp_tmp_n9au2yez:sent 4023683 bytes to 10.53.0.1:20597
2023-09-06 00:20:22 INFO:tcp I:tcp_tmp_n9au2yez:exit status: 0
---------------------------- Captured log teardown -----------------------------
2023-09-06 00:25:23 INFO:tcp I:tcp_tmp_n9au2yez:ns1 didn't die when sent a SIGTERM
2023-09-06 00:25:23 ERROR:tcp Failed to stop servers
2023-09-06 00:25:24 INFO:tcp I:tcp_tmp_n9au2yez:Core dump(s) found: /builds/isc-projects/bind9/bin/tests/system/tcp_tmp_n9au2yez/ns1/core.387947
2023-09-06 00:25:24 INFO:tcp D:tcp_tmp_n9au2yez:backtrace from /builds/isc-projects/bind9/bin/tests/system/tcp_tmp_n9au2yez/ns1/core.387947:
2023-09-06 00:25:24 INFO:tcp D:tcp_tmp_n9au2yez:--------------------------------------------------------------------------------
2023-09-06 00:27:07 INFO:tcp D:/builds/isc-projects/bind9/bin/tests/system/tcp_tmp_n9au2yez:Core was generated by `/builds/isc-projects/bind9/bin/named/.libs/named -D tcp_tmp_n9au2yez-ns1 -X nam'.
2023-09-06 00:27:07 INFO:tcp D:/builds/isc-projects/bind9/bin/tests/system/tcp_tmp_n9au2yez:Program terminated with signal SIGABRT, Aborted.
2023-09-06 00:27:07 INFO:tcp D:/builds/isc-projects/bind9/bin/tests/system/tcp_tmp_n9au2yez:#0 0x00007f8a0a4c3129 in pthread_barrier_wait@GLIBC_2.2.5 () from /lib64/libc.so.6
2023-09-06 00:27:07 INFO:tcp D:/builds/isc-projects/bind9/bin/tests/system/tcp_tmp_n9au2yez:[Current thread is 1 (Thread 0x7f8a09eaa580 (LWP 387947))]
2023-09-06 00:27:07 INFO:tcp D:/builds/isc-projects/bind9/bin/tests/system/tcp_tmp_n9au2yez:#0 0x00007f8a0a4c3129 in pthread_barrier_wait@GLIBC_2.2.5 () from /lib64/libc.so.6
2023-09-06 00:27:07 INFO:tcp D:/builds/isc-projects/bind9/bin/tests/system/tcp_tmp_n9au2yez:#1 0x00007f8a0b2432a2 in stop_tcp_child_job (arg=0x7f8a09ab6800) at netmgr/tcp.c:589
2023-09-06 00:27:07 INFO:tcp D:/builds/isc-projects/bind9/bin/tests/system/tcp_tmp_n9au2yez:#2 0x00007f8a0b243372 in stop_tcp_child (sock=<optimized out>) at netmgr/tcp.c:597
2023-09-06 00:27:07 INFO:tcp D:/builds/isc-projects/bind9/bin/tests/system/tcp_tmp_n9au2yez:#3 0x00007f8a0b243b21 in isc__nm_tcp_stoplistening (sock=0x7f8a09a77800) at netmgr/tcp.c:622
2023-09-06 00:27:07 INFO:tcp D:/builds/isc-projects/bind9/bin/tests/system/tcp_tmp_n9au2yez:#4 0x00007f8a0b23b359 in isc_nm_stoplistening (sock=<optimized out>) at netmgr/netmgr.c:1699
2023-09-06 00:27:07 INFO:tcp D:/builds/isc-projects/bind9/bin/tests/system/tcp_tmp_n9au2yez:#5 0x00007f8a0b23dc62 in isc__nmsocket_stop (listener=0x7f8a09a76e00) at netmgr/netmgr.c:1730
2023-09-06 00:27:07 INFO:tcp D:/builds/isc-projects/bind9/bin/tests/system/tcp_tmp_n9au2yez:#6 0x00007f8a0b24183e in isc__nm_streamdns_stoplistening (sock=<optimized out>) at netmgr/streamdns.c:962
2023-09-06 00:27:07 INFO:tcp D:/builds/isc-projects/bind9/bin/tests/system/tcp_tmp_n9au2yez:#7 0x00007f8a0b23b360 in isc_nm_stoplistening (sock=<optimized out>) at netmgr/netmgr.c:1702
2023-09-06 00:27:07 INFO:tcp D:/builds/isc-projects/bind9/bin/tests/system/tcp_tmp_n9au2yez:#8 0x00007f8a0afcab27 in ns_interface_shutdown (ifp=ifp@entry=0x7f8a09ad7980) at interfacemgr.c:729
2023-09-06 00:27:07 INFO:tcp D:/builds/isc-projects/bind9/bin/tests/system/tcp_tmp_n9au2yez:#9 0x00007f8a0afcaf9a in purge_old_interfaces (mgr=mgr@entry=0x7f8a09a70500) at interfacemgr.c:815
2023-09-06 00:27:07 INFO:tcp D:/builds/isc-projects/bind9/bin/tests/system/tcp_tmp_n9au2yez:#10 0x00007f8a0afcb13e in ns_interfacemgr_shutdown (mgr=0x7f8a09a70500) at interfacemgr.c:435
2023-09-06 00:27:07 INFO:tcp D:/builds/isc-projects/bind9/bin/tests/system/tcp_tmp_n9au2yez:#11 0x0000000000445bf1 in shutdown_server (arg=0x7f8a09a9f700) at server.c:9983
2023-09-06 00:27:07 INFO:tcp D:/builds/isc-projects/bind9/bin/tests/system/tcp_tmp_n9au2yez:#12 0x00007f8a0b24b383 in isc__async_cb (handle=<optimized out>) at async.c:111
2023-09-06 00:27:07 INFO:tcp D:/builds/isc-projects/bind9/bin/tests/system/tcp_tmp_n9au2yez:#13 0x00007f8a0a977bd3 in ?? () from /lib64/libuv.so.1
2023-09-06 00:27:07 INFO:tcp D:/builds/isc-projects/bind9/bin/tests/system/tcp_tmp_n9au2yez:#14 0x00007f8a0a99457b in ?? () from /lib64/libuv.so.1
2023-09-06 00:27:07 INFO:tcp D:/builds/isc-projects/bind9/bin/tests/system/tcp_tmp_n9au2yez:#15 0x00007f8a0a97d097 in uv_run () from /lib64/libuv.so.1
2023-09-06 00:27:07 INFO:tcp D:/builds/isc-projects/bind9/bin/tests/system/tcp_tmp_n9au2yez:#16 0x00007f8a0b25d1ba in loop_thread (arg=arg@entry=0x7f8a09aac800) at loop.c:282
2023-09-06 00:27:07 INFO:tcp D:/builds/isc-projects/bind9/bin/tests/system/tcp_tmp_n9au2yez:#17 0x00007f8a0b26ca20 in thread_body (wrap=0xb788b0) at thread.c:85
2023-09-06 00:27:07 INFO:tcp D:/builds/isc-projects/bind9/bin/tests/system/tcp_tmp_n9au2yez:#18 0x00007f8a0b26ca99 in isc_thread_main (func=func@entry=0x7f8a0b25d12f <loop_thread>, arg=0x7f8a09aac800) at thread.c:116
2023-09-06 00:27:07 INFO:tcp D:/builds/isc-projects/bind9/bin/tests/system/tcp_tmp_n9au2yez:#19 0x00007f8a0b25e109 in isc_loopmgr_run (loopmgr=0x7f8a09a6f6c0) at loop.c:454
2023-09-06 00:27:07 INFO:tcp D:/builds/isc-projects/bind9/bin/tests/system/tcp_tmp_n9au2yez:#20 0x0000000000426faa in main (argc=16, argv=0x7fff1308dae8) at main.c:1592
2023-09-06 00:27:07 INFO:tcp D:tcp_tmp_n9au2yez:--------------------------------------------------------------------------------
```
```
06-Sep-2023 00:20:58.284 client @0x7f895a786800 10.53.0.1#53464 (isc.org): bad zone transfer request: 'isc.org/IN': non-authoritative zone (NOTAUTH)
06-Sep-2023 00:20:58.284 client @0x7f895a787400 10.53.0.1#53464 (isc.org): bad zone transfer request: 'isc.org/IN': non-authoritative zone (NOTAUTH)
06-Sep-2023 00:20:58.284 client @0x7f895a788000 10.53.0.1#53464 (isc.org): bad zone transfer request: 'isc.org/IN': non-authoritative zone (NOTAUTH)
06-Sep-2023 00:20:58.284 client @0x7f895a788c00 10.53.0.1#53464 (isc.org): bad zone transfer request: 'isc.org/IN': non-authoritative zone (NOTAUTH)
06-Sep-2023 00:20:58.284 client @0x7f895a789800 10.53.0.1#53464 (isc.org): bad zone transfer request: 'isc.org/IN': non-authoritative zone (NOTAUTH)
06-Sep-2023 00:20:58.284 client @0x7f895a78a400 10.53.0.1#53464 (isc.org): bad zone transfer request: 'isc.org/IN': non-authoritative zone (NOTAUTH)
06-Sep-2023 00:20:58.284 client @0x7f895a7a5000 10.53.0.1#53464 (isc.org): bad zone transfer request: 'isc.org/IN': non-authoritative zone (NOTAUTH)
06-Sep-2023 00:20:58.284 client @0x7f895a7a5c00 10.53.0.1#53464 (isc.org): bad zone transfer request: 'isc.org/IN': non-authoritative zone (NOTAUTH)
06-Sep-2023 00:20:58.284 netmgr 0x7f8a09a6f900: Shutting down network manager worker on loop 0x7f8a09aae180(3)
06-Sep-2023 00:20:58.284 netmgr 0x7f8a09a6f900: Shutting down network manager worker on loop 0x7f8a09aad900(2)
```
[core.387947-backtrace.txt](/uploads/dab4601f64759ee9475d504cac179df2/core.387947-backtrace.txt)
[named.run](/uploads/d5b292cffcbd202101133e28d131551b/named.run)
Locally, I can't reproduce it; `ns1` terminates at worst in 210 seconds.May 2024 (9.18.27, 9.18.27-S1, 9.19.24)https://gitlab.isc.org/isc-projects/bind9/-/issues/4104ZoneQuota stats counter is not counting everything2024-02-24T07:55:05ZOndřej SurýZoneQuota stats counter is not counting everythingThe `ZoneQuota` should log all the hits to `fcount_incr()` returning `ISC_R_QUOTA`, but it does only in a single place. The counting should be moved to `fctx_incr()`.The `ZoneQuota` should log all the hits to `fcount_incr()` returning `ISC_R_QUOTA`, but it does only in a single place. The counting should be moved to `fctx_incr()`.May 2024 (9.18.27, 9.18.27-S1, 9.19.24)Ondřej SurýOndřej Surýhttps://gitlab.isc.org/isc-projects/bind9/-/issues/3987Change DNSKEY TTL of inline-signed zone2024-02-24T07:55:08ZGerald VogtChange DNSKEY TTL of inline-signed zone### Description
I have a few zones using inline-signing which I have set up originally with 2d TTL. Due to this the existing DNSKEY RRs also have 2d TTL. Now I have been trying to reduce the TTL to 1d but it seems there is no supported ...### Description
I have a few zones using inline-signing which I have set up originally with 2d TTL. Due to this the existing DNSKEY RRs also have 2d TTL. Now I have been trying to reduce the TTL to 1d but it seems there is no supported way or tool to do so.
I have set dnskey-ttl to 1d and replace keys, still all DNSKEY RRs have 2d TTL. Setting it on the key with dnssec-settime doesn't help either and man pages specifically mention:
```
This option sets the default TTL to use for this key when it is converted into a DNSKEY RR.
This is the TTL used when the key is imported into a zone, unless there was already a DNSKEY
RRset in place, in which case the existing TTL takes precedence.
```
Running AlmaLinux 9 bind-9.16.23-5.el9_1.x86_64.
### Request
Add some way to change the TTL of DNSKEY RRs in inline-signed zones.
### Links / references
I have found a thread from 2016 about the same problem: https://www.mail-archive.com/bind-users@lists.isc.org/msg23186.htmlMay 2024 (9.18.27, 9.18.27-S1, 9.19.24)Matthijs Mekkingmatthijs@isc.orgMatthijs Mekkingmatthijs@isc.orghttps://gitlab.isc.org/isc-projects/bind9/-/issues/3472IPv4-only mode not respected for zone transfers2024-02-24T07:55:11ZThomas AmgartenIPv4-only mode not respected for zone transfers### Summary
Running BIND in IPv4-only-mode (```named -4```) and using a mirror zone (local root), then BIND tries to AXFR the root zone with IPv6 and reports failures about the unreachability:
```
27-Jul-2022 08:57:43.309 general: info:...### Summary
Running BIND in IPv4-only-mode (```named -4```) and using a mirror zone (local root), then BIND tries to AXFR the root zone with IPv6 and reports failures about the unreachability:
```
27-Jul-2022 08:57:43.309 general: info: zone ./IN: refresh: failure trying primary 2001:500:2::c#53 (source ::#0): operation canceled
27-Jul-2022 08:57:43.309 general: info: zone ./IN: refresh: failure trying primary 2001:500:2f::f#53 (source ::#0): operation canceled
27-Jul-2022 08:57:43.809 general: info: zone ./IN: refresh: failure trying primary 2001:500:12::d0d#53 (source ::#0): operation canceled
27-Jul-2022 08:57:43.809 general: info: zone ./IN: refresh: failure trying primary 2001:7fd::1#53 (source ::#0): operation canceled
27-Jul-2022 08:57:44.309 general: info: zone ./IN: refresh: failure trying primary 2620:0:2830:202::132#53 (source ::#0): operation canceled
27-Jul-2022 08:57:44.309 general: info: zone ./IN: refresh: failure trying primary 2620:0:2d0:202::132#53 (source ::#0): operation canceled
```
### BIND version used
```
$ named -V
BIND 9.18.5 (Stable Release) <id:6593103>
running on Linux x86_64 4.18.0-305.10.2.el8_4.x86_64 #1 SMP Tue Jul 20 20:34:55 UTC 2021
built by make with '--prefix=/usr/local/bind-9.18.5' '--sysconfdir=/opt/chroot/bind/etc/named/' '--mandir=/usr/local/share/man' '--localstatedir=/opt/chroot/bind/var' '--enable-largefile' '--enable-full-report' '--without-gssapi' '--with-json-c' '--enable-singletrace' 'PKG_CONFIG_PATH=:/usr/local/libuv/lib/pkgconfig/'
compiled by GCC 8.4.1 20200928 (Red Hat 8.4.1-1)
compiled with OpenSSL version: OpenSSL 1.1.1g FIPS 21 Apr 2020
linked to OpenSSL version: OpenSSL 1.1.1g FIPS 21 Apr 2020
compiled with libuv version: 1.41.1
linked to libuv version: 1.41.1
compiled with libnghttp2 version: 1.33.0
linked to libnghttp2 version: 1.33.0
compiled with json-c version: 0.13.1
linked to json-c version: 0.13.1
compiled with zlib version: 1.2.11
linked to zlib version: 1.2.11
threads support is enabled
default paths:
named configuration: /opt/chroot/bind/etc/named/named.conf
rndc configuration: /opt/chroot/bind/etc/named/rndc.conf
DNSSEC root key: /opt/chroot/bind/etc/named/bind.keys
nsupdate session key: /opt/chroot/bind/var/run/named/session.key
named PID file: /opt/chroot/bind/var/run/named/named.pid
named lock file: /opt/chroot/bind/var/run/named/named.lock
```
### Steps to reproduce
Create a mirror zone:
```
zone "." {
type mirror;
notify no;
};
```
Run BIND with IPv4-only:
```
$ /usr/local/bind/sbin/named -4 -t /opt/chroot/bind -u named -c /etc/named/named.conf
```
And now check the log for the IPv6 failure:
```
27-Jul-2022 09:18:59.148 general: info: zone ./IN: refresh: failure trying primary 2001:500:200::b#53 (source ::#0): operation canceled
27-Jul-2022 09:18:59.651 general: info: zone ./IN: refresh: failure trying primary 2001:500:2::c#53 (source ::#0): operation canceled
27-Jul-2022 09:18:59.651 general: info: zone ./IN: refresh: failure trying primary 2001:500:2f::f#53 (source ::#0): operation canceled
27-Jul-2022 09:19:00.151 general: info: zone ./IN: refresh: failure trying primary 2001:500:12::d0d#53 (source ::#0): operation canceled
27-Jul-2022 09:19:00.151 general: info: zone ./IN: refresh: failure trying primary 2001:7fd::1#53 (source ::#0): operation canceled
27-Jul-2022 09:19:00.651 general: info: zone ./IN: refresh: failure trying primary 2620:0:2830:202::132#53 (source ::#0): operation canceled
27-Jul-2022 09:19:00.651 general: info: zone ./IN: refresh: failure trying primary 2620:0:2d0:202::132#53 (source ::#0): operation canceled
```
### What is the current *bug* behavior?
BIND tries to AXFR the root zone over IPv6, although ```named``` is configured to run in IPv4-only-mode.
### What is the expected *correct* behavior?
Not trying to AXFR the mirror zone over IPv6.
### Relevant configuration files
### Relevant logs and/or screenshots
Failure in the log:
```
27-Jul-2022 09:11:18.990 general: info: zone ./IN: refresh: failure trying primary 2001:500:2::c#53 (source ::#0): operation canceled
27-Jul-2022 09:11:18.990 general: info: zone ./IN: refresh: failure trying primary 2001:500:2f::f#53 (source ::#0): operation canceled
27-Jul-2022 09:11:19.490 general: info: zone ./IN: refresh: failure trying primary 2001:500:12::d0d#53 (source ::#0): operation canceled
27-Jul-2022 09:11:19.490 general: info: zone ./IN: refresh: failure trying primary 2001:7fd::1#53 (source ::#0): operation canceled
27-Jul-2022 09:11:19.990 general: info: zone ./IN: refresh: failure trying primary 2620:0:2830:202::132#53 (source ::#0): operation canceled
27-Jul-2022 09:11:19.990 general: info: zone ./IN: refresh: failure trying primary 2620:0:2d0:202::132#53 (source ::#0): operation canceled
```
### Possible fixesMay 2024 (9.18.27, 9.18.27-S1, 9.19.24)Mark AndrewsMark Andrewshttps://gitlab.isc.org/isc-projects/bind9/-/issues/2744warning: checkhints: unable to get root NS rrset from cache: not found2024-03-27T00:34:35ZCathy Almondwarning: checkhints: unable to get root NS rrset from cache: not foundPeriodically we see reports of resolvers that are failing to respond to clients successfully, perhaps with a build-up of recursive clients, inbound UDP packet drops, late and missing query responses and so on. Rebooting the server entir...Periodically we see reports of resolvers that are failing to respond to clients successfully, perhaps with a build-up of recursive clients, inbound UDP packet drops, late and missing query responses and so on. Rebooting the server entirely usually fixes the problem - for a time. Flushing cache may also buy some relief, but generally this does not last as long as if the server is rebooted entirely.
Plus one symptom in the logs - repeated spates of messages like this:
```
31-May-2021 16:08:38.110 general: warning: checkhints: unable to get root NS rrset from cache: not found
31-May-2021 16:08:41.110 general: warning: checkhints: unable to get root NS rrset from cache: not found
31-May-2021 16:08:42.151 general: warning: checkhints: unable to get root NS rrset from cache: not found
```
This error message occurs when the root nameservers have just been primed, but when checkhints goes to look at them, they're no longer available in cache (have been expired, possible also removed), all in a very short period of time.
Reports of this have been seen intermittently for many years and from many versions of BIND 9. Typically (in the older reports) this was a rare occurrence seen on a resolver that had been running for a long time; months, possibly years. Therefore after rebooting, the error and the problem was never seen again (or at least not within the shelf-life of the admin who reported it to us originally).
We suspect that what is happening is that the cache structure and content have become unmaintainable over a long period of content being added, expired and removed, and that there it's become impossible to add new RRsets to cache without using expiring existing content because of max-cache-size. The cache tree structure itself also occupies memory, and we've seen a few instances where a long-lived cache has become 'straggly' but also sparsely populated.
What we haven't been able to catch (yet), is the exact path taken that causes this error to be logged, although we have been hoping that improved stats, along with a `catch it earlier` assertion (the server anyway needs to be restarted when it has reached this state) might help. See #2082 .
We have also seen that in one or two instances of this warning being logged, in addition there was a problem reaching some of the root nameserver addresses listed in the root hints and used for priming. Either the root hints were out of date and an older IP address was unreachable, or there were local routing issues (typically IPv6-related) reaching some root server addresses. **This shouldn't be a problem**, per the way that root hints priming is designed, _but 'fixing' the root hints appears to have made the problem go away in some instances, as has fixing the routing and unreachability of some root hint addresses._
----
For anyone experiencing this problem for the first time, the likelihood is that one or more things have changed in your operating environment, and that these are causing cache content to be more substantial than before, or potentially distributed differently. For example:
- Installing a version of BIND that has `stale-cache-enable yes` by default
- An increase in client queries overall
- Client query patterns changing - perhaps causing a higher rate than usual of cached negative responses
- An increase in dual-stack clients querying for AAAA records
- An increase in client querying for HTTPS records
- A new client application that uses DNS-based probing
- Clients using a tunnelling-over-DNS service
- Using a client filtering service that operates by means of resolving the original client query first by appending another private zone name to it and checking the response status before allowing the original query to pass - thus adding the filtering RRsets to cache as well as the actual client query responses.
Currently, clues may be found in the BIND statistics and also in a dump of cache.
Firstly, these counters (available either from the output from `rndc stats` or using the xml or json statistics interface), can be a good indicator that there is too much cache cleaning taking place due to memory pressure, versus RRset TTL expiration:
DeleteLRU - "cache records deleted due to memory exhaustion"
DeleteTTL - "cache records deleted due to TTL expiration"
These are counters, therefore although seeing DeleteLRU far exceeding DeleteTTL in a single snapshot of the stats is a good indicator that all is not well with cache, ideally you want to monitor the trend over time.
Also these :
HeapMemInUse - "cache heap memory in use"
TreeMemInUse - "cache tree memory in use"
HeapMemMax - "cache heap highest memory in use"
TreeMemMax - "cache tree highest memory in use"
All of the above are gauges - they tell you 'this is where we are now', so a snapshot can be useful, as well as monitoring pattern over time. The 'Max' is a high water mark.
Aside: don't be tempted to look at either of these - they are not useful operationally and aren't counting what you might think they are from their names:
HeapMemTotal - "cache heap memory total"
TreeMemTotal - "cache tree memory total"
And finally, there are counters available of what's in cache currrently by RType. These are prefixed with `!` for counters of NXRRSET (pseudo RR indicating that a name that was queried existed but the type didn't), `#` for stale content, and `~` for content that has expired and is waiting on housekeeping/deletion.
If there is any kind of unexpected skew, it might be worth dumping cache to see what's in there.
And then decide - is it just that max-cache-size is now insufficient, or is that something else needs to be done to reduce cache content.May 2024 (9.18.27, 9.18.27-S1, 9.19.24)Mark AndrewsMark Andrewshttps://gitlab.isc.org/isc-projects/bind9/-/issues/4592Improve the isc_heap resize algorithm2024-03-06T08:38:23ZOndřej SurýImprove the isc_heap resize algorithmThe current isc_heap resizing algorithm grows the array for holding the heap elements by 1024 (there's an argument to `isc_heap_create()`, but either default (1024) or explicit 1024 is used everywhere).The current isc_heap resizing algorithm grows the array for holding the heap elements by 1024 (there's an argument to `isc_heap_create()`, but either default (1024) or explicit 1024 is used everywhere).May 2024 (9.18.27, 9.18.27-S1, 9.19.24)https://gitlab.isc.org/isc-projects/bind9/-/issues/4564slightly worse cold cache performance after the KeyTrap fix2024-02-24T07:52:45ZTom Krizekslightly worse cold cache performance after the KeyTrap fixThe keytrap fix (merged in isc-private/bind9!628) has a significant impact on client query latency during startup (cold cache) as well as increased memory consumption. Using `recursive-clients 1000;` yielded quite similar results to `100...The keytrap fix (merged in isc-private/bind9!628) has a significant impact on client query latency during startup (cold cache) as well as increased memory consumption. Using `recursive-clients 1000;` yielded quite similar results to `10000` (which was used for most charts in here).
## Cold cache latency
### :question: 9.18 cold cache UDP
![keytrap-cold-cache-latency-9.18](/uploads/9953460d5a50fb571f18c21ece5f7415/keytrap-cold-cache-latency-9.18.png)
#### load 15x
| | before | after |
| ------ | ------ | ----- |
| responses <2.0s | 91 % | 79 % |
| responses <100ms | 88 % | 75 % |
#### load 10x
| | before | after |
| ------ | ------ | ----- |
| responses <2.0s | 96 % | 89 % |
| responses <100ms | 92 % | 85 % |
#### load 5x
| | before | after |
| ------ | ------ | ----- |
| responses <2.0s | 99 % | 98 % |
| responses <100ms | 93 % | 92 % |
### :question: 9.16 cold cache UDP
![keytrap-cold-cache-latency-9.16](/uploads/795943f2c6c6959c15f30c9f41597976/keytrap-cold-cache-latency-9.16.png)
### :white_check_mark: 9.19 cold cache UDP
the impact for ~"v9.19" is quite minimal and I don't consider it an issue
![keytrap-cold-cache-latency-9.19](/uploads/d86be8aeb8170b8e596bd85666937a81/keytrap-cold-cache-latency-9.19.png)
### :question: 9.18 cold cache TCP
The performance drop can also be observed with TCP with much lower overall throughput.
![keytrap-hot-cache-latency-tcp-9.18](/uploads/b581e94d77c5c1cdc9e143fdfff3bac2/keytrap-hot-cache-latency-tcp-9.18.png)
## :white_check_mark: Hot cache latency
The good news is that it doesn't really affect performance with hot cache.
![keytrap-hot-cache-latency-9.18](/uploads/e1704c0c853dc5b6ab798e1821b4a7db/keytrap-hot-cache-latency-9.18.png)
## Memory consumption
### :question: 9.18 memory consumption UDP
The initial memory consumption also gets slightly higher:
![keytrap-memory-9.18](/uploads/7d89b5dbc594c64c57802e11418c03b6/keytrap-memory-9.18.png)
### :white_check_mark: 9.18 memory consumption TCP
While the memory consumption is slightly higher for TCP under load, I think this can be explained by the fact that some queries take longer time to resolve -> some connections might be open for a longer time, thus consume more resources than before.
![keytrap-memory-tcp-9.18](/uploads/88be13f12e69bb69fc7f6d917dc21e6f/keytrap-memory-tcp-9.18.png)May 2024 (9.18.27, 9.18.27-S1, 9.19.24)https://gitlab.isc.org/isc-projects/bind9/-/issues/4422No supported algorithms on platform2024-02-29T15:26:01ZMark AndrewsNo supported algorithms on platformJob [#3783240](https://gitlab.isc.org/isc-projects/bind9/-/jobs/3783240) failed for 5d20a7ce254dabe1d4a99f7bd0fd1cfa6309124b:
```
$ PYTHON="$(source bin/tests/system/conf.sh; echo $PYTHON)"
Traceback (most recent call last):
File "/bu...Job [#3783240](https://gitlab.isc.org/isc-projects/bind9/-/jobs/3783240) failed for 5d20a7ce254dabe1d4a99f7bd0fd1cfa6309124b:
```
$ PYTHON="$(source bin/tests/system/conf.sh; echo $PYTHON)"
Traceback (most recent call last):
File "/builds/isc-projects/bind9/bin/tests/system/get_algorithms.py", line 241, in <module>
main()
File "/builds/isc-projects/bind9/bin/tests/system/get_algorithms.py", line 227, in main
algs = filter_supported(algs)
^^^^^^^^^^^^^^^^^^^^^^
File "/builds/isc-projects/bind9/bin/tests/system/get_algorithms.py", line 138, in filter_supported
raise RuntimeError(
RuntimeError: no DEFAULT algorithm from "stable" set supported on this platform
$
```May 2024 (9.18.27, 9.18.27-S1, 9.19.24)Tom KrizekTom Krizekhttps://gitlab.isc.org/isc-projects/bind9/-/issues/4345Debug messages logging network traffic only include the address of one peer2024-02-24T08:19:42ZMichał KępieńDebug messages logging network traffic only include the address of one peerEven with `-d 99` used on the command line, `named` only logs lines
like:
28-Sep-2023 14:31:23.212 sending packet to 2001:503:ba3e::2:30#53
or:
28-Sep-2023 14:31:23.232 received packet from 2001:503:ba3e::2:30#53
However, net...Even with `-d 99` used on the command line, `named` only logs lines
like:
28-Sep-2023 14:31:23.212 sending packet to 2001:503:ba3e::2:30#53
or:
28-Sep-2023 14:31:23.232 received packet from 2001:503:ba3e::2:30#53
However, network traffic is always sent **from** one socket **to**
another. The currently available debug messages do not include the
sender's address (first example) or the receiver's address (second
example). As a result, just bumping up the log level is often not
enough to diagnose certain issues and a network traffic sniffer has to
be used in order to learn the details of the packets being exchanged.
This lack of detail sometimes also makes debugging system test issues
harder than it has to be. With multiple tests being run in parallel,
knowing the exact addresses and ports that were used by each running
`named` instance is crucial for determining whether a test failure was
caused by an unexpected interaction between tests or not. (Such issues
happened more than once in the past, particularly when network code
and/or the system test framework were being worked on.)
Debug messages logging network traffic should be extended to include
information about both sides of each communication channel.
While this issue is technically only tangential to #4344, having
detailed network-level information available would greatly improve the
benefits of the feature proposed here.May 2024 (9.18.27, 9.18.27-S1, 9.19.24)Michał KępieńMichał Kępieńhttps://gitlab.isc.org/isc-projects/bind9/-/issues/4344Enable extraction of exact local socket addresses2024-02-24T08:19:47ZMichał KępieńEnable extraction of exact local socket addressesThe Network Manager API is currently unable to expose the exact
address/port that a local wildcard/TCP socket is bound to. This limits
the level of detail available to all sorts of traffic-logging code
(debug messages, dnstap, etc.)
Th...The Network Manager API is currently unable to expose the exact
address/port that a local wildcard/TCP socket is bound to. This limits
the level of detail available to all sorts of traffic-logging code
(debug messages, dnstap, etc.)
This has been previously discussed (in dnstap context) in #3143. Back
then, it quickly [emerged][1] that extracting the exact address that a
local wildcard/TCP socket is bound to requires issuing a system call.
Unfortunately, the function that would be responsible for doing this is
[called on a hot path][2]. After running some performance tests, it
[became obvious][3] that doing that unconditionally is a non-starter
performance-wise. The proposal was scrapped and replaced with a [note
in documentation](!6472).
However, the problem persists and limits the capabilities of not just
dnstap, but also logging code. In some cases, more detailed logging is
preferred over raw performance and there should be some way for the user
to express their preference in that regard.
[1]: https://gitlab.isc.org/isc-projects/bind9/-/merge_requests/5816#note_272336
[2]: https://gitlab.isc.org/isc-projects/bind9/-/merge_requests/5816#note_272404
[3]: https://gitlab.isc.org/isc-projects/bind9/-/merge_requests/5816#note_272407May 2024 (9.18.27, 9.18.27-S1, 9.19.24)Michał KępieńMichał Kępień