BIND issueshttps://gitlab.isc.org/isc-projects/bind9/-/issues2022-11-16T16:07:31Zhttps://gitlab.isc.org/isc-projects/bind9/-/issues/3629Slow retries after timeouts2022-11-16T16:07:31Zgrzchr15Slow retries after timeoutsMeasurements from Neustar/UltraDNS for some DNS servers including BIND9,They think there is weird behavior:
https://ripe85.ripe.net/wp-content/uploads/presentations/96-dknight-fewnsmanyips-ripe85-dnswg.pdf
Page 8
Video: https://ripe85....Measurements from Neustar/UltraDNS for some DNS servers including BIND9,They think there is weird behavior:
https://ripe85.ripe.net/wp-content/uploads/presentations/96-dknight-fewnsmanyips-ripe85-dnswg.pdf
Page 8
Video: https://ripe85.ripe.net/archive/video/dave-knight_fewer-name-servers-more-addresses_main-20221027-112204.mp4 time 7:17 onwards
Measurements from Neustar/UltraDNS for some DNS servers including BIND9
- Bind Strongly prefers IPv6 - they think there is weird behavior.
- If one address is broken, penalize all higher numbered addresses until piling onto the last one?
- Slow to get an answer when retryingŠtěpán BalážikŠtěpán Balážikhttps://gitlab.isc.org/isc-projects/bind9/-/issues/3704nsupdate prints confusing error message when answer has RCODE=REFUSED2022-11-29T09:25:03ZPetr Špačekpspacek@isc.orgnsupdate prints confusing error message when answer has RCODE=REFUSEDThis is follow-up from [discussion](https://gitlab.isc.org/isc-private/bind9/-/merge_requests/442#note_328521):
`nsupdate` says `Communication with 10.53.0.1#5300 failed: REFUSED` rather than `status: REFUSED`. This is somewhat confusin...This is follow-up from [discussion](https://gitlab.isc.org/isc-private/bind9/-/merge_requests/442#note_328521):
`nsupdate` says `Communication with 10.53.0.1#5300 failed: REFUSED` rather than `status: REFUSED`. This is somewhat confusing because the communication went okay (we have sent & received the answer from server) and the server indeed sent RCODE=REFUSED.https://gitlab.isc.org/isc-projects/bind9/-/issues/3705automated test for statistics channel versioning2022-11-29T13:34:00ZPetr Špačekpspacek@isc.orgautomated test for statistics channel versioningWe should have a test for statistics channel. I envision that the test should at least detect:
- [ ] new fields - minor version bump in in order
- [ ] removed fields
- [ ] value type changes? (e.g. int to float)
It would be much easier...We should have a test for statistics channel. I envision that the test should at least detect:
- [ ] new fields - minor version bump in in order
- [ ] removed fields
- [ ] value type changes? (e.g. int to float)
It would be much easier to do if we had a way to export ALL counters, including all zero-value counters, from stats channel. As far as I can tell from the main branch 532615baf868c2cef926f1494199fd9c0153064b it is not the case.https://gitlab.isc.org/isc-projects/bind9/-/issues/3691stats channels and `rndc dumpstats` do not expose all counters from `rndc sta...2022-11-29T13:42:48ZPetr Špačekpspacek@isc.orgstats channels and `rndc dumpstats` do not expose all counters from `rndc status`### Summary
JSON and XML stat channels, and `rndc dumpstats` command, do not expose counters from `rndc status`. This forces users to scrape both channels to get complete picture.
### BIND version used
9.19.8-dev (Development Release)...### Summary
JSON and XML stat channels, and `rndc dumpstats` command, do not expose counters from `rndc status`. This forces users to scrape both channels to get complete picture.
### BIND version used
9.19.8-dev (Development Release) 9128e54 , but it certainly dates long way back.
### What is the current *bug* behavior?
Compare lines produced by `rndc status` with content of JSON stats channel:
| rndc status line | evaluation | JSON key |
|-------------------------------------------------------------|-------------------|-------------|
| version: BIND 9.19.8-dev (Development Release) <id:9128e54> | different format, just `9.19.8-dev` | version |
| running on p: Linux x86_64 6.0.8-arch1-1 #1 SMP … | missing | |
| boot time: Tue, 22 Nov 2022 08:43:49 GMT | different format | boot-time |
| last configured: Tue, 22 Nov 2022 09:34:20 GMT | different format | config-time |
| configuration file: /etc/named.conf | missing | |
| CPUs found: 8 | missing | |
| worker threads: 8 | missing | |
| UDP listeners per interface: 8 | missing | |
| number of zones: 103 (98 automatic) | missing | |
| debug level: 0 | missing | |
| xfers running: 0 | missing | |
| xfers deferred: 0 | missing | |
| soa queries in progress: 0 | missing | |
| query logging is OFF | missing | |
| recursive clients: 0/900/1000 | missing | |
| tcp clients: 0/150 | missing | |
| TCP high-water: 0 | missing | |
| server is up and running | missing | |
### What is the expected *correct* behavior?
All information from `rndc status` is also exposed in other stats channels.Not plannedhttps://gitlab.isc.org/isc-projects/bind9/-/issues/3738Many repeated log messages about managed-keys-zone2022-12-13T14:38:25ZPetr Špačekpspacek@isc.orgMany repeated log messages about managed-keys-zone### Summary
Authoritative server excessively logs
```
managed-keys-zone: Unable to fetch DNSKEY set '.': failure
```
or
```
managed-keys-zone: Key 20326 for zone . is now trusted (acceptance timer complete)
```
### BIND version used
-...### Summary
Authoritative server excessively logs
```
managed-keys-zone: Unable to fetch DNSKEY set '.': failure
```
or
```
managed-keys-zone: Key 20326 for zone . is now trusted (acceptance timer complete)
```
### BIND version used
- ~"Affects v9.19": Intermittently reproducible, BIND 9.19.8-dev 1b2ee33.
- Not sure about older versions.
### Steps to reproduce
1. Configure server with `options { recursion no; };`
2. Do bunch of restart or `rndc reconfig` s
### What is the current *bug* behavior?
Message
```
managed-keys-zone: Unable to fetch DNSKEY set '.': failure
```
is repeated many times within the same millisecond.
Largest observed repetition is 114.
### What is the expected *correct* behavior?
First, I dunno why the auth server should even bother fetching `. DNSKEY` ...
If it is legit I would not expect it going in circles.
### Relevant configuration files
(abbreviated)
```
options {
recursion no;
listen-on {
};
listen-on-v6 {
2600::0;
};
allow-query {
"any";
};
notify no;
};
zone "net." {
type primary;
file "/usr/etc/smallnet.db";
masterfile-format text;
};
```
`smallnet.db` is an empty zone.
If `net.` zone is configured with an empty zone it complains about inability to fetch keys.
If `net.` is not configured at all it repeats log line about key being trusted.
### Relevant logs and/or screenshots
[log](/uploads/c414c9ae327b4d726fb42773db4c8f75/log)https://gitlab.isc.org/isc-projects/bind9/-/issues/3741reuse TCP/TLS connections for XFR2022-12-19T15:49:41ZPetr Špačekpspacek@isc.orgreuse TCP/TLS connections for XFR### Description
Profiling confirms we thought before: Not reusing TCP connections is a real performance drag for secondary servers which have to transfer lots of zones.
This is a profile for secondary with 100 k small zones being trans...### Description
Profiling confirms we thought before: Not reusing TCP connections is a real performance drag for secondary servers which have to transfer lots of zones.
This is a profile for secondary with 100 k small zones being transferred from the same primary:
![catz.svg](/uploads/eb13335b4753ae32439ce28d44fdd579/catz.svg)
I.e. about 1/2 of CPU time spent by `net` threads in bind(), spinning on CPU and looking for a free source port - because there's a lot of connections going on. (I did tune the OS to use 1k-64k port range before doing this test.)
Measured on v9_18_10, zone list comes via CATZ from the same primary.
### Request
Reuse TCP/TLS connections when talking to the same primary.
Please note that reusing connections for ordinary queries is very intentionally out of scope for this ticket. It causes (or at least caused) all sorts of issues with broken implementations, and I hope that reusing it for zone transfers will be better.
### Links / referenceshttps://gitlab.isc.org/isc-projects/bind9/-/issues/2996Migrate PKCS11 from "engine" to "provider"2022-12-26T19:20:52ZMark AndrewsMigrate PKCS11 from "engine" to "provider"OpenSSL 3.0.0 has deprecated the `engine` api in favour of the `provider` api. We currently use the `engine` api and OpenSC for pkcs11 access to HSMs. We need to move to using the `provider` api as soon as possible.
OpenSC has an open...OpenSSL 3.0.0 has deprecated the `engine` api in favour of the `provider` api. We currently use the `engine` api and OpenSC for pkcs11 access to HSMs. We need to move to using the `provider` api as soon as possible.
OpenSC has an open ticket for OpenSSL 3.0.0 https://github.com/OpenSC/OpenSC/issues/2308Not plannedhttps://gitlab.isc.org/isc-projects/bind9/-/issues/3757named-checkconfig -px inserts extra blanks in output2022-12-31T08:40:56ZPhilip Prindevillenamed-checkconfig -px inserts extra blanks in output<!--
If the bug you are reporting is potentially security-related - for example,
if it involves an assertion failure or other crash in `named` that can be
triggered repeatedly - then please do *NOT* report it here, but send an
email to [...<!--
If the bug you are reporting is potentially security-related - for example,
if it involves an assertion failure or other crash in `named` that can be
triggered repeatedly - then please do *NOT* report it here, but send an
email to [security-officer@isc.org](security-officer@isc.org).
-->
### Summary
Certain multiline commands like `listen-on-v6` generate two spaces instead of one before the leading left curly bracket.
### BIND version used
```
BIND 9.18.10 (Stable Release) <id:aa8ab10>
running on Linux x86_64 5.15.85 #0 SMP Mon Dec 26 23:46:44 2022
built by make with '--target=x86_64-openwrt-linux' '--host=x86_64-openwrt-linux' '--build=x86_64-pc-linux-gnu' '--program-prefix=' '--program-suffix=' '--prefix=/usr' '--exec-prefix=/usr' '--bindir=/usr/bin' '--sbindir=/usr/sbin' '--libexecdir=/usr/lib' '--sysconfdir=/etc' '--datadir=/usr/share' '--localstatedir=/var' '--mandir=/usr/man' '--infodir=/usr/info' '--with-openssl=/home/philipp/lede/staging_dir/target-x86_64_musl/usr' '--without-lmdb' '--enable-epoll' '--without-gssapi' '--without-readline' '--sysconfdir=/etc/bind' '--with-json-c=no' '--with-libxml2=no' '--enable-doh' 'build_alias=x86_64-pc-linux-gnu' 'host_alias=x86_64-openwrt-linux' 'target_alias=x86_64-openwrt-linux' 'CC=x86_64-openwrt-linux-musl-gcc' 'CFLAGS=-Os -pipe -fno-caller-saves -fno-plt -fhonour-copts -fmacro-prefix-map=/home/philipp/lede/build_dir/target-x86_64_musl/bind-9.18.10=bind-9.18.10 -Wformat -Werror=format-security -fstack-protector -D_FORTIFY_SOURCE=1 -Wl,-z,now -Wl,-z,relro ' 'LDFLAGS=-L/home/philipp/lede/staging_dir/toolchain-x86_64_gcc-11.3.0_musl/usr/lib -L/home/philipp/lede/staging_dir/toolchain-x86_64_gcc-11.3.0_musl/lib -znow -zrelro -Wl,--gc-sections,--as-needed ' 'CPPFLAGS=-I/home/philipp/lede/staging_dir/toolchain-x86_64_gcc-11.3.0_musl/usr/include -I/home/philipp/lede/staging_dir/toolchain-x86_64_gcc-11.3.0_musl/include/fortify -I/home/philipp/lede/staging_dir/toolchain-x86_64_gcc-11.3.0_musl/include ' 'PKG_CONFIG=/home/philipp/lede/staging_dir/host/bin/pkg-config' 'PKG_CONFIG_PATH=/home/philipp/lede/staging_dir/target-x86_64_musl/usr/lib/pkgconfig:/home/philipp/lede/staging_dir/target-x86_64_musl/usr/share/pkgconfig' 'PKG_CONFIG_LIBDIR=/home/philipp/lede/staging_dir/target-x86_64_musl/usr/lib/pkgconfig:/home/philipp/lede/staging_dir/target-x86_64_musl/usr/share/pkgconfig'
compiled by GCC 11.3.0
compiled with OpenSSL version: OpenSSL 1.1.1s 1 Nov 2022
linked to OpenSSL version: OpenSSL 1.1.1s 1 Nov 2022
compiled with libuv version: 1.44.1
linked to libuv version: 1.44.1
compiled with libnghttp2 version: 1.44.0
linked to libnghttp2 version: 1.44.0
compiled with zlib version: 1.2.13
linked to zlib version: 1.2.13
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): no
default paths:
named configuration: /etc/bind/named.conf
rndc configuration: /etc/bind/rndc.conf
DNSSEC root key: /etc/bind/bind.keys
nsupdate session key: /var/run/named/session.key
named PID file: /var/run/named/named.pid
named lock file: /var/run/named/named.lock
```
### Steps to reproduce
Create a `named.conf` with `listen-on-v6 { none; }` in the `options { ... };` section, and load it.
Then run:
```
named-checkconf -px \
| sed -r -ne '1N; N; /^\tlisten-on-v6 +\{\n\t\t"none";\n\t\};$/{ p; q; }; D'
```
and the output will be:
```
listen-on-v6 {
"none";
};
```
Note the extraneous space on the first line.
### What is the current *bug* behavior?
Two spaces before the `{`.
### What is the expected *correct* behavior?
A single space as for all other commands.
### Relevant configuration files
```
// This is the primary configuration file for the BIND DNS server named.
options {
directory "/tmp";
// If your ISP provided one or more IP addresses for stable
// nameservers, you probably want to use them as forwarders.
// Uncomment the following block, and insert the addresses replacing
// the all-0's placeholder.
// forwarders {
// 0.0.0.0;
// };
recursion yes;
// note that all subnets are visible to each other;
// if we wished to isolate them we could use "views".
allow-query {
localhost;
192.168.6.0/24;
192.168.7.0/24;
192.168.8.0/24;
};
auth-nxdomain no; # conform to RFC1035
// added by philipp
allow-transfer { none; };
// dnssec-validation no;
// dnssec-enabled yes;
dnssec-validation auto;
listen-on-v6 { none; };
};
include "/etc/bind/named-rndc.conf";
include "/tmp/bind/named.conf.local";
// prime the server with knowledge of the root servers
zone "." {
type hint;
file "/etc/bind/db.root";
};
// be authoritative for the localhost forward and reverse zones, and for
// broadcast zones as per RFC 1912
zone "localhost" {
type master;
file "/etc/bind/db.local";
};
zone "127.in-addr.arpa" {
type master;
file "/etc/bind/db.127";
};
zone "0.in-addr.arpa" {
type master;
file "/etc/bind/db.0";
};
zone "255.in-addr.arpa" {
type master;
file "/etc/bind/db.255";
};
# added by philipp
zone "tiktok.com" {
type master;
file "/etc/bind/db.tiktok.com";
};
```
### Relevant logs and/or screenshots
```
listen-on-v6 {
"none";
};
```
### Possible fixes
UnknownNot plannedhttps://gitlab.isc.org/isc-projects/bind9/-/issues/3758Revisit BIND features to prevent the scenario where a second BIND instance is...2023-01-02T14:18:27ZCathy AlmondRevisit BIND features to prevent the scenario where a second BIND instance is running accidentallyAs discussed with Engineering, but not relating to a specific customer issue, although Support team regularly encounter sites with unintentional multiple running instances of named, so I'm tagging this one as 'Customer'.
With newer BIND...As discussed with Engineering, but not relating to a specific customer issue, although Support team regularly encounter sites with unintentional multiple running instances of named, so I'm tagging this one as 'Customer'.
With newer BIND using SO_REUSEPORT (`reuseport yes;`) there is no longer anything to stop multiple instances of running named from listening on the same sockets - the kernel will distribute incoming queries to the listening threads/processes per however the kernel and NICs implement and support rx-flow-hash.
This could be seen as a 'feature' by some. But for others, it allows accidental launching of multiple instances of named, and then much confusion and pain troubleshooting ensuing problems, if, for example, the intent was to restart named with a different version or different configuration. Having different instances fielding different queries could produce different outcomes!
This new behaviour (mostly) negates this change, introduced in BIND 9.11.0:
4022. [func] Stop multiple spawns of named by limiting number of
processes to 1. This is done by using a lockfile and
checking whether we can listen on any configured
TCP interfaces. [RT #37908]
Of significance is that with the introduction of reuseport, the TCP listen check will now no longer work, and that lock-file is not enabled by default.
```
lock-file
This is the pathname of a file on which named attempts to acquire a file lock when starting for the first time; if
unsuccessful, the server terminates, under the assumption that another server is already running. If not specified,
the default is none.
Specifying lock-file none disables the use of a lock file. lock-file is ignored if named was run using the
-X option, which overrides it. Changes to lock-file are ignored if named is being reloaded or reconfigured;
it is only effective when the server is first started.
```
This is distinct from pid-file, whose purpose is to identify the pid of the running named instance, so that signals can be sent to it:
```
pid-file
This is the pathname of the file the server writes its process ID in. If not specified, the default is /var/run/
named/named.pid. The PID file is used by programs that send signals to the running name server. Specifying
pid-file none disables the use of a PID file; no file is written and any existing one is removed. Note that
none is a keyword, not a filename, and therefore is not enclosed in double quotes.
```
---
What to do? I'm not sure - I think this is a 'gotcha' rather than a bug at this point, but I think it's so subtle that it has the potential to derail the unwary who aren't aware that it could happen. Should we perhaps change the default for the existence of the lock-file?Not plannedhttps://gitlab.isc.org/isc-projects/bind9/-/issues/3763rndc documentation misses a feature; rndc-confgen still uses md52023-01-05T21:28:34ZTimothe Littrndc documentation misses a feature; rndc-confgen still uses md5The code is (mostly) willing, but the documentation is weak :-(
I finally noticed that the rndc [documentation](https://bind9.readthedocs.io/en/v9_18_10/manpages.html#rndc-conf-rndc-configuration-file) describes rndc.conf as
> "has a si...The code is (mostly) willing, but the documentation is weak :-(
I finally noticed that the rndc [documentation](https://bind9.readthedocs.io/en/v9_18_10/manpages.html#rndc-conf-rndc-configuration-file) describes rndc.conf as
> "has a similar structure and syntax to `named.conf`".
This is true, but omits a valuable feature:
`include` works in `rndc.conf`.
It turns out that this is useful if you ever need (or want) to rotate keys, since a (suitably protected) .key file can be `include`d in `rndc.conf` and likewise `include`d in `named.conf`.
In any case, this structure avoids duplication of the secret key; makes updating the key simpler, and allows `rndc.conf` to have read permissions - thus making the `options` clause visible, which may be desirable. It also means that if you use unique keys for more than one `named` instance, you can simply move the key file to your management stations, but retain the default-server without editing each station's `rndc.conf`.
For example:
```sh
named.conf
# Define the rndc control key
include "rndc.key";
cat >/etc/named/rndc.conf
include "rndc.key";
options {
default-server: 2001:0db8::53;
default-port: 953;
};
# Now, updating and initial key creation becomes simply:
touch /etc/named/rndc.key
chmod 600 /etc/named/rndc.key
tsig-keygen -a sha256 rndc-key >/etc/named/rndc.key
rndc reconfig
```
No more copying the `key` clause into both files, or including in `named.conf` but copying into `rndc.conf`.
For extra credit - `rndc-confgen` should probably produce this structure, since it's better than the current suggestions.
`rndc-confgen` should definitely be updated to default to SHA256 rather than MD5, since MD5 is deprecated and the documentation says (under the `key` statment) that SHA256 is now the default...
Happy New Year.Not plannedhttps://gitlab.isc.org/isc-projects/bind9/-/issues/3730rndc and stats should respond while zones are loading2023-01-06T17:17:02ZPetr Špačekpspacek@isc.orgrndc and stats should respond while zones are loading### Description
Neither RNDC or statistics channels generate responses to requests while primary zones are being loaded after startup.
### Versions tested
* ~"Affects v9.16": It kind of works for RNDC (but not stats channel), assuming ...### Description
Neither RNDC or statistics channels generate responses to requests while primary zones are being loaded after startup.
### Versions tested
* ~"Affects v9.16": It kind of works for RNDC (but not stats channel), assuming there is enough threads. `rndc` blocks mainly when `named -n1` is used.
* ~"Affects v9.18" Same as v9.16.
* ~"Affects v9.19": It does not work at all during first startup. It looks to me like a regression/fallout in recent versions.
### Request
I would expect that RNDC and stats channel can be used to monitor progress - e.g. number of zones loaded (and ideally also configured, which would be a new counter).
### Reproducer
1. Configure a large zone, say `net.`, and start named.
2. Attempt to run `rndc status` or GET on statistics channels.
3. Answer is returned only after the zone is loaded (or fails to load).
### Links / referenceshttps://gitlab.isc.org/isc-projects/bind9/-/issues/2938CID 339072 (#1 of 1): Unchecked return value (CHECKED_RETURN)2023-01-09T11:11:24ZMark AndrewsCID 339072 (#1 of 1): Unchecked return value (CHECKED_RETURN)lib/dns/rpz.c:
```
2246
CID 339072 (#1 of 1): Unchecked return value (CHECKED_RETURN)
25. check_return: Calling isc_timer_reset without checking return value (as is done elsewhere 9 out of 10 times).
2247 isc_timer_...lib/dns/rpz.c:
```
2246
CID 339072 (#1 of 1): Unchecked return value (CHECKED_RETURN)
25. check_return: Calling isc_timer_reset without checking return value (as is done elsewhere 9 out of 10 times).
2247 isc_timer_reset(rpz->updatetimer, isc_timertype_inactive, NULL,
2248 NULL, true);
```Not plannedMark AndrewsMark Andrewshttps://gitlab.isc.org/isc-projects/bind9/-/issues/3775update-policy documentation confuses2023-01-09T11:29:01ZTimothe Littupdate-policy documentation confusesNot plannedhttps://gitlab.isc.org/isc-projects/bind9/-/issues/3776update-policy wildcard match limitations2023-01-09T11:30:12ZTimothe Littupdate-policy wildcard match limitations[The `wildcard` match documentation](https://bind9.readthedocs.io/en/v9_18_10/reference.html#dynamic-update-policies) reads
> The name field is subject to **DNS wildcard expansion**, and this rule matches when the name being updated is ...[The `wildcard` match documentation](https://bind9.readthedocs.io/en/v9_18_10/reference.html#dynamic-update-policies) reads
> The name field is subject to **DNS wildcard expansion**, and this rule matches when the name being updated is a valid expansion of the wildcard.
It would be useful to have a more flexible wildcard match for the update-policy's grant/deny wildcard names.
An example that would help many of us (who use Let's Encrypt) is
`_acme-challenge.*.example.net`, as in
```
grant "CERTIFICATE_ISSUE_BOT" name _acme-challenge.*.example.net. TXT ;
```
Since DNS wildcards only work for the leftmost label, this can't be expressed with the current syntax.
As a result, when a server is added, not only must the A/AAAA records be added (which can be done with UPDATE), but a `grant` clause must be added to the configuration (which can not).
Or allow the BOT to handle all TXT records in the domain. I'm pretty sure I don't want a bot to be able to mess up SPF, google console, and other TXT records...
There are other cases where a generic glob match would be helpful, but most of them can be worked-around by suitable naming and/or introducing a subdomain. Unfortunately, that's not the case for ACME, which requires this structure for the records it uses for `dns-01` validation.
This is NOT asking for changes to how queries are resolved. That ship sailed (to where there be dragons) long ago. Just how `update-policy` clauses are matched. `update-policy` is internal to bind, and the suggested change would be upward-compatible.Not plannedhttps://gitlab.isc.org/isc-projects/bind9/-/issues/3660CID 375800: Concurrent data access violations in lib/isc/rwlock.c2023-01-10T14:15:41ZMichal NowakCID 375800: Concurrent data access violations in lib/isc/rwlock.cCoverity Scan assumes that `rwl->readers_waiting` should be accessed with a lock held as is done elsewhere 4 out of 5 times.
The following recent commits might be of interest:
- 98b7a93772077c021c3ff8a8d763decb8dffeba1
- 6bd201ccec1d5a...Coverity Scan assumes that `rwl->readers_waiting` should be accessed with a lock held as is done elsewhere 4 out of 5 times.
The following recent commits might be of interest:
- 98b7a93772077c021c3ff8a8d763decb8dffeba1
- 6bd201ccec1d5a11a42890e8b94a6920fcda97bb
- 0492bbf590fa5c7e52f94d5a9220724e68052444
```
*** CID 375800: Concurrent data access violations (MISSING_LOCK)
/lib/isc/rwlock.c: 104 in isc__rwlock_init()
98 rwl->magic = 0;
99
100 atomic_init(&rwl->spins, 0);
101 atomic_init(&rwl->write_requests, 0);
102 atomic_init(&rwl->write_completions, 0);
103 atomic_init(&rwl->cnt_and_flag, 0);
>>> CID 375800: Concurrent data access violations (MISSING_LOCK)
>>> Accessing "rwl->readers_waiting" without holding lock "isc_rwlock.lock". Elsewhere, "isc_rwlock.readers_waiting" is accessed with "isc_rwlock.lock" held 4 out of 5 times.
104 rwl->readers_waiting = 0;
105 atomic_init(&rwl->write_granted, 0);
106 if (read_quota != 0) {
107 UNEXPECTED_ERROR("read quota is not supported");
108 }
109 if (write_quota == 0) {
```Not plannedhttps://gitlab.isc.org/isc-projects/bind9/-/issues/3642tcpdns_recv_send failure in mem.c:7722023-01-10T14:16:34ZMichal Nowaktcpdns_recv_send failure in mem.c:772Job [#2874890](https://gitlab.isc.org/isc-projects/bind9/-/jobs/2874890) failed for 395a5576b40eb7f4d34ee0606200947b4698173e with:
```
[ RUN ] tcpdns_recv_send
mem.c:772: REQUIRE(((ctx) != ((void *)0) && ((const isc__magic_t *)(ctx)...Job [#2874890](https://gitlab.isc.org/isc-projects/bind9/-/jobs/2874890) failed for 395a5576b40eb7f4d34ee0606200947b4698173e with:
```
[ RUN ] tcpdns_recv_send
mem.c:772: REQUIRE(((ctx) != ((void *)0) && ((const isc__magic_t *)(ctx))->magic == ((('M') << 24 | ('e') << 16 | ('m') << 8 | ('C'))))) failed, back trace
```
<details><summary>tcpdns_recv_send failure</summary>
```
[==========] Running 6 test(s).
[ RUN ] tcpdns_noop
[ OK ] tcpdns_noop
[ RUN ] tcpdns_noresponse
[ OK ] tcpdns_noresponse
[ RUN ] tcpdns_timeout_recovery
[ OK ] tcpdns_timeout_recovery
[ RUN ] tcpdns_recv_one
[ OK ] tcpdns_recv_one
[ RUN ] tcpdns_recv_two
[ OK ] tcpdns_recv_two
[ RUN ] tcpdns_recv_send
mem.c:772: REQUIRE(((ctx) != ((void *)0) && ((const isc__magic_t *)(ctx))->magic == ((('M') << 24 | ('e') << 16 | ('m') << 8 | ('C'))))) failed, back trace
mem.c:772: REQUIRE(((ctx) != ((void *)0) && ((const isc__magic_t *)(ctx))->magic == ((('M') << 24 | ('e') << 16 | ('m') << 8 | ('C'))))) failed, back trace
mem.c:772: REQUIRE(((ctx) != ((void *)0) && ((const isc__magic_t *)(ctx))->magic == ((('M') << 24 | ('e') << 16 | ('m') << 8 | ('C'))))) failed, back trace
/builds/isc-projects/bind9/lib/isc/.libs/libisc-9.19.7-dev.so(+0x3119d)[0x7efd91df119d]
/builds/isc-projects/bind9/lib/isc/.libs/libisc-9.19.7-dev.so(+0x3119d)[0x7efd91df119d]
/builds/isc-projects/bind9/lib/isc/.libs/libisc-9.19.7-dev.so(+0x3119d)[0x7efd91df119d]
/builds/isc-projects/bind9/lib/isc/.libs/libisc-9.19.7-dev.so(isc_assertion_failed+0xa)[0x7efd91df1118]
/builds/isc-projects/bind9/lib/isc/.libs/libisc-9.19.7-dev.so(isc_assertion_failed+0xa)[0x7efd91df1118]
/builds/isc-projects/bind9/lib/isc/.libs/libisc-9.19.7-dev.so(isc_assertion_failed+0xa)[0x7efd91df1118]
/builds/isc-projects/bind9/lib/isc/.libs/libisc-9.19.7-dev.so(isc__mem_get+0x9f)[0x7efd91e04800]
/builds/isc-projects/bind9/lib/isc/.libs/libisc-9.19.7-dev.so(isc__mem_get+0x9f)[0x7efd91e04800]
/builds/isc-projects/bind9/lib/isc/.libs/libisc-9.19.7-dev.so(isc__mem_get+0x9f)[0x7efd91e04800]
/builds/isc-projects/bind9/lib/isc/.libs/libisc-9.19.7-dev.so(isc_nm_tcpdnsconnect+0x8b)[0x7efd91de92af]
/builds/isc-projects/bind9/lib/isc/.libs/libisc-9.19.7-dev.so(isc_nm_tcpdnsconnect+0x8b)[0x7efd91de92af]
/builds/isc-projects/bind9/lib/isc/.libs/libisc-9.19.7-dev.so(isc_nm_tcpdnsconnect+0x8b)[0x7efd91de92af]
/builds/isc-projects/bind9/tests/isc/.libs/lt-tcpdns_test[0x403b0d]
/builds/isc-projects/bind9/tests/isc/.libs/lt-tcpdns_test(stream_recv_send_connect+0x5a)[0x4040ec]
/builds/isc-projects/bind9/lib/isc/.libs/libisc-9.19.7-dev.so(+0x3b536)[0x7efd91dfb536]
/builds/isc-projects/bind9/tests/isc/.libs/lt-tcpdns_test[0x403b0d]
/builds/isc-projects/bind9/tests/isc/.libs/lt-tcpdns_test[0x403b0d]
/lib64/libuv.so.1(uv__run_idle+0x99)[0x7efd91ba7a49]
/builds/isc-projects/bind9/tests/isc/.libs/lt-tcpdns_test(stream_recv_send_connect+0x5a)[0x4040ec]
/builds/isc-projects/bind9/tests/isc/.libs/lt-tcpdns_test(stream_recv_send_connect+0x5a)[0x4040ec]
/builds/isc-projects/bind9/lib/isc/.libs/libisc-9.19.7-dev.so(+0x3b536)[0x7efd91dfb536]
/lib64/libuv.so.1(uv_run+0x298)[0x7efd91ba0bf8]
/builds/isc-projects/bind9/lib/isc/.libs/libisc-9.19.7-dev.so(+0x3b536)[0x7efd91dfb536]
/lib64/libuv.so.1(uv__run_idle+0x99)[0x7efd91ba7a49]
/builds/isc-projects/bind9/lib/isc/.libs/libisc-9.19.7-dev.so(+0x41b44)[0x7efd91e01b44]
/lib64/libuv.so.1(uv__run_idle+0x99)[0x7efd91ba7a49]
/lib64/libuv.so.1(uv_run+0x298)[0x7efd91ba0bf8]
/builds/isc-projects/bind9/lib/isc/.libs/libisc-9.19.7-dev.so(isc__trampoline_run+0x16)[0x7efd91e1b87f]
/lib64/libuv.so.1(uv_run+0x298)[0x7efd91ba0bf8]
/builds/isc-projects/bind9/lib/isc/.libs/libisc-9.19.7-dev.so(+0x41b44)[0x7efd91e01b44]
/lib64/libpthread.so.0(+0x81df)[0x7efd90de91df]
/builds/isc-projects/bind9/lib/isc/.libs/libisc-9.19.7-dev.so(+0x41b44)[0x7efd91e01b44]
/builds/isc-projects/bind9/lib/isc/.libs/libisc-9.19.7-dev.so(isc__trampoline_run+0x16)[0x7efd91e1b87f]
/lib64/libc.so.6(clone+0x43)[0x7efd90a55dd3]
/builds/isc-projects/bind9/lib/isc/.libs/libisc-9.19.7-dev.so(isc__trampoline_run+0x16)[0x7efd91e1b87f]
/lib64/libpthread.so.0(+0x81df)[0x7efd90de91df]
../../tests/unit-test-driver.sh: line 36: 7887 Aborted (core dumped) "${TEST_PROGRAM}"
I:tcpdns_test:Core dump found: ./core.7887
D:tcpdns_test:backtrace from ./core.7887 start
[New LWP 7975]
[New LWP 7970]
[New LWP 7973]
[New LWP 7887]
[New LWP 7971]
[New LWP 7976]
[New LWP 7972]
[New LWP 7977]
[New LWP 7974]
[New LWP 7968]
[New LWP 7967]
[New LWP 7969]
[New LWP 7978]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/builds/isc-projects/bind9/tests/isc/.libs/lt-tcpdns_test'.
Program terminated with signal SIGABRT, Aborted.
#0 0x00007efd90a6aa9f in raise () from /lib64/libc.so.6
[Current thread is 1 (Thread 0x7efd89efb700 (LWP 7975))]
Thread 13 (Thread 0x7efd83fff700 (LWP 7978)):
#0 0x00007efd90df282d in __lll_lock_wait () from /lib64/libpthread.so.0
No symbol table info available.
#1 0x00007efd90debba4 in pthread_mutex_lock () from /lib64/libpthread.so.0
No symbol table info available.
#2 0x00007efd90b84ff3 in dl_iterate_phdr () from /lib64/libc.so.6
No symbol table info available.
#3 0x00007efd8f0a1bf5 in _Unwind_Find_FDE () from /lib64/libgcc_s.so.1
No symbol table info available.
#4 0x00007efd8f09e193 in uw_frame_state_for () from /lib64/libgcc_s.so.1
No symbol table info available.
#5 0x00007efd8f0a01d8 in _Unwind_Backtrace () from /lib64/libgcc_s.so.1
No symbol table info available.
#6 0x00007efd90b57c46 in backtrace () from /lib64/libc.so.6
No symbol table info available.
#7 0x00007efd91df18f2 in isc_backtrace (addrs=addrs@entry=0x7efd83ffce20, maxaddrs=maxaddrs@entry=128) at backtrace.c:44
n = <optimized out>
#8 0x00007efd91df119d in default_callback (file=0x7efd91e2ff0b "mem.c", line=772, type=isc_assertiontype_require, cond=0x7efd91e304a0 "((ctx) != ((void *)0) && ((const isc__magic_t *)(ctx))->magic == ((('M') << 24 | ('e') << 16 | ('m') << 8 | ('C'))))") at assertions.c:100
tracebuf = {0x7efd91df18f2 <isc_backtrace+24>, 0x7efd91df119d <default_callback+49>, 0x7efd91df1118 <isc_assertion_failed+10>, 0x7efd80e008c0, 0x14, 0x7efd80e09218, 0x0, 0x7efd83ffe058, 0x7efd83ffcee8, 0xe6c048c994a92300, 0x7efd57200000, 0x400, 0x200, 0x7efd83ffde68, 0x7efd57200000, 0x7efd83ffd110, 0x7efd83ffdc78, 0x7efd9037de0b <je_arena_ralloc+459>, 0x0, 0x7efd57201000, 0x7efd83ffd118, 0x0, 0x7efd80e008c0, 0x0, 0x0, 0x201, 0x0, 0x0, 0x0, 0x3c3000, 0x7efd903b134a <extents_remove_locked.isra+170>, 0xe6c048c994a92300, 0x23, 0x7efd8ec03268, 0x7efd8ec03268, 0x7efd8ec0f200, 0x7efd8e660cc8, 0x7efd907fdec0, 0xd50dcc13, 0x7efd83ffdc78, 0x7efd8ec0f100, 0x7efd903aca72 <extent_lock_from_addr+434>, 0x0, 0x100000000000000, 0x7efd83ffdc78, 0x0, 0x7efd83ffdc78, 0xd50dcc13, 0x7efd8ec03268, 0x7efd8ec0f200, 0x7efd8ec0f580, 0x7efd903b1877 <extent_try_coalesce_impl+839>, 0x7efd83ffdca8, 0x7efd8ec00980, 0x7efd83ffd250, 0x7efd00000001, 0x0, 0x7efd83ffd108, 0x0, 0x183ffd250, 0x7efd83ffdca8, 0x1, 0x8, 0x7efd83ffd108, 0x0, 0x54, 0x7efd83ffd0f0, 0x7efd91df6247 <isc_hash64+87>, 0x7efd83ffd05f, 0x7efd92549c70 <isc_modules+80>, 0x0, 0x0, 0x0, 0x0, 0x0, 0x7efd83ffd198, 0x0, 0x183ffdc78, 0x0, 0x7efd83ffd1b8, 0x0, 0x183ffd198, 0x0, 0x1, 0x8, 0x7efd83ffd1b8, 0x0, 0x2e2, 0x7efd83ffd1a0, 0x7efd91df6247 <isc_hash64+87>, 0x7efd83ffd1c0, 0x7efd91e03bc9 <delete_trace_entry+303>, 0x7efd91e2b585, 0x7efd5720f400, 0x0, 0x7efd57200000, 0x400, 0x0, 0x0, 0x7efd83ffd258, 0x0, 0x7efd83ffd268, 0x0, 0x7efd83ffd278, 0x0, 0x18ea13010, 0x168, 0x1, 0x8, 0x7efd83ffd278, 0x0, 0x201, 0x7efd83ffd260, 0x7efd91df6247 <isc_hash64+87>, 0x7efd91e27a1e, 0x7efd57204000, 0x7efd83ffd1f0, 0x7efd91e05a3c <isc__mem_putanddetach+114>, 0x7efd5720f400, 0x0, 0x0, 0x0, 0x7efd83ffd2a0, 0x7efd91df15d7 <isc_astack_destroy+125>, 0x7efd83ffdc78, 0x7efd83ffd328, 0x0, 0x10027ffff}
nframes = <optimized out>
#9 0x00007efd91df1118 in isc_assertion_failed (file=file@entry=0x7efd91e2ff0b "mem.c", line=line@entry=772, type=type@entry=isc_assertiontype_require, cond=cond@entry=0x7efd91e304a0 "((ctx) != ((void *)0) && ((const isc__magic_t *)(ctx))->magic == ((('M') << 24 | ('e') << 16 | ('m') << 8 | ('C'))))") at assertions.c:49
No locals.
#10 0x00007efd91e04800 in isc__mem_get (ctx=<optimized out>, size=size@entry=2208, flags=flags@entry=0, file=file@entry=0x7efd91e2a6f2 "netmgr/tcpdns.c", line=line@entry=269) at mem.c:781
ptr = 0x0
#11 0x00007efd91de92af in isc_nm_tcpdnsconnect (mgr=<optimized out>, local=0x6084e0 <tcp_connect_addr>, peer=0x608580 <tcp_listen_addr>, cb=0x40529c <connect_connect_cb>, cbarg=cbarg@entry=0x403ae9 <tcpdns_connect>, timeout=timeout@entry=30000) at netmgr/tcpdns.c:269
result = ISC_R_SUCCESS
sock = 0x0
ievent = 0x0
req = 0x0
sa_family = 10
worker = 0x7efd8ead4680
__func__ = "isc_nm_tcpdnsconnect"
#12 0x0000000000403b0d in tcpdns_connect (nm=<optimized out>) at tcpdns_test.c:63
No locals.
#13 0x00000000004040ec in stream_recv_send_connect (arg=0x403ae9 <tcpdns_connect>) at netmgr_common.c:516
connect = 0x403ae9 <tcpdns_connect>
connect_addr = {type = {sa = {sa_family = 10, sa_data = '\000' <repeats 13 times>}, sin = {sin_family = 10, sin_port = 0, sin_addr = {s_addr = 0}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 10, sin6_port = 0, sin6_flowinfo = 0, sin6_addr = {__in6_u = {__u6_addr8 = '\000' <repeats 15 times>, "\001", __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 256}, __u6_addr32 = {0, 0, 0, 16777216}}}, sin6_scope_id = 0}, ss = {ss_family = 10, __ss_padding = '\000' <repeats 21 times>, "\001", '\000' <repeats 95 times>, __ss_align = 0}, sunix = {sun_family = 10, sun_path = '\000' <repeats 21 times>, "\001", '\000' <repeats 85 times>}}, length = 28, link = {prev = 0xffffffffffffffff, next = 0xffffffffffffffff}}
#14 0x00007efd91dfb536 in isc__job_cb (idle=0x7efd8ebf0808) at job.c:75
job = 0x7efd8ebf0800
r = <optimized out>
__func__ = "isc__job_cb"
#15 0x00007efd91ba7a49 in uv.run_idle () from /lib64/libuv.so.1
No symbol table info available.
#16 0x00007efd91ba0bf8 in uv_run () from /lib64/libuv.so.1
No symbol table info available.
#17 0x00007efd91e01b44 in loop_run (loop=0x7efd8eaa5b80) at loop.c:267
r = <optimized out>
job = <optimized out>
r = <optimized out>
job = <optimized out>
__func__ = "loop_run"
next = <optimized out>
#18 loop_thread (arg=0x7efd8eaa5b80) at loop.c:294
loop = 0x7efd8eaa5b80
#19 0x00007efd91e1b87f in isc__trampoline_run (arg=0x18486b0) at trampoline.c:198
trampoline = 0x18486b0
result = <optimized out>
#20 0x00007efd90de91df in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#21 0x00007efd90a55dd3 in clone () from /lib64/libc.so.6
No symbol table info available.
Thread 12 (Thread 0x7efd82ffd700 (LWP 7969)):
#0 0x00007efd90df05be in pthread_barrier_wait () from /lib64/libpthread.so.0
No symbol table info available.
#1 0x00007efd91bada7d in uv_barrier_wait () from /lib64/libuv.so.1
No symbol table info available.
#2 0x00007efd91de8154 in isc__nm_async_tcpdnsstop (worker=worker@entry=0x7efd8ead40c0, ev0=ev0@entry=0x7efd8ea8bd00) at netmgr/tcpdns.c:670
ievent = 0x7efd8ea8bd00
sock = 0x7efd8e3196e0
__func__ = "isc__nm_async_tcpdnsstop"
#3 0x00007efd91de27d2 in process_netievent (arg=0x7efd8ea8bd00) at netmgr/netmgr.c:463
ievent = 0x7efd8ea8bd00
worker = 0x7efd8ead40c0
#4 0x00007efd91dfb536 in isc__job_cb (idle=0x7efd8ebf0a48) at job.c:75
job = 0x7efd8ebf0a40
r = <optimized out>
__func__ = "isc__job_cb"
#5 0x00007efd91ba7a49 in uv.run_idle () from /lib64/libuv.so.1
No symbol table info available.
#6 0x00007efd91ba0bf8 in uv_run () from /lib64/libuv.so.1
No symbol table info available.
#7 0x00007efd91e01b44 in loop_run (loop=0x7efd8eaa26a0) at loop.c:267
r = <optimized out>
job = <optimized out>
r = <optimized out>
job = <optimized out>
__func__ = "loop_run"
next = <optimized out>
#8 loop_thread (arg=0x7efd8eaa26a0) at loop.c:294
loop = 0x7efd8eaa26a0
#9 0x00007efd91e1b87f in isc__trampoline_run (arg=0x1845fc0) at trampoline.c:198
trampoline = 0x1845fc0
result = <optimized out>
#10 0x00007efd90de91df in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#11 0x00007efd90a55dd3 in clone () from /lib64/libc.so.6
No symbol table info available.
Thread 11 (Thread 0x7efd81ffb700 (LWP 7967)):
#0 0x00007efd90df05be in pthread_barrier_wait () from /lib64/libpthread.so.0
No symbol table info available.
#1 0x00007efd91bada7d in uv_barrier_wait () from /lib64/libuv.so.1
No symbol table info available.
#2 0x00007efd91de8154 in isc__nm_async_tcpdnsstop (worker=worker@entry=0x7efd8ead4040, ev0=ev0@entry=0x7efd8ea8bb80) at netmgr/tcpdns.c:670
ievent = 0x7efd8ea8bb80
sock = 0x7efd8e3185a0
__func__ = "isc__nm_async_tcpdnsstop"
#3 0x00007efd91de27d2 in process_netievent (arg=0x7efd8ea8bb80) at netmgr/netmgr.c:463
ievent = 0x7efd8ea8bb80
worker = 0x7efd8ead4040
#4 0x00007efd91dfb536 in isc__job_cb (idle=0x7efd8ea24508) at job.c:75
job = 0x7efd8ea24500
r = <optimized out>
__func__ = "isc__job_cb"
#5 0x00007efd91ba7a49 in uv.run_idle () from /lib64/libuv.so.1
No symbol table info available.
#6 0x00007efd91ba0bf8 in uv_run () from /lib64/libuv.so.1
No symbol table info available.
#7 0x00007efd91e01b44 in loop_run (loop=0x7efd8eaa1ae0) at loop.c:267
r = <optimized out>
job = <optimized out>
r = <optimized out>
job = <optimized out>
__func__ = "loop_run"
next = <optimized out>
#8 loop_thread (arg=0x7efd8eaa1ae0) at loop.c:294
loop = 0x7efd8eaa1ae0
#9 0x00007efd91e1b87f in isc__trampoline_run (arg=0x1848200) at trampoline.c:198
trampoline = 0x1848200
result = <optimized out>
#10 0x00007efd90de91df in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#11 0x00007efd90a55dd3 in clone () from /lib64/libc.so.6
No symbol table info available.
Thread 10 (Thread 0x7efd827fc700 (LWP 7968)):
#0 0x00007efd90df05be in pthread_barrier_wait () from /lib64/libpthread.so.0
No symbol table info available.
#1 0x00007efd91bada7d in uv_barrier_wait () from /lib64/libuv.so.1
No symbol table info available.
#2 0x00007efd91de8154 in isc__nm_async_tcpdnsstop (worker=worker@entry=0x7efd8ead4080, ev0=ev0@entry=0x7efd8ea8a800) at netmgr/tcpdns.c:670
ievent = 0x7efd8ea8a800
sock = 0x7efd8e318e40
__func__ = "isc__nm_async_tcpdnsstop"
#3 0x00007efd91de27d2 in process_netievent (arg=0x7efd8ea8a800) at netmgr/netmgr.c:463
ievent = 0x7efd8ea8a800
worker = 0x7efd8ead4080
#4 0x00007efd91dfb536 in isc__job_cb (idle=0x7efd8ea23848) at job.c:75
job = 0x7efd8ea23840
r = <optimized out>
__func__ = "isc__job_cb"
#5 0x00007efd91ba7a49 in uv.run_idle () from /lib64/libuv.so.1
No symbol table info available.
#6 0x00007efd91ba0bf8 in uv_run () from /lib64/libuv.so.1
No symbol table info available.
#7 0x00007efd91e01b44 in loop_run (loop=0x7efd8eaa20c0) at loop.c:267
r = <optimized out>
job = <optimized out>
r = <optimized out>
job = <optimized out>
__func__ = "loop_run"
next = <optimized out>
#8 loop_thread (arg=0x7efd8eaa20c0) at loop.c:294
loop = 0x7efd8eaa20c0
#9 0x00007efd91e1b87f in isc__trampoline_run (arg=0x1845e20) at trampoline.c:198
trampoline = 0x1845e20
result = <optimized out>
#10 0x00007efd90de91df in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#11 0x00007efd90a55dd3 in clone () from /lib64/libc.so.6
No symbol table info available.
Thread 9 (Thread 0x7efd8a6fc700 (LWP 7974)):
#0 0x00007efd90df05be in pthread_barrier_wait () from /lib64/libpthread.so.0
No symbol table info available.
#1 0x00007efd91bada7d in uv_barrier_wait () from /lib64/libuv.so.1
No symbol table info available.
#2 0x00007efd91de8154 in isc__nm_async_tcpdnsstop (worker=worker@entry=0x7efd8ead4200, ev0=ev0@entry=0x7efd8ea8af80) at netmgr/tcpdns.c:670
ievent = 0x7efd8ea8af80
sock = 0x7efd8e31c200
__func__ = "isc__nm_async_tcpdnsstop"
#3 0x00007efd91de27d2 in process_netievent (arg=0x7efd8ea8af80) at netmgr/netmgr.c:463
ievent = 0x7efd8ea8af80
worker = 0x7efd8ead4200
#4 0x00007efd91dfb536 in isc__job_cb (idle=0x7efd8ebf0d48) at job.c:75
job = 0x7efd8ebf0d40
r = <optimized out>
__func__ = "isc__job_cb"
#5 0x00007efd91ba7a49 in uv.run_idle () from /lib64/libuv.so.1
No symbol table info available.
#6 0x00007efd91ba0bf8 in uv_run () from /lib64/libuv.so.1
No symbol table info available.
#7 0x00007efd91e01b44 in loop_run (loop=0x7efd8eaa4400) at loop.c:267
r = <optimized out>
job = <optimized out>
r = <optimized out>
job = <optimized out>
__func__ = "loop_run"
next = <optimized out>
#8 loop_thread (arg=0x7efd8eaa4400) at loop.c:294
loop = 0x7efd8eaa4400
#9 0x00007efd91e1b87f in isc__trampoline_run (arg=0x1847ef0) at trampoline.c:198
trampoline = 0x1847ef0
result = <optimized out>
#10 0x00007efd90de91df in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#11 0x00007efd90a55dd3 in clone () from /lib64/libc.so.6
No symbol table info available.
Thread 8 (Thread 0x7efd88ef9700 (LWP 7977)):
#0 0x00007efd90b85317 in _dl_addr () from /lib64/libc.so.6
No symbol table info available.
#1 0x00007efd90b58296 in backtrace_symbols_fd () from /lib64/libc.so.6
No symbol table info available.
#2 0x00007efd91df193a in isc_backtrace_symbols_fd (buffer=buffer@entry=0x7efd88ef6e20, size=size@entry=13, fd=<optimized out>) at backtrace.c:61
No locals.
#3 0x00007efd91df11f6 in default_callback (file=0x7efd91e2ff0b "mem.c", line=772, type=<optimized out>, cond=0x7efd91e304a0 "((ctx) != ((void *)0) && ((const isc__magic_t *)(ctx))->magic == ((('M') << 24 | ('e') << 16 | ('m') << 8 | ('C'))))") at assertions.c:107
tracebuf = {0x7efd91df119d <default_callback+49>, 0x7efd91df1118 <isc_assertion_failed+10>, 0x7efd91e04800 <isc__mem_get+159>, 0x7efd91de92af <isc_nm_tcpdnsconnect+139>, 0x403b0d <tcpdns_connect+36>, 0x4040ec <stream_recv_send_connect+90>, 0x7efd91dfb536 <isc__job_cb+59>, 0x7efd91ba7a49 <uv.run_idle+153>, 0x7efd91ba0bf8 <uv_run+664>, 0x7efd91e01b44 <loop_thread+433>, 0x7efd91e1b87f <isc__trampoline_run+22>, 0x7efd90de91df <start_thread+239>, 0x7efd90a55dd3 <clone+67>, 0x7efd90a55dd3 <clone+67>, 0x0, 0x7efd9037ae61 <arena_bin_malloc_hard+1201>, 0x7efd806086e8, 0x3, 0x7efd88ef6f2f, 0xa, 0x7efd905f9d90, 0x7efd9037ad6e <arena_bin_malloc_hard+958>, 0x7efd806008c0, 0x7efd88ef7c78, 0x7efd8060a880, 0x7efd80608760, 0x7efd80608728, 0x7efd905f9d90, 0x7efd88ef6f2c, 0x7efd88ef7038, 0x0, 0x188ef6f2d, 0x0, 0x1, 0x8, 0x7efd88ef7038, 0x7efd8e6620d8, 0x7efd907ff200, 0xd50dcc13, 0x7efd88ef7c78, 0x7efd8ec0f300, 0x7efd903aca72 <extent_lock_from_addr+434>, 0x0, 0x1007efd9037bd7f, 0x4000000000, 0x0, 0x7efd88ef7c78, 0xd50dcc13, 0x7efd8ec03268, 0x7efd8ec0f400, 0x7efd8ec0f500, 0x7efd903b1877 <extent_try_coalesce_impl+839>, 0x7efd88ef7ca8, 0x7efd8ec00980, 0x7efd88ef7250, 0x48c900000001, 0x0, 0x7efd88ef7108, 0x0, 0x188ef7250, 0x7efd88ef7ca8, 0x1, 0x8, 0x7efd88ef7108, 0x0, 0x54, 0x7efd88ef70f0, 0x7efd91df6247 <isc_hash64+87>, 0x7efd88ef705f, 0x7efd92549c70 <isc_modules+80>, 0x0, 0x0, 0x0, 0x100000000000000, 0x0, 0xe6c048c994a92300, 0x0, 0xe6c048c994a92300, 0x7efd88ef7190, 0x7efd88ef71b8, 0x0, 0x1000000a8, 0x0, 0x1, 0x8, 0x7efd88ef71b8, 0x0, 0x2e2, 0x7efd88ef71a0, 0x7efd91df6247 <isc_hash64+87>, 0x7efd88ef71c0, 0x7efd91e03bc9 <delete_trace_entry+303>, 0x7efd91e2b585, 0x7efd5660e400, 0x7efd88ef7130, 0x8, 0x7efd8eaa5928, 0x34, 0x7efd91bb52a8, 0x7efd88ef7258, 0x0, 0x7efd88ef7268, 0x0, 0x7efd88ef7278, 0x0, 0x100000001, 0x8, 0x1, 0x8, 0x7efd88ef7278, 0x0, 0x201, 0x7efd88ef7260, 0x7efd91df6247 <isc_hash64+87>, 0x7efd91e27a1e, 0x7efd56603000, 0x7efd88ef71f0, 0x7efd91e05a3c <isc__mem_putanddetach+114>, 0x7efd5660e400, 0x0, 0x0, 0x0, 0x7efd88ef72a0, 0x7efd91df15d7 <isc_astack_destroy+125>, 0x7efd88ef7c78, 0x7efd88ef7328, 0x0, 0x10027ffff}
nframes = 13
#4 0x00007efd91df1118 in isc_assertion_failed (file=file@entry=0x7efd91e2ff0b "mem.c", line=line@entry=772, type=type@entry=isc_assertiontype_require, cond=cond@entry=0x7efd91e304a0 "((ctx) != ((void *)0) && ((const isc__magic_t *)(ctx))->magic == ((('M') << 24 | ('e') << 16 | ('m') << 8 | ('C'))))") at assertions.c:49
No locals.
#5 0x00007efd91e04800 in isc__mem_get (ctx=<optimized out>, size=size@entry=2208, flags=flags@entry=0, file=file@entry=0x7efd91e2a6f2 "netmgr/tcpdns.c", line=line@entry=269) at mem.c:781
ptr = 0x0
#6 0x00007efd91de92af in isc_nm_tcpdnsconnect (mgr=<optimized out>, local=0x6084e0 <tcp_connect_addr>, peer=0x608580 <tcp_listen_addr>, cb=0x40529c <connect_connect_cb>, cbarg=cbarg@entry=0x403ae9 <tcpdns_connect>, timeout=timeout@entry=30000) at netmgr/tcpdns.c:269
result = ISC_R_SUCCESS
sock = 0x0
ievent = 0x0
req = 0x0
sa_family = 10
worker = 0x7efd8ead4640
__func__ = "isc_nm_tcpdnsconnect"
#7 0x0000000000403b0d in tcpdns_connect (nm=<optimized out>) at tcpdns_test.c:63
No locals.
#8 0x00000000004040ec in stream_recv_send_connect (arg=0x403ae9 <tcpdns_connect>) at netmgr_common.c:516
connect = 0x403ae9 <tcpdns_connect>
connect_addr = {type = {sa = {sa_family = 10, sa_data = '\000' <repeats 13 times>}, sin = {sin_family = 10, sin_port = 0, sin_addr = {s_addr = 0}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 10, sin6_port = 0, sin6_flowinfo = 0, sin6_addr = {__in6_u = {__u6_addr8 = '\000' <repeats 15 times>, "\001", __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 256}, __u6_addr32 = {0, 0, 0, 16777216}}}, sin6_scope_id = 0}, ss = {ss_family = 10, __ss_padding = '\000' <repeats 21 times>, "\001", '\000' <repeats 95 times>, __ss_align = 0}, sunix = {sun_family = 10, sun_path = '\000' <repeats 21 times>, "\001", '\000' <repeats 85 times>}}, length = 28, link = {prev = 0xffffffffffffffff, next = 0xffffffffffffffff}}
#9 0x00007efd91dfb536 in isc__job_cb (idle=0x7efd8ebf0748) at job.c:75
job = 0x7efd8ebf0740
r = <optimized out>
__func__ = "isc__job_cb"
#10 0x00007efd91ba7a49 in uv.run_idle () from /lib64/libuv.so.1
No symbol table info available.
#11 0x00007efd91ba0bf8 in uv_run () from /lib64/libuv.so.1
No symbol table info available.
#12 0x00007efd91e01b44 in loop_run (loop=0x7efd8eaa55a0) at loop.c:267
r = <optimized out>
job = <optimized out>
r = <optimized out>
job = <optimized out>
__func__ = "loop_run"
next = <optimized out>
#13 loop_thread (arg=0x7efd8eaa55a0) at loop.c:294
loop = 0x7efd8eaa55a0
#14 0x00007efd91e1b87f in isc__trampoline_run (arg=0x1848510) at trampoline.c:198
trampoline = 0x1848510
result = <optimized out>
#15 0x00007efd90de91df in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#16 0x00007efd90a55dd3 in clone () from /lib64/libc.so.6
No symbol table info available.
Thread 7 (Thread 0x7efd8b6fe700 (LWP 7972)):
#0 0x00007efd90df05be in pthread_barrier_wait () from /lib64/libpthread.so.0
No symbol table info available.
#1 0x00007efd91bada7d in uv_barrier_wait () from /lib64/libuv.so.1
No symbol table info available.
#2 0x00007efd91de8154 in isc__nm_async_tcpdnsstop (worker=worker@entry=0x7efd8ead4180, ev0=ev0@entry=0x7efd8ea8ac80) at netmgr/tcpdns.c:670
ievent = 0x7efd8ea8ac80
sock = 0x7efd8e31b0c0
__func__ = "isc__nm_async_tcpdnsstop"
#3 0x00007efd91de27d2 in process_netievent (arg=0x7efd8ea8ac80) at netmgr/netmgr.c:463
ievent = 0x7efd8ea8ac80
worker = 0x7efd8ead4180
#4 0x00007efd91dfb536 in isc__job_cb (idle=0x7efd8ebf0bc8) at job.c:75
job = 0x7efd8ebf0bc0
r = <optimized out>
__func__ = "isc__job_cb"
#5 0x00007efd91ba7a49 in uv.run_idle () from /lib64/libuv.so.1
No symbol table info available.
#6 0x00007efd91ba0bf8 in uv_run () from /lib64/libuv.so.1
No symbol table info available.
#7 0x00007efd91e01b44 in loop_run (loop=0x7efd8eaa3840) at loop.c:267
r = <optimized out>
job = <optimized out>
r = <optimized out>
job = <optimized out>
__func__ = "loop_run"
next = <optimized out>
#8 loop_thread (arg=0x7efd8eaa3840) at loop.c:294
loop = 0x7efd8eaa3840
#9 0x00007efd91e1b87f in isc__trampoline_run (arg=0x1846050) at trampoline.c:198
trampoline = 0x1846050
result = <optimized out>
#10 0x00007efd90de91df in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#11 0x00007efd90a55dd3 in clone () from /lib64/libc.so.6
No symbol table info available.
Thread 6 (Thread 0x7efd896fa700 (LWP 7976)):
#0 0x00007efd90df282d in __lll_lock_wait () from /lib64/libpthread.so.0
No symbol table info available.
#1 0x00007efd90debba4 in pthread_mutex_lock () from /lib64/libpthread.so.0
No symbol table info available.
#2 0x00007efd90b851f7 in _dl_addr () from /lib64/libc.so.6
No symbol table info available.
#3 0x00007efd90b58296 in backtrace_symbols_fd () from /lib64/libc.so.6
No symbol table info available.
#4 0x00007efd91df193a in isc_backtrace_symbols_fd (buffer=buffer@entry=0x7efd896f7e20, size=size@entry=13, fd=<optimized out>) at backtrace.c:61
No locals.
#5 0x00007efd91df11f6 in default_callback (file=0x7efd91e2ff0b "mem.c", line=772, type=<optimized out>, cond=0x7efd91e304a0 "((ctx) != ((void *)0) && ((const isc__magic_t *)(ctx))->magic == ((('M') << 24 | ('e') << 16 | ('m') << 8 | ('C'))))") at assertions.c:107
tracebuf = {0x7efd91df119d <default_callback+49>, 0x7efd91df1118 <isc_assertion_failed+10>, 0x7efd91e04800 <isc__mem_get+159>, 0x7efd91de92af <isc_nm_tcpdnsconnect+139>, 0x403b0d <tcpdns_connect+36>, 0x4040ec <stream_recv_send_connect+90>, 0x7efd91dfb536 <isc__job_cb+59>, 0x7efd91ba7a49 <uv.run_idle+153>, 0x7efd91ba0bf8 <uv_run+664>, 0x7efd91e01b44 <loop_thread+433>, 0x7efd91e1b87f <isc__trampoline_run+22>, 0x7efd90de91df <start_thread+239>, 0x7efd90a55dd3 <clone+67>, 0x7efd90a55dd3 <clone+67>, 0x0, 0x7efd896f8110, 0x7efd896f8c78, 0x7efd9037de0b <je_arena_ralloc+459>, 0x0, 0x7efd56c00400, 0x7efd896f8118, 0x0, 0x7efd80a008c0, 0x0, 0x0, 0x201, 0x0, 0x0, 0x0, 0x141000, 0x7efd903b134a <extents_remove_locked.isra+170>, 0xe6c048c994a92300, 0x1d, 0x7efd8ec03268, 0x7efd8ec03268, 0x7efd8ec0f400, 0x7efd8e6616d0, 0x7efd907ff5f0, 0xd50dcc13, 0x7efd896f8c78, 0x7efd8ec0f200, 0x7efd903aca72 <extent_lock_from_addr+434>, 0x0, 0x100000000000001, 0x7efd896f8c78, 0x0, 0x7efd896f8c78, 0xd50dcc13, 0x7efd8ec03268, 0x7efd8ec0f300, 0x7efd8ec0f500, 0x7efd903b1877 <extent_try_coalesce_impl+839>, 0x7efd896f8ca8, 0x7efd8ec00980, 0x7efd896f8250, 0x7efd00000001, 0x0, 0x7efd896f8108, 0x0, 0x1896f8250, 0x7efd896f8ca8, 0x1, 0x8, 0x7efd896f8108, 0x0, 0x54, 0x7efd896f80f0, 0x7efd91df6247 <isc_hash64+87>, 0x7efd896f805f, 0x7efd92549c70 <isc_modules+80>, 0x0, 0x0, 0x0, 0x0, 0x0, 0x7efd896f8198, 0x0, 0x1896f8c78, 0x0, 0x7efd896f81b8, 0x0, 0x1896f8198, 0x0, 0x1, 0x8, 0x7efd896f81b8, 0x0, 0x2e2, 0x7efd896f81a0, 0x7efd91df6247 <isc_hash64+87>, 0x7efd896f81c0, 0x7efd91e03bc9 <delete_trace_entry+303>, 0x7efd91e2b585, 0x7efd56c13400, 0x0, 0x7efd80000000, 0x7efd8df8c120, 0x7efd896f8c78, 0x7efd8ea32e30, 0x7efd896f8258, 0x0, 0x7efd896f8268, 0x0, 0x7efd896f8278, 0x0, 0x18ea18010, 0x168, 0x1, 0x8, 0x7efd896f8278, 0x0, 0x201, 0x7efd896f8260, 0x7efd91df6247 <isc_hash64+87>, 0x7efd91e27a1e, 0x7efd56c04400, 0x7efd896f81f0, 0x7efd91e05a3c <isc__mem_putanddetach+114>, 0x7efd56c13400, 0x0, 0x0, 0x0, 0x7efd896f82a0, 0x7efd91df15d7 <isc_astack_destroy+125>, 0x7efd896f8c78, 0x7efd896f8328, 0x0, 0x10027ffff}
nframes = 13
#6 0x00007efd91df1118 in isc_assertion_failed (file=file@entry=0x7efd91e2ff0b "mem.c", line=line@entry=772, type=type@entry=isc_assertiontype_require, cond=cond@entry=0x7efd91e304a0 "((ctx) != ((void *)0) && ((const isc__magic_t *)(ctx))->magic == ((('M') << 24 | ('e') << 16 | ('m') << 8 | ('C'))))") at assertions.c:49
No locals.
#7 0x00007efd91e04800 in isc__mem_get (ctx=<optimized out>, size=size@entry=2208, flags=flags@entry=0, file=file@entry=0x7efd91e2a6f2 "netmgr/tcpdns.c", line=line@entry=269) at mem.c:781
ptr = 0x0
#8 0x00007efd91de92af in isc_nm_tcpdnsconnect (mgr=<optimized out>, local=0x6084e0 <tcp_connect_addr>, peer=0x608580 <tcp_listen_addr>, cb=0x40529c <connect_connect_cb>, cbarg=cbarg@entry=0x403ae9 <tcpdns_connect>, timeout=timeout@entry=30000) at netmgr/tcpdns.c:269
result = ISC_R_SUCCESS
sock = 0x0
ievent = 0x0
req = 0x0
sa_family = 10
worker = 0x7efd8ead4600
__func__ = "isc_nm_tcpdnsconnect"
#9 0x0000000000403b0d in tcpdns_connect (nm=<optimized out>) at tcpdns_test.c:63
No locals.
#10 0x00000000004040ec in stream_recv_send_connect (arg=0x403ae9 <tcpdns_connect>) at netmgr_common.c:516
connect = 0x403ae9 <tcpdns_connect>
connect_addr = {type = {sa = {sa_family = 10, sa_data = '\000' <repeats 13 times>}, sin = {sin_family = 10, sin_port = 0, sin_addr = {s_addr = 0}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 10, sin6_port = 0, sin6_flowinfo = 0, sin6_addr = {__in6_u = {__u6_addr8 = '\000' <repeats 15 times>, "\001", __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 256}, __u6_addr32 = {0, 0, 0, 16777216}}}, sin6_scope_id = 0}, ss = {ss_family = 10, __ss_padding = '\000' <repeats 21 times>, "\001", '\000' <repeats 95 times>, __ss_align = 0}, sunix = {sun_family = 10, sun_path = '\000' <repeats 21 times>, "\001", '\000' <repeats 85 times>}}, length = 28, link = {prev = 0xffffffffffffffff, next = 0xffffffffffffffff}}
#11 0x00007efd91dfb536 in isc__job_cb (idle=0x7efd8ebf0688) at job.c:75
job = 0x7efd8ebf0680
r = <optimized out>
__func__ = "isc__job_cb"
#12 0x00007efd91ba7a49 in uv.run_idle () from /lib64/libuv.so.1
No symbol table info available.
#13 0x00007efd91ba0bf8 in uv_run () from /lib64/libuv.so.1
No symbol table info available.
#14 0x00007efd91e01b44 in loop_run (loop=0x7efd8eaa4fc0) at loop.c:267
r = <optimized out>
job = <optimized out>
r = <optimized out>
job = <optimized out>
__func__ = "loop_run"
next = <optimized out>
#15 loop_thread (arg=0x7efd8eaa4fc0) at loop.c:294
loop = 0x7efd8eaa4fc0
#16 0x00007efd91e1b87f in isc__trampoline_run (arg=0x1847a10) at trampoline.c:198
trampoline = 0x1847a10
result = <optimized out>
#17 0x00007efd90de91df in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#18 0x00007efd90a55dd3 in clone () from /lib64/libc.so.6
No symbol table info available.
Thread 5 (Thread 0x7efd8beff700 (LWP 7971)):
#0 0x00007efd90df05be in pthread_barrier_wait () from /lib64/libpthread.so.0
No symbol table info available.
#1 0x00007efd91bada7d in uv_barrier_wait () from /lib64/libuv.so.1
No symbol table info available.
#2 0x00007efd91de8154 in isc__nm_async_tcpdnsstop (worker=worker@entry=0x7efd8ead4140, ev0=ev0@entry=0x7efd8ea89900) at netmgr/tcpdns.c:670
ievent = 0x7efd8ea89900
sock = 0x7efd8e31a820
__func__ = "isc__nm_async_tcpdnsstop"
#3 0x00007efd91de27d2 in process_netievent (arg=0x7efd8ea89900) at netmgr/netmgr.c:463
ievent = 0x7efd8ea89900
worker = 0x7efd8ead4140
#4 0x00007efd91dfb536 in isc__job_cb (idle=0x7efd8ebf0b08) at job.c:75
job = 0x7efd8ebf0b00
r = <optimized out>
__func__ = "isc__job_cb"
#5 0x00007efd91ba7a49 in uv.run_idle () from /lib64/libuv.so.1
No symbol table info available.
#6 0x00007efd91ba0bf8 in uv_run () from /lib64/libuv.so.1
No symbol table info available.
#7 0x00007efd91e01b44 in loop_run (loop=0x7efd8eaa3260) at loop.c:267
r = <optimized out>
job = <optimized out>
r = <optimized out>
job = <optimized out>
__func__ = "loop_run"
next = <optimized out>
#8 loop_thread (arg=0x7efd8eaa3260) at loop.c:294
loop = 0x7efd8eaa3260
#9 0x00007efd91e1b87f in isc__trampoline_run (arg=0x1846020) at trampoline.c:198
trampoline = 0x1846020
result = <optimized out>
#10 0x00007efd90de91df in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#11 0x00007efd90a55dd3 in clone () from /lib64/libc.so.6
No symbol table info available.
Thread 4 (Thread 0x7efd92768140 (LWP 7887)):
#0 0x00007efd90df05be in pthread_barrier_wait () from /lib64/libpthread.so.0
No symbol table info available.
#1 0x00007efd91bada7d in uv_barrier_wait () from /lib64/libuv.so.1
No symbol table info available.
#2 0x00007efd91de8154 in isc__nm_async_tcpdnsstop (worker=worker@entry=0x7efd8ead4000, ev0=ev0@entry=0x7efd8ea8b700) at netmgr/tcpdns.c:670
ievent = 0x7efd8ea8b700
sock = 0x7efd8e317d00
__func__ = "isc__nm_async_tcpdnsstop"
#3 0x00007efd91de27d2 in process_netievent (arg=0x7efd8ea8b700) at netmgr/netmgr.c:463
ievent = 0x7efd8ea8b700
worker = 0x7efd8ead4000
#4 0x00007efd91de2af3 in isc__nm_process_ievent (worker=<optimized out>, event=<optimized out>) at netmgr/netmgr.c:567
No locals.
#5 0x00007efd91de72c5 in stop_tcpdns_child (sock=sock@entry=0x7efd8e5d8c00, tid=tid@entry=0) at netmgr/tcpdns.c:605
csock = 0x7efd8e317d00
ievent = <optimized out>
#6 0x00007efd91de7c14 in isc__nm_tcpdns_stoplistening (sock=0x7efd8e5d8c00) at netmgr/tcpdns.c:632
__func__ = "isc__nm_tcpdns_stoplistening"
#7 0x00007efd91ddf096 in isc_nm_stoplistening (sock=<optimized out>) at netmgr/netmgr.c:2091
No locals.
#8 0x0000000000403c86 in stop_listening (arg=<optimized out>) at tcpdns_test.c:45
No locals.
#9 0x00007efd91dfb536 in isc__job_cb (idle=0x7efd8ebefe48) at job.c:75
job = 0x7efd8ebefe40
r = <optimized out>
__func__ = "isc__job_cb"
#10 0x00007efd91ba7a49 in uv.run_idle () from /lib64/libuv.so.1
No symbol table info available.
#11 0x00007efd91ba0bf8 in uv_run () from /lib64/libuv.so.1
No symbol table info available.
#12 0x00007efd91e01b44 in loop_run (loop=0x7efd8eaa1500) at loop.c:267
r = <optimized out>
job = <optimized out>
r = <optimized out>
job = <optimized out>
__func__ = "loop_run"
next = <optimized out>
#13 loop_thread (arg=0x7efd8eaa1500) at loop.c:294
loop = 0x7efd8eaa1500
#14 0x00007efd91e02b91 in isc_loopmgr_run (loopmgr=0x7efd8ea23540) at loop.c:474
__func__ = "isc_loopmgr_run"
#15 0x0000000000403ae7 in run_test_tcpdns_recv_send (state=<optimized out>) at tcpdns_test.c:121
No locals.
#16 0x00007efd91782f37 in cmocka_run_one_test_or_fixture () from /lib64/libcmocka.so.0
No symbol table info available.
#17 0x00007efd917838a1 in _cmocka_run_group_tests () from /lib64/libcmocka.so.0
No symbol table info available.
#18 0x000000000040405e in main () at tcpdns_test.c:153
r = <optimized out>
Thread 3 (Thread 0x7efd8aefd700 (LWP 7973)):
#0 0x00007efd90df05be in pthread_barrier_wait () from /lib64/libpthread.so.0
No symbol table info available.
#1 0x00007efd91bada7d in uv_barrier_wait () from /lib64/libuv.so.1
No symbol table info available.
#2 0x00007efd91de8154 in isc__nm_async_tcpdnsstop (worker=worker@entry=0x7efd8ead41c0, ev0=ev0@entry=0x7efd8ea8ae00) at netmgr/tcpdns.c:670
ievent = 0x7efd8ea8ae00
sock = 0x7efd8e31b960
__func__ = "isc__nm_async_tcpdnsstop"
#3 0x00007efd91de27d2 in process_netievent (arg=0x7efd8ea8ae00) at netmgr/netmgr.c:463
ievent = 0x7efd8ea8ae00
worker = 0x7efd8ead41c0
#4 0x00007efd91dfb536 in isc__job_cb (idle=0x7efd8ebf0c88) at job.c:75
job = 0x7efd8ebf0c80
r = <optimized out>
__func__ = "isc__job_cb"
#5 0x00007efd91ba7a49 in uv.run_idle () from /lib64/libuv.so.1
No symbol table info available.
#6 0x00007efd91ba0bf8 in uv_run () from /lib64/libuv.so.1
No symbol table info available.
#7 0x00007efd91e01b44 in loop_run (loop=0x7efd8eaa3e20) at loop.c:267
r = <optimized out>
job = <optimized out>
r = <optimized out>
job = <optimized out>
__func__ = "loop_run"
next = <optimized out>
#8 loop_thread (arg=0x7efd8eaa3e20) at loop.c:294
loop = 0x7efd8eaa3e20
#9 0x00007efd91e1b87f in isc__trampoline_run (arg=0x1846080) at trampoline.c:198
trampoline = 0x1846080
result = <optimized out>
#10 0x00007efd90de91df in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#11 0x00007efd90a55dd3 in clone () from /lib64/libc.so.6
No symbol table info available.
Thread 2 (Thread 0x7efd837fe700 (LWP 7970)):
#0 0x00007efd90df05be in pthread_barrier_wait () from /lib64/libpthread.so.0
No symbol table info available.
#1 0x00007efd91bada7d in uv_barrier_wait () from /lib64/libuv.so.1
No symbol table info available.
#2 0x00007efd91de8154 in isc__nm_async_tcpdnsstop (worker=worker@entry=0x7efd8ead4100, ev0=ev0@entry=0x7efd8ea8be80) at netmgr/tcpdns.c:670
ievent = 0x7efd8ea8be80
sock = 0x7efd8e319f80
__func__ = "isc__nm_async_tcpdnsstop"
#3 0x00007efd91de27d2 in process_netievent (arg=0x7efd8ea8be80) at netmgr/netmgr.c:463
ievent = 0x7efd8ea8be80
worker = 0x7efd8ead4100
#4 0x00007efd91dfb536 in isc__job_cb (idle=0x7efd8ebf08c8) at job.c:75
job = 0x7efd8ebf08c0
r = <optimized out>
__func__ = "isc__job_cb"
#5 0x00007efd91ba7a49 in uv.run_idle () from /lib64/libuv.so.1
No symbol table info available.
#6 0x00007efd91ba0bf8 in uv_run () from /lib64/libuv.so.1
No symbol table info available.
#7 0x00007efd91e01b44 in loop_run (loop=0x7efd8eaa2c80) at loop.c:267
r = <optimized out>
job = <optimized out>
r = <optimized out>
job = <optimized out>
__func__ = "loop_run"
next = <optimized out>
#8 loop_thread (arg=0x7efd8eaa2c80) at loop.c:294
loop = 0x7efd8eaa2c80
#9 0x00007efd91e1b87f in isc__trampoline_run (arg=0x1845ff0) at trampoline.c:198
trampoline = 0x1845ff0
result = <optimized out>
#10 0x00007efd90de91df in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#11 0x00007efd90a55dd3 in clone () from /lib64/libc.so.6
No symbol table info available.
Thread 1 (Thread 0x7efd89efb700 (LWP 7975)):
#0 0x00007efd90a6aa9f in raise () from /lib64/libc.so.6
No symbol table info available.
#1 0x00007efd90a3de05 in abort () from /lib64/libc.so.6
No symbol table info available.
#2 0x00007efd91df111d in isc_assertion_failed (file=file@entry=0x7efd91e2ff0b "mem.c", line=line@entry=772, type=type@entry=isc_assertiontype_require, cond=cond@entry=0x7efd91e304a0 "((ctx) != ((void *)0) && ((const isc__magic_t *)(ctx))->magic == ((('M') << 24 | ('e') << 16 | ('m') << 8 | ('C'))))") at assertions.c:50
No locals.
#3 0x00007efd91e04800 in isc__mem_get (ctx=<optimized out>, size=size@entry=2208, flags=flags@entry=0, file=file@entry=0x7efd91e2a6f2 "netmgr/tcpdns.c", line=line@entry=269) at mem.c:781
ptr = 0x0
#4 0x00007efd91de92af in isc_nm_tcpdnsconnect (mgr=<optimized out>, local=0x6084e0 <tcp_connect_addr>, peer=0x608580 <tcp_listen_addr>, cb=0x40529c <connect_connect_cb>, cbarg=cbarg@entry=0x403ae9 <tcpdns_connect>, timeout=timeout@entry=30000) at netmgr/tcpdns.c:269
result = ISC_R_SUCCESS
sock = 0x0
ievent = 0x0
req = 0x0
sa_family = 10
worker = 0x7efd8ead45c0
__func__ = "isc_nm_tcpdnsconnect"
#5 0x0000000000403b0d in tcpdns_connect (nm=<optimized out>) at tcpdns_test.c:63
No locals.
#6 0x00000000004040ec in stream_recv_send_connect (arg=0x403ae9 <tcpdns_connect>) at netmgr_common.c:516
connect = 0x403ae9 <tcpdns_connect>
connect_addr = {type = {sa = {sa_family = 10, sa_data = '\000' <repeats 13 times>}, sin = {sin_family = 10, sin_port = 0, sin_addr = {s_addr = 0}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 10, sin6_port = 0, sin6_flowinfo = 0, sin6_addr = {__in6_u = {__u6_addr8 = '\000' <repeats 15 times>, "\001", __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 256}, __u6_addr32 = {0, 0, 0, 16777216}}}, sin6_scope_id = 0}, ss = {ss_family = 10, __ss_padding = '\000' <repeats 21 times>, "\001", '\000' <repeats 95 times>, __ss_align = 0}, sunix = {sun_family = 10, sun_path = '\000' <repeats 21 times>, "\001", '\000' <repeats 85 times>}}, length = 28, link = {prev = 0xffffffffffffffff, next = 0xffffffffffffffff}}
#7 0x00007efd91dfb536 in isc__job_cb (idle=0x7efd8ebf05c8) at job.c:75
job = 0x7efd8ebf05c0
r = <optimized out>
__func__ = "isc__job_cb"
#8 0x00007efd91ba7a49 in uv.run_idle () from /lib64/libuv.so.1
No symbol table info available.
#9 0x00007efd91ba0bf8 in uv_run () from /lib64/libuv.so.1
No symbol table info available.
#10 0x00007efd91e01b44 in loop_run (loop=0x7efd8eaa49e0) at loop.c:267
r = <optimized out>
job = <optimized out>
r = <optimized out>
job = <optimized out>
__func__ = "loop_run"
next = <optimized out>
#11 loop_thread (arg=0x7efd8eaa49e0) at loop.c:294
loop = 0x7efd8eaa49e0
#12 0x00007efd91e1b87f in isc__trampoline_run (arg=0x1847870) at trampoline.c:198
trampoline = 0x1847870
result = <optimized out>
#13 0x00007efd90de91df in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#14 0x00007efd90a55dd3 in clone () from /lib64/libc.so.6
No symbol table info available.
D:tcpdns_test:backtrace from ./core.7887 end
FAIL tcpdns_test (exit status: 134)
```
</details>Not plannedhttps://gitlab.isc.org/isc-projects/bind9/-/issues/3695Improvement: Including query time in dnstap CLIENT_RESPONSE messages2023-01-11T12:15:33ZBorja Marcos EA2EKHImprovement: Including query time in dnstap CLIENT_RESPONSE messages### Description
While the dnstap specification recommends including the query time for AUTH_RESPONSE, RESOLVER_RESPONSE and
CLIENT_RESPONSE dnstap messages, the latter is excluded.
Having the query time in CLIENT_RESPONSE dnstap messa...### Description
While the dnstap specification recommends including the query time for AUTH_RESPONSE, RESOLVER_RESPONSE and
CLIENT_RESPONSE dnstap messages, the latter is excluded.
Having the query time in CLIENT_RESPONSE dnstap messages would be very useful when using dnstap to keep track
of response times.
### Request
In lib/dns/dnstap.c (both for 9.16 and 9.18) the dns_dt_send function accepts the qtime and rtime parameters.
However, when building the dnstap message, CLIENT_RESPONSE messages are prevented from using the qtime parameter.
` dm.m.has_response_time_sec = 1;
dm.m.response_time_nsec = isc_time_nanoseconds(t);
dm.m.has_response_time_nsec = 1;
/*
* Types CR, RR, and FR can fall through and get the query
* time set as well. Any other response type, break.
*/
if (msgtype != DNS_DTTYPE_RR && msgtype != DNS_DTTYPE_FR
&& msgtype != DNS_DTTYPE_CR) { // << I HAVE ADDED THIS!
break;
}
FALLTHROUGH;
case DNS_DTTYPE_AQ:
case DNS_DTTYPE_CQ:
case DNS_DTTYPE_FQ:
case DNS_DTTYPE_RQ:
case DNS_DTTYPE_SQ:
case DNS_DTTYPE_TQ:
case DNS_DTTYPE_UQ:
if (qtime != NULL) {
t = qtime;
}
dm.m.query_time_sec = isc_time_seconds(t);
dm.m.has_query_time_sec = 1;
dm.m.query_time_nsec = isc_time_nanoseconds(t);
dm.m.has_query_time_nsec = 1;
break;
`
I have tried making the simple change shown above (so that qtime is considered for
CLIENT_RESPONSE messages as well) and it works both for 9.16.35 and 9.18.9.
The change looks safe enough (it won´t crash because if qtime is NULL t will contain a
timestamp obtained when dns_dt_send() is invoked) and at worst it would contain a false
qtime.
A more correct alternative would be to include it for CLIENT_RESPONSE messages only if qtime != NULL. But
I don´t know whether it can happen or all the calls to dns_dt_send() will contain qtime.
Also, is it possible for qtime to be missing for a CLIENT_RESPONSE but not for a RESOLVER_RESPONSE? Because for a RESOLVER_RESPONSE it would mean that query time in the dnstap message would contain the timestamp obtained in dns_dt_send() and, being probably
greater than the response time itself that would botch a time difference calculation.
### Links / referencesNot plannedhttps://gitlab.isc.org/isc-projects/bind9/-/issues/3698rndc can get very very slow if large number of requests is made over short pe...2023-01-12T11:25:12ZPetr Špačekpspacek@isc.orgrndc can get very very slow if large number of requests is made over short period of time### Summary
rndc can get very very slow if large number of requests is made over short period of time. Primary cause seems to be that packet deduplication goes O(n^2).
### BIND version used
- ~"Affects v9.19" : e2bbf38cdb42de70d504b2f...### Summary
rndc can get very very slow if large number of requests is made over short period of time. Primary cause seems to be that packet deduplication goes O(n^2).
### BIND version used
- ~"Affects v9.19" : e2bbf38cdb42de70d504b2ff281fb360cd0f27c0
- I assume that supported versions are affected
### Steps to reproduce
TL;DR call `rndc addzone` in a tight loop, and measure response time.
Helper scripts:
* [addconfprim.py](/uploads/129fa9ac79cd590c9172e6d61f28a59f/addconfprim.py) - run this
* [rndc.py](/uploads/23c2eba46244ac7decbe865d84a92052/rndc.py)
### What is the current *bug* behavior?
Adding zones slows down very quickly.
```
33000 zones present; adding last 1000 took 1.93 secs
...
65000 zones present; adding last 1000 took 4.42 secs
```
### What is the expected *correct* behavior?
No speed degradation.
### Relevant configuration files
```
key "key" {
algorithm hmac-sha256;
secret "ptCZS/77Xm2sIzCdO/oxEoer2BbDgCfvF0CrqrcdRWM=";
};
options {
max-cache-size 10M;
recursion no;
notify no;
allow-new-zones yes;
lmdb-mapsize 110M;
};
```
* [empty.db](/uploads/da7366d7d37edc16d43b7280f7cbaf6f/empty.db)
### Possible fixes
From a quick glance, the problem centers around `DUP_LIFETIME` defined in `lib/isccc/cc.c` and in the inefficiency of `isccc_cc_cleansymtab()` and it's use.https://gitlab.isc.org/isc-projects/bind9/-/issues/3803Delayed zone deletion2023-01-17T07:51:26ZOndřej SurýDelayed zone deletionWhen zones are removed from the configuration, the process to release the memory held by the deleted zones could take even minute or more if the server is busy.
This has been (partially?) fixed in `main` which doesn't exhibit the behavi...When zones are removed from the configuration, the process to release the memory held by the deleted zones could take even minute or more if the server is busy.
This has been (partially?) fixed in `main` which doesn't exhibit the behaviour, but it's true for 9.16 and 9.18. This can be reproduced by doing something like this:
1. add zone <n+1> to `zones.conf`
2. del zone <n> to `zones.conf`
3. run `rndc reconfig`
4. repeat
It's now roughly at `dom170883.example` and the server consumes 3.2GB of memory.
This is not normal mode of operation, but in the environment that provides short-lived domains for containers, it's very much plausible.
I've had a `jeprof` output with symbols, but alas, I've deleted the binary, so you need to trust me that the 99% is all `dns_zone_create()`:
![Screenshot_2023-01-17_at_8.50.40](/uploads/afa578c916aceda4ae64e73a25466e2e/Screenshot_2023-01-17_at_8.50.40.png)https://gitlab.isc.org/isc-projects/bind9/-/issues/3809zones deleted during asyncload are never freed2023-01-18T16:02:17ZOndřej Surýzones deleted during asyncload are never freedZones that are deleted during the asyncload go into spiral:
```
dns_zone_create:::0:0x7f4c0b3c4e00->irefs = 0
zone_iattach:asyncload:zt.c:370:0x7f4c0b3c4e00->irefs = 2
dns_zone__idetach:zone_asyncload:zone.c:2423:0x7f4c0b3c4e00->irefs =...Zones that are deleted during the asyncload go into spiral:
```
dns_zone_create:::0:0x7f4c0b3c4e00->irefs = 0
zone_iattach:asyncload:zt.c:370:0x7f4c0b3c4e00->irefs = 2
dns_zone__idetach:zone_asyncload:zone.c:2423:0x7f4c0b3c4e00->irefs = 1
[...13k...]
zone_iattach:asyncload:zt.c:370:0x7f4c0b3c4e00->irefs = 2
dns_zone__idetach:zone_asyncload:zone.c:2423:0x7f4c0b3c4e00->irefs = 1
[...continues...]
```