BIND issueshttps://gitlab.isc.org/isc-projects/bind9/-/issues2024-03-21T15:29:09Zhttps://gitlab.isc.org/isc-projects/bind9/-/issues/4247Autosign resigning too fast after dnssec-settime calls2024-03-21T15:29:09ZMark AndrewsAutosign resigning too fast after dnssec-settime callsJob [#3570991](https://gitlab.isc.org/isc-projects/bind9/-/jobs/3570991) failed for ce1db0017ee498c3c9e0d632b83113a344d25dda:
I've seen autosign fail in the ZSK roll test several times and it appears to be because dnssec-signzone is bei...Job [#3570991](https://gitlab.isc.org/isc-projects/bind9/-/jobs/3570991) failed for ce1db0017ee498c3c9e0d632b83113a344d25dda:
I've seen autosign fail in the ZSK roll test several times and it appears to be because dnssec-signzone is being called in the same second as dnssec-settime. dnssec-signzone uses the phase `is set and is in the past` as the determinant of when things change. Should this be made `is set and is now or in the past`? Which behaviour is consistent with named's behaviour? Which behaviour is less error prone? If we don't change the behaviour we need to add sleeps to ensure the tests succeed.
```
-S This option enables smart signing, which instructs dnssec-signzone to search the key repository for keys that match the zone
being signed, and to include them in the zone if appropriate.
When a key is found, its timing metadata is examined to determine how it should be used, according to the following rules.
Each successive rule takes priority over the prior ones:
If no timing metadata has been set for the key, the key is published in the zone and used to sign the zone.
If the key's publication date is set and is in the past, the key is published in the zone.
If the key's activation date is set and is in the past, the key is published (regardless of publication date) and used to
sign the zone.
If the key's revocation date is set and is in the past, and the key is published, then the key is revoked, and the revoked
key is used to sign the zone.
If either the key's unpublication or deletion date is set and in the past, the key is NOT published or used to sign the
zone, regardless of any other metadata.
If the key's sync publication date is set and is in the past, synchronization records (type CDS and/or CDNSKEY) are
created.
If the key's sync deletion date is set and is in the past, synchronization records (type CDS and/or CDNSKEY) are removed.
```
```
2023-08-08 00:59:52 INFO:autosign I:autosign_tmp_x_6wkr8z:preparing ZSK roll
2023-08-08 00:59:52 INFO:autosign I:autosign_tmp_x_6wkr8z:ns1 A zone reload and thaw was started.
2023-08-08 00:59:52 INFO:autosign I:autosign_tmp_x_6wkr8z:ns1 Check the logs to see the result.
2023-08-08 00:59:56 INFO:autosign I:autosign_tmp_x_6wkr8z:revoking key to duplicated key ID
2023-08-08 00:59:56 INFO:autosign dnssec-settime: warning: Permissions on the file ns2/Kbar.+013+59973.private have changed from 0644 to 0600 as a result of this operation.
2023-08-08 00:59:56 INFO:autosign I:autosign_tmp_x_6wkr8z:ns2 A zone reload and thaw was started.
2023-08-08 00:59:56 INFO:autosign I:autosign_tmp_x_6wkr8z:ns2 Check the logs to see the result.
2023-08-08 00:59:56 INFO:autosign I:autosign_tmp_x_6wkr8z:waiting for changes to take effect
2023-08-08 01:00:01 INFO:autosign I:autosign_tmp_x_6wkr8z:checking former standby key 5259 is now active (53)
2023-08-08 01:00:01 INFO:autosign I:autosign_tmp_x_6wkr8z:failed
```
```
echo_i "preparing ZSK roll"
starttime=$($PERL -e 'print time(), "\n";')
oldfile=$(cat active.key)
oldid=$(keyfile_to_key_id "$(cat active.key)")
newfile=$(cat standby.key)
newid=$(keyfile_to_key_id "$(cat standby.key)")
$SETTIME -K ns1 -I now -D now+25 $oldfile > settime.out.test$n.1 || ret=1
$SETTIME -K ns1 -i 0 -S $oldfile $newfile > settime.out.test$n.2 || ret=1
# note previous zone serial number
oldserial=$($DIG $DIGOPTS +short soa . @10.53.0.1 | awk '{print $3}')
($RNDCCMD 10.53.0.1 freeze . 2>&1 | sed 's/^/ns1 /' | cat_i) || ret=1
cp ns1/root.db.signed ns1/root.db.1
$SIGNER -S -o . -O full -K ns1 -f ns1/root.db.signed ns1/root.db.1 > signing.root.out$n 2>&1 || ret=1
($RNDCCMD 10.53.0.1 thaw . 2>&1 | sed 's/^/ns1 /' | cat_i) || ret=1
sleep 4
echo_i "revoking key to duplicated key ID"
$SETTIME -R now -K ns2 Kbar.+013+59973.key > settime.out.test$n.3 || ret=1
($RNDCCMD 10.53.0.2 freeze bar. 2>&1 | sed 's/^/ns2 /' | cat_i) || ret=1
cp ns2/bar.db.signed ns2/bar.db
$SIGNER -S -o bar. -O full -K ns2 ns2/bar.db > signing.bar.out$n 2>&1 || ret=1
($RNDCCMD 10.53.0.2 thaw bar. 2>&1 | sed 's/^/ns2 /' | cat_i) || ret=1
echo_i "waiting for changes to take effect"
sleep 5
echo_i "checking former standby key $newid is now active ($n)"
ret=0
$DIG $DIGOPTS dnskey . @10.53.0.1 > dig.out.ns1.test$n || ret=1
grep 'RRSIG.*'" $newid "'\. ' dig.out.ns1.test$n > /dev/null || ret=1
n=$((n + 1))
if [ $ret != 0 ]; then echo_i "failed"; fi
status=$((status + ret))
```
```
08-Aug-2023 00:59:52.469 allocate new control connection
08-Aug-2023 00:59:52.469 received control channel command 'freeze .'
08-Aug-2023 00:59:52.469 loop exclusive mode: starting
08-Aug-2023 00:59:52.469 loop exclusive mode: started
08-Aug-2023 00:59:52.469 zone_dump: zone ./IN: enter
08-Aug-2023 00:59:52.469 loop exclusive mode: ending
08-Aug-2023 00:59:52.469 loop exclusive mode: ended
08-Aug-2023 00:59:52.469 freezing zone './IN': success
08-Aug-2023 00:59:52.469 freeing control connection
08-Aug-2023 00:59:52.497 dump_done: zone ./IN: enter
08-Aug-2023 00:59:52.497 zone_journal_compact: zone ./IN: target journal size 7662
08-Aug-2023 00:59:52.497 zone ./IN: dns_journal_compact: success
08-Aug-2023 00:59:52.509 allocate new control connection
08-Aug-2023 00:59:52.509 received control channel command 'thaw .'
08-Aug-2023 00:59:52.509 loop exclusive mode: starting
08-Aug-2023 00:59:52.509 loop exclusive mode: started
08-Aug-2023 00:59:52.509 zone ./IN: starting load
08-Aug-2023 00:59:52.509 zone_startload: zone ./IN: enter
08-Aug-2023 00:59:52.509 loop exclusive mode: ending
08-Aug-2023 00:59:52.509 loop exclusive mode: ended
08-Aug-2023 00:59:52.509 thawing zone './IN': success
08-Aug-2023 00:59:52.509 freeing control connection
08-Aug-2023 00:59:52.509 zone_loaddone: zone ./IN: enter
08-Aug-2023 00:59:52.509 zone ./IN: number of nodes in database: 5
08-Aug-2023 00:59:52.509 zone ./IN: loaded; checking validity
08-Aug-2023 00:59:52.509 dns_zone_verifydb: zone ./IN: enter
08-Aug-2023 00:59:52.509 zone ./IN: zone serial (2000042101) unchanged. zone may fail to transfer to secondaries.
08-Aug-2023 00:59:52.509 zone ./IN: replacing zone database
08-Aug-2023 00:59:52.509 calling free_rbtdb(.)
08-Aug-2023 00:59:52.509 done free_rbtdb(.)
08-Aug-2023 00:59:52.509 zone ./IN: loaded serial 2000042101 (DNSSEC signed)
08-Aug-2023 00:59:52.509 zone_postload: zone ./IN: done
08-Aug-2023 00:59:52.509 zone__settimer: zone ./IN: enter
```April 2024 (9.16.50, 9.16.50-S1, 9.18.26, 9.18.26-S1, 9.19.23)https://gitlab.isc.org/isc-projects/bind9/-/issues/1565"autosign" system test still fails occasionally due to apparent randomness is...2024-03-21T15:29:42ZMichał Kępień"autosign" system test still fails occasionally due to apparent randomness issuesThe `autosign` system test still [fails occasionally][1] due to the number of daily categories into which signature expiration times are divided is not high enough (4, which is less than the required minimum of 5):
```
I:autosign:checki...The `autosign` system test still [fails occasionally][1] due to the number of daily categories into which signature expiration times are divided is not high enough (4, which is less than the required minimum of 5):
```
I:autosign:checking expired signatures were jittered correctly (13)
I:autosign:404 20200121
I:autosign:202 20200123
I:autosign:599 20200124
I:autosign:405 20200125
I:autosign:error: not enough categories
I:autosign:failed
```
We should investigate our options here to prevent this test from failing as it is happening too often to just gloss over it. Assuming nothing is wrong with the implementation itself (or the test code checking the number of categories), we should either further lower the minimum required number of categories or ignore this issue completely - otherwise we are going to develop a bad reflex of ignoring all failures of this test.
[1]: https://gitlab.isc.org/isc-private/bind9/-/jobs/572751April 2024 (9.16.50, 9.16.50-S1, 9.18.26, 9.18.26-S1, 9.19.23)https://gitlab.isc.org/isc-projects/bind9/-/issues/4628CID 487827: Control flow issues (DEADCODE) in lib/dns/qp-zonedb.c2024-03-11T18:39:47ZMichal NowakCID 487827: Control flow issues (DEADCODE) in lib/dns/qp-zonedb.cCoverity Scan claims dead code in `lib/dns/qp-zonedb.c` (#4411).
```
/lib/dns/qp-zonedb.c: 1600 in loadnode()
1594 * just now getting an NSEC record.
1595 */
1596 if (node->nsec == DNS_DB_NSEC_HAS_NSEC) {
1597 ...Coverity Scan claims dead code in `lib/dns/qp-zonedb.c` (#4411).
```
/lib/dns/qp-zonedb.c: 1600 in loadnode()
1594 * just now getting an NSEC record.
1595 */
1596 if (node->nsec == DNS_DB_NSEC_HAS_NSEC) {
1597 goto done;
1598 }
1599 } else {
>>> CID 487827: Control flow issues (DEADCODE)
>>> Execution cannot reach this statement: "goto done;".
1600 goto done;
1601 }
1602
1603 if (!hasnsec) {
1604 goto done;
1605 }
```March 2024 (9.16.49, 9.16.49-S1, 9.18.25, 9.18.25-S1, 9.19.22)Matthijs Mekkingmatthijs@isc.orgMatthijs Mekkingmatthijs@isc.orghttps://gitlab.isc.org/isc-projects/bind9/-/issues/4625Broken trust chain on corner case secure chain2024-03-12T10:11:00ZMatthijs Mekkingmatthijs@isc.orgBroken trust chain on corner case secure chain### Summary
Consider the following chain:
```
parent. DS 1
parent. DS 2
parent. DS 3
parent. RRSIG(DS)
example.parent. DNSKEY 257 id=1
example.parent. DNSKEY 257 id=2
example.parent. DNSKEY 256 id=99
example.parent. RRSIG(DNSKEY) id=1...### Summary
Consider the following chain:
```
parent. DS 1
parent. DS 2
parent. DS 3
parent. RRSIG(DS)
example.parent. DNSKEY 257 id=1
example.parent. DNSKEY 257 id=2
example.parent. DNSKEY 256 id=99
example.parent. RRSIG(DNSKEY) id=1
```
This delegation will result in a broken trust chain, despite there is a secure chain via DNSKEY with id=1. There are also broken chains (DS 3 has no corresponding DNSKEY, DNSKEY with id=2 is not signing).
This works in 9.19.20, but no longer in 9.19.21. Could it be the KeyTrap fix in 9.21 that is causing this?
Older versions (9.18, 9.16) are not affected.
### BIND version affected
9.19.21
### Steps to reproduce
To do.
### What is the current *bug* behavior?
Broken trust chain.
### What is the expected *correct* behavior?
Secure answer.
### Relevant configuration files
Default empty config.
### Relevant logs
To do.March 2024 (9.16.49, 9.16.49-S1, 9.18.25, 9.18.25-S1, 9.19.22)Matthijs Mekkingmatthijs@isc.orgMatthijs Mekkingmatthijs@isc.orghttps://gitlab.isc.org/isc-projects/bind9/-/issues/4623dns_db_setloop at wrong place in cache_create_db2024-03-08T11:48:33ZMark Andrewsdns_db_setloop at wrong place in cache_create_dbdns_db_setloop should only be called if the database creation succeeds.dns_db_setloop should only be called if the database creation succeeds.March 2024 (9.16.49, 9.16.49-S1, 9.18.25, 9.18.25-S1, 9.19.22)https://gitlab.isc.org/isc-projects/bind9/-/issues/4621rndc flush make cache pruning no-op2024-03-08T11:44:42ZOndřej Surýrndc flush make cache pruning no-opWhen `rndc flush` (e.g. `dns_cache_flush()`) is called, the task is not set for the rbtdb which makes the cache pruning basically no-op, piling up the parent nodes that could not be sweeped together with the child nodes.When `rndc flush` (e.g. `dns_cache_flush()`) is called, the task is not set for the rbtdb which makes the cache pruning basically no-op, piling up the parent nodes that could not be sweeped together with the child nodes.March 2024 (9.16.49, 9.16.49-S1, 9.18.25, 9.18.25-S1, 9.19.22)https://gitlab.isc.org/isc-projects/bind9/-/issues/4613Release Checklist for BIND 9.16.49, 9.16.49-S1, 9.18.25, 9.18.25-S1, 9.19.222024-03-27T21:12:56ZPetr Špačekpspacek@isc.orgRelease Checklist for BIND 9.16.49, 9.16.49-S1, 9.18.25, 9.18.25-S1, 9.19.22## Release Schedule
**Code Freeze:** Wednesday, 6 March 2024
**Tagging Deadline:** Monday, 11 March 2024
**Public Release:** Wednesday, 20 March 2024
## Warning
This release uses non-standard process. It is based on February releas...## Release Schedule
**Code Freeze:** Wednesday, 6 March 2024
**Tagging Deadline:** Monday, 11 March 2024
**Public Release:** Wednesday, 20 March 2024
## Warning
This release uses non-standard process. It is based on February releases (9.16.48, 9.18.24, 9.19.21) and adds cherry-picked MRs on top.
## Documentation Review Links
**Closed issues assigned to the milestone without a release note:**
- [9.16.49](https://gitlab.isc.org/isc-projects/bind9/-/issues?scope=all&sort=created_asc&state=closed&milestone_title=March+2024+%289.16.49%2C+9.16.49-S1%2C+9.18.25%2C+9.18.25-S1%2C+9.19.22%29¬%5Blabel_name%5D%5B%5D=Release+Notes¬%5Blabel_name%5D%5B%5D=Duplicate&label_name%5B%5D=v9.16)
- [9.16.49-S1](https://gitlab.isc.org/isc-projects/bind9/-/issues?scope=all&sort=created_asc&state=closed&milestone_title=March+2024+%289.16.49%2C+9.16.49-S1%2C+9.18.25%2C+9.18.25-S1%2C+9.19.22%29¬%5Blabel_name%5D%5B%5D=Release+Notes¬%5Blabel_name%5D%5B%5D=Duplicate&label_name%5B%5D=v9.16-S)
- [9.18.25](https://gitlab.isc.org/isc-projects/bind9/-/issues?scope=all&sort=created_asc&state=closed&milestone_title=March+2024+%289.16.49%2C+9.16.49-S1%2C+9.18.25%2C+9.18.25-S1%2C+9.19.22%29¬%5Blabel_name%5D%5B%5D=Release+Notes¬%5Blabel_name%5D%5B%5D=Duplicate&label_name%5B%5D=v9.18)
- [9.18.25-S1](https://gitlab.isc.org/isc-projects/bind9/-/issues?scope=all&sort=created_asc&state=closed&milestone_title=March+2024+%289.16.49%2C+9.16.49-S1%2C+9.18.25%2C+9.18.25-S1%2C+9.19.22%29¬%5Blabel_name%5D%5B%5D=Release+Notes¬%5Blabel_name%5D%5B%5D=Duplicate&label_name%5B%5D=v9.18-S)
- [9.19.22](https://gitlab.isc.org/isc-projects/bind9/-/issues?scope=all&sort=created_asc&state=closed&milestone_title=March+2024+%289.16.49%2C+9.16.49-S1%2C+9.18.25%2C+9.18.25-S1%2C+9.19.22%29¬%5Blabel_name%5D%5B%5D=Release+Notes¬%5Blabel_name%5D%5B%5D=Duplicate&label_name%5B%5D=v9.19)
**Merge requests merged into the milestone without a release note:**
- [9.16.49](https://gitlab.isc.org/isc-projects/bind9/-/merge_requests?scope=all&sort=merged_at&state=merged&milestone_title=March+2024+%289.16.49%2C+9.16.49-S1%2C+9.18.25%2C+9.18.25-S1%2C+9.19.22%29¬%5Blabel_name%5D%5B%5D=Release+Notes&target_branch=bind-9.16)
- [9.16.49-S1](https://gitlab.isc.org/isc-private/bind9/-/merge_requests?scope=all&sort=merged_at&state=merged&milestone_title=March+2024+%289.16.49%2C+9.16.49-S1%2C+9.18.25%2C+9.18.25-S1%2C+9.19.22%29¬%5Blabel_name%5D%5B%5D=Release+Notes&target_branch=bind-9.16-sub)
- [9.18.25](https://gitlab.isc.org/isc-projects/bind9/-/merge_requests?scope=all&sort=merged_at&state=merged&milestone_title=March+2024+%289.16.49%2C+9.16.49-S1%2C+9.18.25%2C+9.18.25-S1%2C+9.19.22%29¬%5Blabel_name%5D%5B%5D=Release+Notes&target_branch=bind-9.18)
- [9.18.25-S1](https://gitlab.isc.org/isc-private/bind9/-/merge_requests?scope=all&sort=merged_at&state=merged&milestone_title=March+2024+%289.16.49%2C+9.16.49-S1%2C+9.18.25%2C+9.18.25-S1%2C+9.19.22%29¬%5Blabel_name%5D%5B%5D=Release+Notes&target_branch=bind-9.18-sub)
- [9.19.22](https://gitlab.isc.org/isc-projects/bind9/-/merge_requests?scope=all&sort=merged_at&state=merged&milestone_title=March+2024+%289.16.49%2C+9.16.49-S1%2C+9.18.25%2C+9.18.25-S1%2C+9.19.22%29¬%5Blabel_name%5D%5B%5D=Release+Notes&target_branch=main)
**Merge requests merged into the milestone without a `CHANGES` entry:**
- [9.16.49](https://gitlab.isc.org/isc-projects/bind9/-/merge_requests?scope=all&sort=merged_at&state=merged&milestone_title=March+2024+%289.16.49%2C+9.16.49-S1%2C+9.18.25%2C+9.18.25-S1%2C+9.19.22%29&label_name%5B%5D=No+CHANGES&target_branch=bind-9.16)
- [9.16.49-S1](https://gitlab.isc.org/isc-private/bind9/-/merge_requests?scope=all&sort=merged_at&state=merged&milestone_title=March+2024+%289.16.49%2C+9.16.49-S1%2C+9.18.25%2C+9.18.25-S1%2C+9.19.22%29&label_name%5B%5D=No+CHANGES&target_branch=bind-9.16-sub)
- [9.18.25](https://gitlab.isc.org/isc-projects/bind9/-/merge_requests?scope=all&sort=merged_at&state=merged&milestone_title=March+2024+%289.16.49%2C+9.16.49-S1%2C+9.18.25%2C+9.18.25-S1%2C+9.19.22%29&label_name%5B%5D=No+CHANGES&target_branch=bind-9.18)
- [9.18.25-S1](https://gitlab.isc.org/isc-private/bind9/-/merge_requests?scope=all&sort=merged_at&state=merged&milestone_title=March+2024+%289.16.49%2C+9.16.49-S1%2C+9.18.25%2C+9.18.25-S1%2C+9.19.22%29&label_name%5B%5D=No+CHANGES&target_branch=bind-9.18-sub)
- [9.19.22](https://gitlab.isc.org/isc-projects/bind9/-/merge_requests?scope=all&sort=merged_at&state=merged&milestone_title=March+2024+%289.16.49%2C+9.16.49-S1%2C+9.18.25%2C+9.18.25-S1%2C+9.19.22%29&label_name%5B%5D=No+CHANGES&target_branch=main)
## Release Checklist
### Before the Code Freeze
- [x] ***(QA)*** Rebase -S editions on top of current open-source versions: `git checkout bind-9.18-sub && git rebase origin/bind-9.18`
- [x] ***(QA)*** [Inform](https://gitlab.isc.org/isc-private/bind-qa/-/blob/master/bind9/releng/inform_supp_marketing.py) Support and Marketing of impending release (and give estimated release dates).
- [x] ***(QA)*** Ensure there are no permanent test failures on any platform. Check [public](https://gitlab.isc.org/isc-projects/bind9/-/pipelines?scope=all&source=schedule) and [private](https://gitlab.isc.org/isc-private/bind9/-/pipelines?scope=all&source=schedule) scheduled pipelines.
- [x] ***(QA)*** Check charts from `shotgun:*` jobs in the scheduled pipelines to verify there is no unexplained performance drop for any protocol.
- [x] ***(QA)*** Check [Perflab](https://perflab.isc.org/) to ensure there has been no unexplained drop in performance for the versions being released.
- [x] ***(QA)*** Check whether all issues assigned to the release milestone are resolved[^1].
- [x] ***(QA)*** Ensure that there are no outstanding [merge requests in the private repository](https://gitlab.isc.org/isc-private/bind9/-/merge_requests/)[^1] (Subscription Edition only).
- [x] ***(QA)*** [Ensure](https://gitlab.isc.org/isc-private/bind-qa/-/blob/master/bind9/releng/check_backports.py) all merge requests marked for backporting have been indeed backported.
- [x] ***(QA)*** ~~[Announce](https://gitlab.isc.org/isc-private/bind-qa/-/blob/master/bind9/releng/inform_code_freeze.py) (on Mattermost) that the code freeze is in effect.~~
### Before the Tagging Deadline
- [x] ***(QA)*** Inspect the current output of the `cross-version-config-tests` job to verify that no unexpected backward-incompatible change was introduced in the current release cycle.
- [x] ***(QA)*** Ensure release notes are correct, ask Support and Marketing to check them as well. [Example](https://gitlab.isc.org/isc-private/bind9/-/merge_requests/510)
- [x] ***(QA)*** Add a release marker to `CHANGES`. Examples: [9.18](https://gitlab.isc.org/isc-projects/bind9/-/commit/f14d8ad78c0506fd4247187f2177f8eceeb6b3b9), [9.16](https://gitlab.isc.org/isc-projects/bind9/-/commit/1bcdf21874f99a00da389d723e0ad07dfd70f9f1)
- [x] ***(QA)*** Add a release marker to `CHANGES.SE` (Subscription Edition only). [Example](https://gitlab.isc.org/isc-private/bind9/-/commit/0f03d5737bcbdaa1bf713c6db1887b14938c3421)
- [x] ***(QA)*** Update BIND 9 version in `configure.ac` ([9.18+](https://gitlab.isc.org/isc-projects/bind9/-/commit/3c85ab7f4c35e6d8acef1393606002a0a8730100)) or `version` ([9.16](https://gitlab.isc.org/isc-projects/bind9/-/merge_requests/7692/diffs?commit_id=1bcdf21874f99a00da389d723e0ad07dfd70f9f1)).
- [x] ***(QA)*** Rebuild `configure` using Autoconf on `docs.isc.org` (9.16).
- [x] ***(QA)*** ~~Update GitLab settings for all maintained branches to disallow merging to them: [public](https://gitlab.isc.org/isc-projects/bind9/-/settings/repository), [private](https://gitlab.isc.org/isc-private/bind9/-/settings/repository)~~
- [x] ***(QA)*** Tag the releases in the private repository (`git tag -s -m "BIND 9.x.y" v9.x.y`).
### Before the ASN Deadline (for ASN Releases) or the Public Release Date (for Regular Releases)
- [x] ***(QA)*** Check that the formatting is correct for the HTML version of release notes.
- [x] ***(QA)*** Check that the formatting of the generated man pages is correct.
- [x] ***(QA)*** Verify GitLab CI results [for the tags](https://gitlab.isc.org/isc-private/bind9/-/pipelines?scope=tags) created and sign off on the releases to be published.
- [x] ***(QA)*** ~~Update GitLab settings for all maintained branches to allow merging to them again: [public](https://gitlab.isc.org/isc-projects/bind9/-/settings/repository), [private](https://gitlab.isc.org/isc-private/bind9/-/settings/repository)~~
- [x] ***(QA)*** Prepare (using [`version_bump.py`](https://gitlab.isc.org/isc-private/bind-qa/-/blob/master/bind9/releng/version_bump.py)) and merge MRs resetting the release notes and updating the version string for [each](!8856) [maintained](!8857) [branch](!8858).
- [x] ***(QA)*** Rebase the Subscription Edition branches (including recent release prep commits) on top of the open source branches with updated version strings.
- [x] ***(QA)*** [Announce (on Mattermost) that the code freeze is over.](https://mattermost.isc.org/isc/pl/8chqbcam7igq5nu8ryxtrjfq4r)
- [x] ***(QA)*** [Request signatures for the tarballs, providing their location and checksums. Ask signers on Mattermost.](https://mattermost.isc.org/isc/pl/ku6mfsqaktrq3ryz4iuth8183c)
- [x] ***(Signers)*** Ensure that the contents of tarballs and tags are identical.
- [x] ***(Signers)*** Validate tarball checksums, sign tarballs, and upload signatures.
- [x] ***(QA)*** Verify tarball signatures and check tarball checksums again: Run `publish_bind.sh` on repo.isc.org to pre-publish.
- [x] ***(QA)*** ~~Prepare the `patches/` subdirectory for each security release (if applicable).~~
- [x] ***(QA)*** Pre-publish ASN and/or Subscription Edition tarballs so that packages can be built.
- [x] ***(QA)*** Build and test ASN and/or Subscription Edition packages (in [cloudsmith branch in private repo](https://gitlab.isc.org/isc-private/rpms/bind/-/tree/cloudsmith)). [Example](https://gitlab.isc.org/isc-private/rpms/bind/-/commit/e2512f4cfaf991827a635e374e7e93b27a5f38ba)
- [x] ***(Marketing)*** ~~Prepare and send out ASN emails (as outlined in the CVE checklist; if applicable).~~
### On the Day of Public Release
- [x] ***(QA)*** ~~Wait for clearance from Security Officer to proceed with the public release (if applicable).~~
- [x] ***(QA)*** Place tarballs in public location on FTP site.
- [x] ***(QA)*** Inform Marketing of the release, providing FTP links for the published tarballs.
- [x] ***(QA)*** [Use the Printing Press project to prepare a release announcement email.](isc-private/printing-press!103)
- [x] ***(Marketing)*** Publish links to downloads on ISC website. [Example](https://gitlab.isc.org/website/theme-staging-site/-/commit/1ac7b30b73cb03228df4cd5651fa4e774ac35625)
- [x] ***(Marketing)*** Update the BIND -S information document in SF with download links to the new versions. (If this is a security release, this will have already been done as part of the ASN process.)
- [x] ***(Marketing)*** Update the Current Software Versions document in the SF portal if any stable versions were released.
- [x] ***(Marketing)*** Send the release announcement email to the *bind-announce* mailing list (and to *bind-users* if a major release - [example](https://lists.isc.org/pipermail/bind-users/2022-January/105624.html)).
- [x] ***(Marketing)*** Announce release on social media sites.
- [x] ***(Marketing)*** Update [Wikipedia entry for BIND](https://en.wikipedia.org/wiki/BIND).
- [x] ***(Support)*** Add the new releases to the [vulnerability matrix in the Knowledge Base](https://kb.isc.org/docs/aa-00913).
- [x] ***(Support)*** Update tickets in case of waiting support customers.
- [x] ***(QA)*** Build and test any outstanding private packages in [private repo](https://gitlab.isc.org/isc-private/rpms/bind/-/tree/cloudsmith). [Example](https://gitlab.isc.org/isc-private/rpms/bind/-/commit/2007d566db81dd9dfd79e571e2f600a3bc284da4)
- [x] ***(QA)*** Build [public RPMs](https://gitlab.isc.org/isc-packages/rpms/bind). [Example commit](https://gitlab.isc.org/isc-packages/rpms/bind/-/commit/3b5e851ea7c4e3570371a4878b5461f02a44f8cc) which triggers [Copr builds](https://copr.fedorainfracloud.org/coprs/isc/) automatically
- [x] ***(SwEng)*** Build Debian/Ubuntu packages.
- [x] ***(SwEng)*** Update Docker files [here](https://gitlab.isc.org/isc-projects/bind9-docker/-/branches) and make sure push is synchronized to [GitHub](https://github.com/isc-projects/bind9-docker). [Docker Hub](https://hub.docker.com/r/internetsystemsconsortium/bind9) should pick it up automatically. [Example](https://gitlab.isc.org/isc-projects/bind9-docker/-/commit/cada7e10e9af951595c98bfffc4bd42512faac05)
- [x] ***(QA)*** Ensure all new tags are annotated and signed. `git show --show-signature v9.19.12`
- [x] ***(QA)*** Push tags for the published releases to the public repository.
- [x] ***(QA)*** Using [`merge_tag.py`](https://gitlab.isc.org/isc-private/bind-qa/-/blob/master/bind9/releng/merge_tag.py), merge published release tags back into the their relevant development/maintenance branches.
- [x] ***(QA)*** ~~Ensure `allow_failure: true` is removed from the `cross-version-config-tests` job if it was set during the current release cycle.~~
- [x] ***(QA)*** Sanitize confidential issues which are assigned to the current release milestone and do not describe a security vulnerability, then make them public.
- [x] ***(QA)*** Sanitize [confidential issues](https://gitlab.isc.org/isc-projects/bind9/-/issues/?sort=milestone_due_desc&state=opened&confidential=yes) which are assigned to older release milestones and describe security vulnerabilities, then make them public if appropriate[^2].
- [x] ***(QA)*** [Update QA tools used in GitLab CI (e.g. Black, PyLint, Sphinx) by modifying the relevant `Dockerfile`.](isc-projects/images!305)
- [x] ***(QA)*** [Run a pipeline to rebuild all images used in GitLab CI.](https://gitlab.isc.org/isc-projects/images/-/pipelines/168133)
- [x] ***(QA)*** [Update `metadata.json` with the upcoming release information.](isc-private/bind-qa!96)
[^1]: If not, use the time remaining until the tagging deadline to ensure all outstanding issues are either resolved or moved to a different milestone.
[^2]: As a rule of thumb, security vulnerabilities which have reproducers merged to the public repository are considered okay for full disclosure.March 2024 (9.16.49, 9.16.49-S1, 9.18.25, 9.18.25-S1, 9.19.22)Michał KępieńMichał Kępieńhttps://gitlab.isc.org/isc-projects/bind9/-/issues/4612resolver crashes on 10-0-0-38.abcdefghijklmnopqrstuvwxyz012345.plex.direct DS...2024-03-06T00:16:14ZPetr Špačekpspacek@isc.orgresolver crashes on 10-0-0-38.abcdefghijklmnopqrstuvwxyz012345.plex.direct DS query### Summary
Processing query `10-0-0-38.abcdefghijklmnopqrstuvwxyz012345.plex.direct DS` causes the resolver to crash.
### BIND version affected
* ~"Affects v9.19": 88c56e25a1e6c0c994f38a5db4c6b6f677ec633a
It seems it does NOT affect ...### Summary
Processing query `10-0-0-38.abcdefghijklmnopqrstuvwxyz012345.plex.direct DS` causes the resolver to crash.
### BIND version affected
* ~"Affects v9.19": 88c56e25a1e6c0c994f38a5db4c6b6f677ec633a
It seems it does NOT affect stable branches.
### Steps to reproduce
1. `named -g -c /dev/null`
2. `dig @127.0.0.1 10-0-0-38.abcdefghijklmnopqrstuvwxyz012345.plex.direct DS`
3. :boom:
### What is the current *bug* behavior?
```
28-Feb-2024 14:35:04.363 chase DS servers resolving '10-0-0-38.abcdefghijklmnopqrstuvwxyz012345.plex.direct/DS/IN': 18.202.136.15#53
28-Feb-2024 14:35:04.466 resolver.c:10427: REQUIRE(!dns_rdataset_isassociated(rdataset)) failed
```
### What is the expected *correct* behavior?
No crash.
### Relevant logs
- [Debug -d 99 log](/uploads/7aeca53fc41d38c9c9cbfa8dac8b3475/log)March 2024 (9.16.49, 9.16.49-S1, 9.18.25, 9.18.25-S1, 9.19.22)https://gitlab.isc.org/isc-projects/bind9/-/issues/4604Fix initial tests in masterfile system test2024-03-08T11:12:54ZMark AndrewsFix initial tests in masterfile system testAll three of the initial tests should have a known good output to test against.
The BIND 8 tests should be testing against ttl1.
There should be independent failure reporting for the first three tests.All three of the initial tests should have a known good output to test against.
The BIND 8 tests should be testing against ttl1.
There should be independent failure reporting for the first three tests.March 2024 (9.16.49, 9.16.49-S1, 9.18.25, 9.18.25-S1, 9.19.22)https://gitlab.isc.org/isc-projects/bind9/-/issues/4600autosign system test hung in cross-version-config-tests CI job2024-03-08T11:25:56ZMichal Nowakautosign system test hung in cross-version-config-tests CI jobJob [#4058605](https://gitlab.isc.org/isc-projects/bind9/-/jobs/4058605) failed for e5a98f14bf3203cf803fcc6bd9f3ff03a2b4a8f7 (CI artifacts were saved).
The `autosign` system test hung for 5 minutes on shutdown in [the `cross-version-con...Job [#4058605](https://gitlab.isc.org/isc-projects/bind9/-/jobs/4058605) failed for e5a98f14bf3203cf803fcc6bd9f3ff03a2b4a8f7 (CI artifacts were saved).
The `autosign` system test hung for 5 minutes on shutdown in [the `cross-version-config-tests` CI job](https://gitlab.isc.org/isc-projects/bind9/-/jobs/4058605). I see this for the second time in two days, and I think this is something new and will persist.
This CI job is unique compared to other system test CI jobs: it just starts and stops BIND servers to check that `named.conf` breakages introduced since the previous point release are not present. We had a problem in this scenario before: https://gitlab.isc.org/isc-projects/bind9/-/issues/4213.
```
23-Feb-2024 00:10:42.106 adjust_quantum: old=100, new=137
23-Feb-2024 00:10:42.106 calling free_rbtdb(.)
23-Feb-2024 00:10:42.106 done free_rbtdb(.)
23-Feb-2024 00:10:42.106 done free_rbtdb(oldsigs.example)
23-Feb-2024 00:10:42.106 done free_rbtdb(jitter.nsec3.example)
```
```
2024-02-23 00:18:18 INFO:autosign D:Core was generated by `/builds/isc-projects/bind9/bin/named/.libs/named -D autosign_tmp_7ktl_4p5-ns3 -'.
2024-02-23 00:18:18 INFO:autosign D:Program terminated with signal SIGABRT, Aborted.
2024-02-23 00:18:18 INFO:autosign D:#0 0x00007f5df3ae9b9e in __GI_epoll_pwait (epfd=4, events=0x7ffe9b1a8be0, maxevents=1024, timeout=-1, set=0x0) at ../sysdeps/unix/sysv/linux/epoll_pwait.c:40
2024-02-23 00:18:18 INFO:autosign D:Download failed: Invalid argument. Continuing without source file ./misc/../sysdeps/unix/sysv/linux/epoll_pwait.c.
2024-02-23 00:18:18 INFO:autosign D:[Current thread is 1 (Thread 0x7f5df1217500 (LWP 52959))]
2024-02-23 00:18:18 INFO:autosign D:#0 0x00007f5df3ae9b9e in __GI_epoll_pwait (epfd=4, events=0x7ffe9b1a8be0, maxevents=1024, timeout=-1, set=0x0) at ../sysdeps/unix/sysv/linux/epoll_pwait.c:40
2024-02-23 00:18:18 INFO:autosign D:#1 0x00007f5df3ece522 in uv__io_poll (loop=0x7f5df0e53020, timeout=-1) at /usr/src/libuv-v1.47.0/src/unix/linux.c:1430
2024-02-23 00:18:18 INFO:autosign D:#2 0x00007f5df3eb3e20 in uv_run (loop=0x7f5df0e53020, mode=UV_RUN_DEFAULT) at /usr/src/libuv-v1.47.0/src/unix/core.c:447
2024-02-23 00:18:18 INFO:autosign D:#3 0x00007f5df46b0324 in loop_thread (arg=arg@entry=0x7f5df0e53000) at loop.c:284
2024-02-23 00:18:18 INFO:autosign D:#4 0x00007f5df46c1af1 in thread_body (wrap=0x7f5df0ee7420) at thread.c:85
2024-02-23 00:18:18 INFO:autosign D:#5 0x00007f5df46c1b6a in isc_thread_main (func=func@entry=0x7f5df46b0299 <loop_thread>, arg=0x7f5df0e53000) at thread.c:116
2024-02-23 00:18:18 INFO:autosign D:#6 0x00007f5df46b12c4 in isc_loopmgr_run (loopmgr=0x7f5df0e20a80) at loop.c:456
2024-02-23 00:18:18 INFO:autosign D:#7 0x000055ad3d813480 in main (argc=<optimized out>, argv=<optimized out>) at main.c:1574
```
[core.52959-backtrace.txt](/uploads/3594340469e8638ccfe6192044d7174a/core.52959-backtrace.txt)
[named.run](/uploads/9ff12f3ada8161d465dd0498f6dd7722/named.run)March 2024 (9.16.49, 9.16.49-S1, 9.18.25, 9.18.25-S1, 9.19.22)https://gitlab.isc.org/isc-projects/bind9/-/issues/4597Potential race condition in TTL heap introduced by February 2024 BIND release...2024-03-07T22:29:41ZCathy AlmondPotential race condition in TTL heap introduced by February 2024 BIND release patchesReported to us by an OEM customer who integrates BIND into their own appliance and redistributes:
> In rbtdb.c, there's a call path expirenodeall()->expire_headerlist()->set_ttl()->isc_heap_increased() or isc_heap_decreased(), where a s...Reported to us by an OEM customer who integrates BIND into their own appliance and redistributes:
> In rbtdb.c, there's a call path expirenodeall()->expire_headerlist()->set_ttl()->isc_heap_increased() or isc_heap_decreased(), where a shared TTL heap (per node lock bucket) is modified. Previously, this path is protected by the node write lock, but it's now unprotected, so there can be a race on the heap with, e.g, another thread adding a cache entry to the cache (thus to the TTL heap). expirenodeall() is called via dns_db_expirenodeall(), which is indirectly used for "rndc dumpdb" or "dumpdb flushname/flushtree". So it may be possible, though I've not tried it myself, that invoking these rndc commands results in a crash on a busy recursive server.
>
> It's basically the same for other cases: expirenode() and delete_callback(), although in the latter case the protected data is different. Also, we've found that there's probably no code path to these functions in practice, so it's not a big deal.March 2024 (9.16.49, 9.16.49-S1, 9.18.25, 9.18.25-S1, 9.19.22)Ondřej SurýOndřej Surýhttps://gitlab.isc.org/isc-projects/bind9/-/issues/4596Regression in cache cleaning2024-03-08T11:20:36ZOndřej SurýRegression in cache cleaningThere's an regression introduced in the fix to #4383 that causes the cache memory to clean too slow, so busy resolvers can run out of configured cache memory by not cleaning expired (TTL-expired) records to be not cleaned from the memory...There's an regression introduced in the fix to #4383 that causes the cache memory to clean too slow, so busy resolvers can run out of configured cache memory by not cleaning expired (TTL-expired) records to be not cleaned from the memory fast enough.March 2024 (9.16.49, 9.16.49-S1, 9.18.25, 9.18.25-S1, 9.19.22)Ondřej SurýOndřej Surýhttps://gitlab.isc.org/isc-projects/bind9/-/issues/4595Regression in change for CVE-2023-5680 that can cause named to crash2024-03-08T11:03:30ZCathy AlmondRegression in change for CVE-2023-5680 that can cause named to crashReported to us by an OEM customer who integrates BIND into their own appliance and redistributes:
> NOTE: you might find this as a security issue.
>
> We believe we've identified the likely cause of the crash. It's a regression due to ...Reported to us by an OEM customer who integrates BIND into their own appliance and redistributes:
> NOTE: you might find this as a security issue.
>
> We believe we've identified the likely cause of the crash. It's a regression due to the change for CVE-2023-5680. I've added a patch to a unit test for BIND 9.18.24-S1 that can reproduce the crash. I confirmed the crash happened for 9.18.24-S1 and 9.16.48-S1. One straightforward fix is the other patch I've attached to this ticket.
>
> I believe an engineer familiar with the code base can understand how it happens by reading the patch (it has a lot of comments explaining it), so I won't repeat it here. But I'd note one thing: the introduction of the "old IP tree" breaks one critical assumption: when a node's last reference is released, the cleanup makes sure that there is no rdatasetheader that would still have to be cleaned up (such as an expired cache entry). With this, and the fact that whenerver an rdatasetheader makes a node dirty either a node (read or rw) lock is acquired or a node's reference is increased from 0, it was previously guaranteed that overmem purge never frees other entries that the purge code may reference later. Now that the basic assumption is broken, we now have this crash, and there might be other such cases.
>
> I've not tried to reproduce a crash using a `named` executable, but the unit test indicates it's probably possible to trigger the crash by an external attacker, albeit with some high barriers such as being listed as an "ecs-zone" in the named's configuration. You may want to deal with this case as such.March 2024 (9.16.49, 9.16.49-S1, 9.18.25, 9.18.25-S1, 9.19.22)https://gitlab.isc.org/isc-projects/bind9/-/issues/4591TTL-based cache cleaning in rbtdb ineffective (M/N problem)2024-03-20T13:50:45ZOndřej SurýTTL-based cache cleaning in rbtdb ineffective (M/N problem)Copying stuff from MatterMost for permanent record:
How it started?
> @ondrej: But I don't know actually - if there's something blocking the top of the heap to be cleaned up (dunno why yet), it could block cleaning everything else behin...Copying stuff from MatterMost for permanent record:
How it started?
> @ondrej: But I don't know actually - if there's something blocking the top of the heap to be cleaned up (dunno why yet), it could block cleaning everything else behind it
So, here's a summary of our finding
The TTL based cleaning is opportunistic. When we are inserting a new node, we look at the top of the heap ("list sorted by TTL-value") and if TTL of the top of the heap is expired, we try to eradicate the data it stores from the cache. The code that decides whether we will do the TTL-based cleaning looks like this:
```c
header = isc_heap_element(rbtdb->heaps[rbtnode->locknum], 1);
if (header != NULL) {
dns_ttl_t rdh_ttl = header->rdh_ttl;
/* Only account for stale TTL if cache is not overmem */
if (!cache_is_overmem) {
rdh_ttl += STALE_TTL(header, rbtdb);
}
if (rdh_ttl < now - RBTDB_VIRTUAL) {
expire_header(rbtdb, header, tree_locked,
expire_ttl);
}
}
```
Now, the RBTDB_VIRTUAL is this:
```
/*
* Allow clients with a virtual time of up to 5 minutes in the past to see
* records that would have otherwise have expired.
*/
#define RBTDB_VIRTUAL 300
```
Which means that even with 0 TTL records, the TTL-based cleaning will not kick-in until 5 minutes has passed.
Now what happens if you insert N records (where N could be large) within the first 5 minutes (cold bootstrap)?
After 5 minutes the TTL based cleaning should kick-in, but that's only if everything in the cache has expired, but even with that.
If we insert M records in the next minute, only M records will gets cleaned at maximum.
But anything that has longer TTL will just add to N, so the backlog of the records that are not subject to the TTL-based cleaning will build up over time until we are overmem and LRU based cleaning kicks in.
Additionally, @ondrej found out that there are records with `rdh_ttl` set to `0` if you just run `dnsperf` on a cold cache resolver, which made us puzzled - shouldn't we be cleaning records only after 5 minutes?
@michal did some excellent work and found out following:
so, i looked at those "zero TTL" frees that happen very shortly into the start of regular resolver operation
turns out that these are "superseded" headers
now, i don't understand why RBTDB does that. but it's this branch in add32() that expires these headers: https://gitlab.isc.org/isc-projects/bind9/-/blob/8fb49c5a8acdb37d4f4be0c5f5b19645d0103f48/lib/dns/rbtdb.c#L6677-6714
basically, AFAICT, what happens here is:
resolver: hey, RBTDB, add this shiny new SOA rdataset header to the cache
RBTDB: oh okay, let me see if i have a SOA header on that node already...
RBTDB: yup, got one. i'll just expire the one i had in there before (topheader) and insert the new one you gave me (newheader).
what i don't understand is why it just doesn't leave that old (identical, AFAICT) rdataset intact. but i'll move on with the reasoning for now.
so, the "previously-topmost" SOA header has its TTL set to zero, so it lands on the top of one of the TTL heaps
once we add a new rdataset, it should be cleaned up. but, as we already established yesterday, that only happens if the reference count of its node is zero.
meanwhile, in my very basic test (literally seconds into firing up dnsperf with the query set we use for respdiff tests, at some 1 kQPS), those rdatasets at the top of the heap are for nodes like net. or com. whose reference counts are around 60, or maybe 80 references. and until that count goes to zero, the first rdataset on the TTL heap will not disappear from there, blocking any rdataset headers on the same TTL heap from being cleaned up as well (backlog)
so, i thought "how bad is it and can we measure it?" and oh, boy, he could:
```
20-Feb-2024 10:46:29.561 connection refused resolving 'geo.fortinet.net/NS/IN': 104.198.248.186#53
20-Feb-2024 10:46:29.564 DNS format error from 203.205.195.75#53 resolving ns3.qq.com/AAAA for <unknown>: Name qq.com (SOA) not subdomain of zone ns3.qq.com -- invalid response
20-Feb-2024 10:46:29.564 FORMERR resolving 'ns3.qq.com/AAAA/IN': 203.205.195.75#53
20-Feb-2024 10:46:29.564 DNS format error from 108.136.87.44#53 resolving api.cloud.huawei.com/AAAA for 127.0.0.1#34840: Name huawei.com (SOA) not subdomain of zone cloud.huawei.com -- invalid response
20-Feb-2024 10:46:29.564 FORMERR resolving 'api.cloud.huawei.com/AAAA/IN': 108.136.87.44#53
-- 0 msecs since expiry
-- 0 msecs since expiry
-- 106 msecs since expiry
-- 106 msecs since expiry
-- 29 msecs since expiry
-- 29 msecs since expiry
20-Feb-2024 10:46:29.574 success resolving 'a.karma.sc2.fsapi.com/A' after disabling qname minimization due to 'ncache nxdomain'
-- 243 msecs since expiry
-- 246 msecs since expiry
-- 249 msecs since expiry
-- 433 msecs since expiry
-- 806 msecs since expiry
-- 813 msecs since expiry
-- 243 msecs since expiry
-- 246 msecs since expiry
-- 249 msecs since expiry
-- 433 msecs since expiry
-- 806 msecs since expiry
-- 0 msecs since expiry
-- 816 msecs since expiry
-- 816 msecs since expiry
-- 123 msecs since expiry
-- 323 msecs since expiry
-- 123 msecs since expiry
-- 323 msecs since expiry
20-Feb-2024 10:46:29.601 success resolving 'F00DCFRIBM41.zf.if.atcsg.net/A' after disabling qname minimization due to 'ncache nxdomain'
20-Feb-2024 10:46:29.624 REFUSED unexpected RCODE resolving 'cloud.Jensen.com.cn/NS/IN': 47.118.199.194#53
-- 0 msecs since expiry
-- 0 msecs since expiry
20-Feb-2024 10:46:29.677 DNS format error from 3.97.163.50#53 resolving api.cloud.huawei.com/AAAA for 127.0.0.1#34840: Name huawei.com (SOA) not subdomain of zone cloud.huawei.com -- invalid response
20-Feb-2024 10:46:29.677 FORMERR resolving 'api.cloud.huawei.com/AAAA/IN': 3.97.163.50#53
-- 6 msecs since expiry
-- 3 msecs since expiry
-- 9 msecs since expiry
-- 0 msecs since expiry
20-Feb-2024 10:46:29.801 REFUSED unexpected RCODE resolving 'cloud.Jensen.com.cn/NS/IN': 39.96.153.33#53
-- 3 msecs since expiry
-- 3 msecs since expiry
-- 46 msecs since expiry
-- 19 msecs since expiry
-- 0 msecs since expiry
-- 39 msecs since expiry
-- 0 msecs since expiry
-- 0 msecs since expiry
-- 3 msecs since expiry
-- 3 msecs since expiry
-- 126 msecs since expiry
-- 0 msecs since expiry
-- 0 msecs since expiry
-- 0 msecs since expiry
20-Feb-2024 10:46:30.104 REFUSED unexpected RCODE resolving 'cloud.Jensen.com.cn/NS/IN': 139.224.142.104#53
-- 286 msecs since expiry
-- 0 msecs since expiry
-- 69 msecs since expiry
-- 13 msecs since expiry
20-Feb-2024 10:46:30.307 success resolving 'hcdnd.csfw.c.cdnhwc6.com/AAAA' after disabling qname minimization due to 'ncache nxdomain'
-- 0 msecs since expiry
-- 199 msecs since expiry
-- 269 msecs since expiry
-- 656 msecs since expiry
-- 689 msecs since expiry
-- 746 msecs since expiry
-- 789 msecs since expiry
-- 816 msecs since expiry
-- 819 msecs since expiry
-- 819 msecs since expiry
-- 839 msecs since expiry
-- 853 msecs since expiry
-- 873 msecs since expiry
-- 876 msecs since expiry
-- 889 msecs since expiry
-- 896 msecs since expiry
-- 896 msecs since expiry
-- 916 msecs since expiry
-- 936 msecs since expiry
-- 956 msecs since expiry
-- 969 msecs since expiry
-- 979 msecs since expiry
-- 983 msecs since expiry
-- 999 msecs since expiry
-- 999 msecs since expiry
-- 1006 msecs since expiry
-- 1006 msecs since expiry
-- 1053 msecs since expiry
-- 1053 msecs since expiry
-- 1063 msecs since expiry
-- 1066 msecs since expiry
-- 1073 msecs since expiry
-- 1079 msecs since expiry
-- 1083 msecs since expiry
-- 1089 msecs since expiry
-- 1096 msecs since expiry
-- 1133 msecs since expiry
-- 1139 msecs since expiry
-- 1156 msecs since expiry
-- 1163 msecs since expiry
-- 1166 msecs since expiry
-- 1179 msecs since expiry
-- 1183 msecs since expiry
-- 1189 msecs since expiry
-- 1193 msecs since expiry
-- 1196 msecs since expiry
-- 1199 msecs since expiry
-- 1223 msecs since expiry
-- 1223 msecs since expiry
-- 1249 msecs since expiry
-- 1259 msecs since expiry
-- 1276 msecs since expiry
-- 1293 msecs since expiry
-- 1336 msecs since expiry
-- 1363 msecs since expiry
-- 1369 msecs since expiry
-- 1379 msecs since expiry
-- 1393 msecs since expiry
-- 1396 msecs since expiry
-- 1399 msecs since expiry
-- 1403 msecs since expiry
-- 1423 msecs since expiry
-- 1429 msecs since expiry
-- 1436 msecs since expiry
-- 1436 msecs since expiry
-- 1439 msecs since expiry
-- 1446 msecs since expiry
-- 1446 msecs since expiry
-- 1466 msecs since expiry
-- 1466 msecs since expiry
-- 1469 msecs since expiry
-- 1473 msecs since expiry
-- 1486 msecs since expiry
-- 1503 msecs since expiry
-- 1506 msecs since expiry
-- 1516 msecs since expiry
-- 1539 msecs since expiry
-- 1539 msecs since expiry
-- 1556 msecs since expiry
-- 1566 msecs since expiry
-- 1569 msecs since expiry
-- 1589 msecs since expiry
-- 1623 msecs since expiry
-- 1623 msecs since expiry
-- 1629 msecs since expiry
-- 1636 msecs since expiry
-- 1636 msecs since expiry
-- 1649 msecs since expiry
-- 1679 msecs since expiry
-- 1686 msecs since expiry
-- 1703 msecs since expiry
-- 1703 msecs since expiry
-- 1716 msecs since expiry
-- 1726 msecs since expiry
-- 1736 msecs since expiry
-- 1773 msecs since expiry
-- 1796 msecs since expiry
-- 1796 msecs since expiry
-- 1799 msecs since expiry
-- 1803 msecs since expiry
-- 1829 msecs since expiry
-- 1839 msecs since expiry
-- 1876 msecs since expiry
-- 1879 msecs since expiry
-- 1883 msecs since expiry
-- 1889 msecs since expiry
-- 1889 msecs since expiry
-- 1889 msecs since expiry
-- 1899 msecs since expiry
-- 1946 msecs since expiry
-- 1956 msecs since expiry
-- 1983 msecs since expiry
-- 2013 msecs since expiry
-- 2013 msecs since expiry
-- 2023 msecs since expiry
-- 2049 msecs since expiry
-- 2059 msecs since expiry
-- 2063 msecs since expiry
-- 2079 msecs since expiry
-- 2106 msecs since expiry
-- 2109 msecs since expiry
-- 2119 msecs since expiry
-- 2136 msecs since expiry
-- 2156 msecs since expiry
-- 2183 msecs since expiry
-- 2199 msecs since expiry
-- 2203 msecs since expiry
-- 2219 msecs since expiry
-- 2223 msecs since expiry
-- 2229 msecs since expiry
-- 2243 msecs since expiry
-- 2253 msecs since expiry
-- 2263 msecs since expiry
-- 2286 msecs since expiry
-- 2303 msecs since expiry
-- 2343 msecs since expiry
-- 2356 msecs since expiry
-- 2376 msecs since expiry
-- 2376 msecs since expiry
-- 2379 msecs since expiry
-- 2386 msecs since expiry
-- 2416 msecs since expiry
-- 2426 msecs since expiry
-- 2433 msecs since expiry
-- 2449 msecs since expiry
-- 2466 msecs since expiry
-- 2479 msecs since expiry
-- 2509 msecs since expiry
-- 2516 msecs since expiry
-- 2523 msecs since expiry
-- 2529 msecs since expiry
-- 2536 msecs since expiry
-- 2539 msecs since expiry
-- 2539 msecs since expiry
-- 2543 msecs since expiry
-- 2553 msecs since expiry
-- 2559 msecs since expiry
-- 2569 msecs since expiry
-- 2593 msecs since expiry
-- 2609 msecs since expiry
-- 2616 msecs since expiry
-- 2623 msecs since expiry
-- 2629 msecs since expiry
-- 2656 msecs since expiry
-- 2659 msecs since expiry
-- 2673 msecs since expiry
-- 2716 msecs since expiry
-- 2766 msecs since expiry
-- 2773 msecs since expiry
-- 2773 msecs since expiry
-- 2776 msecs since expiry
-- 2783 msecs since expiry
-- 2789 msecs since expiry
-- 2823 msecs since expiry
-- 2843 msecs since expiry
-- 2879 msecs since expiry
-- 2879 msecs since expiry
-- 2886 msecs since expiry
-- 2899 msecs since expiry
-- 2919 msecs since expiry
-- 2926 msecs since expiry
-- 2949 msecs since expiry
-- 2956 msecs since expiry
-- 2956 msecs since expiry
-- 2956 msecs since expiry
-- 2979 msecs since expiry
-- 2983 msecs since expiry
-- 2983 msecs since expiry
-- 2986 msecs since expiry
-- 3033 msecs since expiry
-- 3039 msecs since expiry
-- 3049 msecs since expiry
-- 3066 msecs since expiry
-- 3086 msecs since expiry
-- 3126 msecs since expiry
-- 3129 msecs since expiry
-- 3156 msecs since expiry
-- 3169 msecs since expiry
-- 3173 msecs since expiry
-- 3176 msecs since expiry
-- 3226 msecs since expiry
-- 3253 msecs since expiry
-- 3266 msecs since expiry
-- 3269 msecs since expiry
-- 3279 msecs since expiry
-- 3279 msecs since expiry
-- 3299 msecs since expiry
-- 3323 msecs since expiry
-- 3323 msecs since expiry
-- 3336 msecs since expiry
-- 3336 msecs since expiry
-- 3363 msecs since expiry
-- 3366 msecs since expiry
-- 3396 msecs since expiry
-- 3399 msecs since expiry
-- 3409 msecs since expiry
-- 3449 msecs since expiry
-- 3463 msecs since expiry
-- 3466 msecs since expiry
-- 3499 msecs since expiry
-- 0 msecs since expiry
-- 199 msecs since expiry
-- 269 msecs since expiry
-- 656 msecs since expiry
-- 689 msecs since expiry
-- 746 msecs since expiry
-- 789 msecs since expiry
-- 816 msecs since expiry
-- 819 msecs since expiry
-- 819 msecs since expiry
-- 839 msecs since expiry
-- 853 msecs since expiry
-- 873 msecs since expiry
-- 876 msecs since expiry
-- 889 msecs since expiry
-- 896 msecs since expiry
-- 896 msecs since expiry
-- 916 msecs since expiry
-- 936 msecs since expiry
-- 956 msecs since expiry
-- 969 msecs since expiry
-- 979 msecs since expiry
-- 983 msecs since expiry
-- 999 msecs since expiry
-- 999 msecs since expiry
-- 1006 msecs since expiry
-- 1006 msecs since expiry
-- 1053 msecs since expiry
-- 1053 msecs since expiry
-- 1063 msecs since expiry
-- 1066 msecs since expiry
-- 1073 msecs since expiry
-- 1079 msecs since expiry
-- 1083 msecs since expiry
-- 1089 msecs since expiry
-- 1096 msecs since expiry
-- 1133 msecs since expiry
-- 1139 msecs since expiry
-- 1156 msecs since expiry
-- 1163 msecs since expiry
-- 1166 msecs since expiry
-- 1179 msecs since expiry
-- 1183 msecs since expiry
-- 1189 msecs since expiry
-- 1196 msecs since expiry
-- 1199 msecs since expiry
-- 1203 msecs since expiry
-- 1226 msecs since expiry
-- 1226 msecs since expiry
-- 1253 msecs since expiry
-- 1263 msecs since expiry
-- 1279 msecs since expiry
-- 1296 msecs since expiry
-- 1339 msecs since expiry
-- 1366 msecs since expiry
-- 1373 msecs since expiry
-- 1383 msecs since expiry
-- 1396 msecs since expiry
-- 1399 msecs since expiry
-- 1403 msecs since expiry
-- 1406 msecs since expiry
-- 1426 msecs since expiry
-- 1433 msecs since expiry
-- 1439 msecs since expiry
-- 1439 msecs since expiry
-- 1443 msecs since expiry
-- 1449 msecs since expiry
-- 1449 msecs since expiry
-- 1469 msecs since expiry
-- 1469 msecs since expiry
-- 1473 msecs since expiry
-- 1476 msecs since expiry
-- 1489 msecs since expiry
-- 1506 msecs since expiry
-- 1509 msecs since expiry
-- 1519 msecs since expiry
-- 1543 msecs since expiry
-- 1543 msecs since expiry
-- 1559 msecs since expiry
-- 1569 msecs since expiry
-- 1573 msecs since expiry
-- 1593 msecs since expiry
-- 1626 msecs since expiry
-- 1626 msecs since expiry
-- 1633 msecs since expiry
-- 1639 msecs since expiry
-- 1639 msecs since expiry
-- 1653 msecs since expiry
-- 1683 msecs since expiry
-- 1689 msecs since expiry
-- 1706 msecs since expiry
-- 1706 msecs since expiry
-- 1719 msecs since expiry
-- 1729 msecs since expiry
-- 1739 msecs since expiry
-- 1776 msecs since expiry
-- 1799 msecs since expiry
-- 1799 msecs since expiry
-- 1803 msecs since expiry
-- 1806 msecs since expiry
-- 1833 msecs since expiry
-- 1843 msecs since expiry
-- 1879 msecs since expiry
-- 1883 msecs since expiry
-- 1886 msecs since expiry
-- 1893 msecs since expiry
-- 1893 msecs since expiry
-- 1893 msecs since expiry
-- 1903 msecs since expiry
-- 1949 msecs since expiry
-- 1959 msecs since expiry
-- 1986 msecs since expiry
-- 2016 msecs since expiry
-- 2016 msecs since expiry
-- 2026 msecs since expiry
-- 2053 msecs since expiry
-- 2063 msecs since expiry
-- 2066 msecs since expiry
-- 2083 msecs since expiry
-- 2109 msecs since expiry
-- 2113 msecs since expiry
-- 2123 msecs since expiry
-- 2139 msecs since expiry
-- 2159 msecs since expiry
-- 2186 msecs since expiry
-- 2203 msecs since expiry
-- 2206 msecs since expiry
-- 2223 msecs since expiry
-- 2226 msecs since expiry
-- 2233 msecs since expiry
-- 2246 msecs since expiry
-- 2256 msecs since expiry
-- 2266 msecs since expiry
-- 2289 msecs since expiry
-- 2306 msecs since expiry
-- 2346 msecs since expiry
-- 2359 msecs since expiry
-- 2379 msecs since expiry
-- 2379 msecs since expiry
-- 2383 msecs since expiry
-- 2389 msecs since expiry
-- 2419 msecs since expiry
-- 2429 msecs since expiry
-- 2436 msecs since expiry
-- 2453 msecs since expiry
-- 2469 msecs since expiry
-- 2483 msecs since expiry
-- 2513 msecs since expiry
-- 2519 msecs since expiry
-- 2526 msecs since expiry
-- 2533 msecs since expiry
-- 2539 msecs since expiry
-- 2543 msecs since expiry
-- 2543 msecs since expiry
-- 2546 msecs since expiry
-- 2556 msecs since expiry
-- 2563 msecs since expiry
-- 2573 msecs since expiry
-- 2596 msecs since expiry
-- 2613 msecs since expiry
-- 2619 msecs since expiry
-- 2626 msecs since expiry
-- 2633 msecs since expiry
-- 2659 msecs since expiry
-- 2663 msecs since expiry
-- 2676 msecs since expiry
-- 2719 msecs since expiry
-- 2769 msecs since expiry
-- 2776 msecs since expiry
-- 2776 msecs since expiry
-- 2779 msecs since expiry
-- 2786 msecs since expiry
-- 2793 msecs since expiry
-- 2826 msecs since expiry
-- 2846 msecs since expiry
-- 2883 msecs since expiry
-- 2883 msecs since expiry
-- 2889 msecs since expiry
-- 2903 msecs since expiry
-- 2923 msecs since expiry
-- 2929 msecs since expiry
-- 2956 msecs since expiry
-- 2959 msecs since expiry
-- 2959 msecs since expiry
-- 2959 msecs since expiry
-- 2983 msecs since expiry
-- 2986 msecs since expiry
-- 2986 msecs since expiry
-- 2989 msecs since expiry
-- 3036 msecs since expiry
-- 3043 msecs since expiry
-- 3053 msecs since expiry
-- 3069 msecs since expiry
-- 3089 msecs since expiry
-- 3129 msecs since expiry
-- 3133 msecs since expiry
-- 3159 msecs since expiry
-- 3173 msecs since expiry
-- 3176 msecs since expiry
-- 3179 msecs since expiry
-- 3229 msecs since expiry
-- 3256 msecs since expiry
-- 3269 msecs since expiry
-- 3273 msecs since expiry
-- 3283 msecs since expiry
-- 3283 msecs since expiry
-- 3303 msecs since expiry
-- 3326 msecs since expiry
-- 3326 msecs since expiry
-- 3339 msecs since expiry
-- 3339 msecs since expiry
-- 3366 msecs since expiry
-- 3369 msecs since expiry
-- 3399 msecs since expiry
-- 3403 msecs since expiry
-- 3413 msecs since expiry
-- 3453 msecs since expiry
-- 3466 msecs since expiry
-- 3469 msecs since expiry
-- 3 msecs since expiry
20-Feb-2024 10:46:30.324 REFUSED unexpected RCODE resolving 'cloud.Jensen.com.cn/NS/IN': 39.96.153.53#53
-- 0 msecs since expiry
-- 0 msecs since expiry
20-Feb-2024 10:46:30.524 REFUSED unexpected RCODE resolving 'cloud.Jensen.com.cn/NS/IN': 39.96.153.32#53
-- 0 msecs since expiry
```
So, there are multiple issues circling around the TTL-based cleaning.March 2024 (9.16.49, 9.16.49-S1, 9.18.25, 9.18.25-S1, 9.19.22)https://gitlab.isc.org/isc-projects/bind9/-/issues/4588CID 486508: Control flow issues in lib/ns/query.c2024-02-21T10:51:33ZMichal NowakCID 486508: Control flow issues in lib/ns/query.cCoverity Scan claims a control flow issue in `lib/ns/query.c`.
```cpp
/lib/ns/query.c: 6307 in fetch_callback()
6301 * Return an error to the client, or just drop.
6302 */
6303 if (fetch_canceled) {
6304 CTRACE...Coverity Scan claims a control flow issue in `lib/ns/query.c`.
```cpp
/lib/ns/query.c: 6307 in fetch_callback()
6301 * Return an error to the client, or just drop.
6302 */
6303 if (fetch_canceled) {
6304 CTRACE(ISC_LOG_ERROR, "fetch cancelled");
6305 query_error(client, DNS_R_SERVFAIL, __LINE__);
6306 } else {
>>> CID 486508: Control flow issues (DEADCODE)
>>> Execution cannot reach this statement: "query_next(client, ISC_R_CA...".
6307 query_next(client, ISC_R_CANCELED);
6308 }
6309
6310 /*
6311 * Free any persistent plugin data that was allocated to
6312 * service the client, then detach the client object.
```March 2024 (9.16.49, 9.16.49-S1, 9.18.25, 9.18.25-S1, 9.19.22)Arаm SаrgsyаnArаm Sаrgsyаnhttps://gitlab.isc.org/isc-projects/bind9/-/issues/4572TLS forwarder lookup fails in resolver.c when TLS CA certificate not available2024-02-21T20:41:29ZTobias WolterTLS forwarder lookup fails in resolver.c when TLS CA certificate not available### Summary
When configuring a forwarder with a TLS configuration that specifies a CA file to verify the remote certificate, BIND dies at the RUNTIME_CHECK in resolver.c when it cannot read the CA file.
### BIND version affected
BIND ...### Summary
When configuring a forwarder with a TLS configuration that specifies a CA file to verify the remote certificate, BIND dies at the RUNTIME_CHECK in resolver.c when it cannot read the CA file.
### BIND version affected
BIND 9.19.19-1+0~20231220.107+debian12~1.gbpfc5ec0-Debian (Development Release) <id:>
### Steps to reproduce
1. Use the provided configuration snippet in any working configuration.
2. Do *not* have a `/certificates` directory.
3. Look up something from test.example.com.
### What is the current *bug* behavior?
BIND crashes in the resolver library due to the TLS context not being set up correctly.
### What is the expected *correct* behavior?
BIND complains about not being able to read about the CA certificate on startup.
### Relevant configuration files
* named.conf (excerpt):
```
tls auth1 {
ca-file "/certificates/ca.crt";
remote-hostname "auth1";
};
tls auth2 {
ca-file "/certificates/ca.crt";
remote-hostname "auth2";
};
zone test.example.com {
type forward;
forwarders port 853 { 172.23.23.11 tls auth1; 172.23.23.12 tls auth2; };
forward only;
};
```
### Relevant logs
```
recursive-2 | 12-Feb-2024 08:57:44.370 client @0x713184c1c000 172.23.23.23#45455 (foo.test.example.com): query: foo.test.example.com IN A +E(0)K (172.23.23.14)
recursive-2 | fetch: foo.test.example.com/A
recursive-2 | QNAME minimization - minimized, qmintype 2 qminname corp
recursive-2 | resolver.c:2175:fctx_query(): fatal error:
recursive-2 | RUNTIME_CHECK(result == ISC_R_SUCCESS) failed
recursive-2 | exiting (due to fatal error in library)
recursive-2 exited with code 139
```March 2024 (9.16.49, 9.16.49-S1, 9.18.25, 9.18.25-S1, 9.19.22)Artem BoldarievArtem Boldarievhttps://gitlab.isc.org/isc-projects/bind9/-/issues/4571findnsec3proofs failed to disassociate all rdatasets returned by dns_ncache_c...2024-03-08T08:24:37ZMark Andrewsfindnsec3proofs failed to disassociate all rdatasets returned by dns_ncache_currentThese are not currently reference counted by if they where it would introduce a memory/reference leak.These are not currently reference counted by if they where it would introduce a memory/reference leak.March 2024 (9.16.49, 9.16.49-S1, 9.18.25, 9.18.25-S1, 9.19.22)https://gitlab.isc.org/isc-projects/bind9/-/issues/4570CID 486327: Control flow issues (UNREACHABLE)2024-03-08T08:20:30ZMark AndrewsCID 486327: Control flow issues (UNREACHABLE)Just need to be removed.
```
** CID 486327: Control flow issues (UNREACHABLE)
/lib/isc/netmgr/netmgr.c: 750 in isc___nmsocket_init()
____________________________________________________________________________________________________...Just need to be removed.
```
** CID 486327: Control flow issues (UNREACHABLE)
/lib/isc/netmgr/netmgr.c: 750 in isc___nmsocket_init()
________________________________________________________________________________________________________
*** CID 486327: Control flow issues (UNREACHABLE)
/lib/isc/netmgr/netmgr.c: 750 in isc___nmsocket_init()
744 sock->statsindex = tcp6statsindex;
745 break;
746 default:
747 UNREACHABLE();
748 }
749 break;
CID 486327: Control flow issues (UNREACHABLE)
This code cannot be reached: "switch (family) {
case 2:...".
750 switch (family) {
751 case AF_INET:
752 sock->statsindex = tcp4statsindex;
753 break;
754 case AF_INET6:
755 sock->statsindex = tcp6statsindex;
```March 2024 (9.16.49, 9.16.49-S1, 9.18.25, 9.18.25-S1, 9.19.22)https://gitlab.isc.org/isc-projects/bind9/-/issues/4569** CID 486326: Memory - corruptions (OVERRUN)2024-03-08T08:23:03ZMark Andrews** CID 486326: Memory - corruptions (OVERRUN)This is cosmetic but should be addressed. sizeof(type.sa) is smaller than sizeof(type) and sizeof(type.sin6) so
while this overruns type.sa it doesn't actually overrun the union.
```
** CID 486326: Memory - corruptions (OVERRUN)
/lib/...This is cosmetic but should be addressed. sizeof(type.sa) is smaller than sizeof(type) and sizeof(type.sin6) so
while this overruns type.sa it doesn't actually overrun the union.
```
** CID 486326: Memory - corruptions (OVERRUN)
/lib/dns/resconf.c: 248 in add_server()
________________________________________________________________________________________________________
*** CID 486326: Memory - corruptions (OVERRUN)
/lib/dns/resconf.c: 248 in add_server()
242 if (res->ai_addrlen > sizeof(address->type)) {
243 isc_mem_put(mctx, address, sizeof(*address));
244 result = ISC_R_RANGE;
245 goto cleanup;
246 }
247 address->length = (unsigned int)res->ai_addrlen;
CID 486326: Memory - corruptions (OVERRUN)
Overrunning struct type sockaddr of 16 bytes by passing it to a function which accesses it at byte offset 27 using argument "res->ai_addrlen" (which evaluates to 28). [Note: The source code implementation of the function has been overridden by a builtin model.]
248 memmove(&address->type.sa, res->ai_addr, res->ai_addrlen);
249 ISC_LINK_INIT(address, link);
250 ISC_LIST_APPEND(*nameservers, address, link);
251
252 cleanup:
253 freeaddrinfo(res);
```March 2024 (9.16.49, 9.16.49-S1, 9.18.25, 9.18.25-S1, 9.19.22)https://gitlab.isc.org/isc-projects/bind9/-/issues/4566slow zone transfer takes longer than expected in statschannel test2024-02-21T23:36:33ZTom Krizekslow zone transfer takes longer than expected in statschannel test`statschannel` system test recently became more unstable, [failing](https://gitlab.isc.org/isc-projects/bind9/-/jobs/4006014) on the following check:
```
2024-02-08 00:32:57 INFO:statschannel I:statschannel_tmp_0gqlueys:Wait for slo...`statschannel` system test recently became more unstable, [failing](https://gitlab.isc.org/isc-projects/bind9/-/jobs/4006014) on the following check:
```
2024-02-08 00:32:57 INFO:statschannel I:statschannel_tmp_0gqlueys:Wait for slow zone transfer to complete (29)
2024-02-08 00:33:16 INFO:statschannel I:statschannel_tmp_0gqlueys:exceeded time limit waiting for literal 'zone example/IN: zone transfer finished: success' in ns3/named.run
2024-02-08 00:33:16 INFO:statschannel I:statschannel_tmp_0gqlueys:failed
```
The check in question uses `-T transferslowly` option which makes the code use `select()` with a one second timeout to delay the individual packets. `ns1` uses the `transfer-format one-answer;` for the transfer to `ns3`. The `example.db` zone has 8 records and the check allows 20 second timeout, which should be more than sufficient. However, the records are delayed more than expected on the sending side:
```
08-Feb-2024 00:32:57.116 client @0x7b780001f800 10.53.0.3#41203 (example): transfer of 'example/IN': AXFR question section OK
08-Feb-2024 00:32:57.116 client @0x7b780001f800 10.53.0.3#41203 (example): transfer of 'example/IN': AXFR authority section OK
08-Feb-2024 00:32:57.116 client @0x7b780001f800 10.53.0.3#41203 (example): transfer of 'example/IN': AXFR started (serial 1)
08-Feb-2024 00:32:57.116 client @0x7b780001f800 10.53.0.3#41203 (example): transfer of 'example/IN': starting maxtime timer 7200000 ms
08-Feb-2024 00:32:57.116 client @0x7b780001f800 10.53.0.3#41203 (example): transfer of 'example/IN': sending TCP message of 77 bytes
08-Feb-2024 00:32:58.120 client @0x7b780001f800 10.53.0.3#41203 (example): transfer of 'example/IN': sending TCP message of 48 bytes
08-Feb-2024 00:32:59.124 client @0x7b780001f800 10.53.0.3#41203 (example): transfer of 'example/IN': sending TCP message of 48 bytes
08-Feb-2024 00:33:02.140 client @0x7b780001f800 10.53.0.3#41203 (example): transfer of 'example/IN': sending TCP message of 53 bytes
08-Feb-2024 00:33:05.152 client @0x7b780001f800 10.53.0.3#41203 (example): transfer of 'example/IN': sending TCP message of 785 bytes
08-Feb-2024 00:33:08.165 client @0x7b780001f800 10.53.0.3#41203 (example): transfer of 'example/IN': sending TCP message of 51 bytes
08-Feb-2024 00:33:11.177 client @0x7b780001f800 10.53.0.3#41203 (example): transfer of 'example/IN': sending TCP message of 50 bytes
08-Feb-2024 00:33:14.189 client @0x7b780001f800 10.53.0.3#41203 (example): transfer of 'example/IN': sending TCP message of 59 bytes
08-Feb-2024 00:33:17.201 client @0x7b780001f800 10.53.0.3#41203 (example): transfer of 'example/IN': sending TCP message of 71 bytes
08-Feb-2024 00:33:19.209 client @0x7b780001f800 10.53.0.3#41203 (example): transfer of 'example/IN': send: operation canceled
```
After the first three record are transmitted, each following record is delayed by just over 3 seconds (rather than 1 second). It could be caused by the load in the CI due to parallelization, but the fact this pattern (first 3 records have 1s delay, remaining record have 3s delay) repeats in another [job](https://gitlab.isc.org/isc-projects/bind9/-/jobs/4007776) makes this a bit suspicious:
```
08-Feb-2024 09:55:12.719 client @0x7f559a027000 10.53.0.3#46059 (example): transfer of 'example/IN': sending TCP message of 77 bytes
08-Feb-2024 09:55:13.719 client @0x7f559a027000 10.53.0.3#46059 (example): transfer of 'example/IN': sending TCP message of 48 bytes
08-Feb-2024 09:55:14.724 client @0x7f559a027000 10.53.0.3#46059 (example): transfer of 'example/IN': sending TCP message of 48 bytes
08-Feb-2024 09:55:17.728 client @0x7f559a027000 10.53.0.3#46059 (example): transfer of 'example/IN': sending TCP message of 53 bytes
08-Feb-2024 09:55:21.740 client @0x7f559a027000 10.53.0.3#46059 (example): transfer of 'example/IN': sending TCP message of 785 bytes
08-Feb-2024 09:55:24.748 client @0x7f559a027000 10.53.0.3#46059 (example): transfer of 'example/IN': sending TCP message of 51 bytes
08-Feb-2024 09:55:28.756 client @0x7f559a027000 10.53.0.3#46059 (example): transfer of 'example/IN': sending TCP message of 50 bytes
08-Feb-2024 09:55:31.765 client @0x7f559a027000 10.53.0.3#46059 (example): transfer of 'example/IN': sending TCP message of 59 bytes
```March 2024 (9.16.49, 9.16.49-S1, 9.18.25, 9.18.25-S1, 9.19.22)Artem BoldarievArtem Boldariev