BIND issueshttps://gitlab.isc.org/isc-projects/bind9/-/issues2023-11-06T08:52:44Zhttps://gitlab.isc.org/isc-projects/bind9/-/issues/3303assertion failure in isc_quota_destroy() on shutdown2023-11-06T08:52:44ZOndřej Surýassertion failure in isc_quota_destroy() on shutdownhttps://gitlab.isc.org/isc-projects/bind9/-/jobs/2469476
```
D:tcp:--------------------------------------------------------------------------------
D:tcp:Core was generated by `/builds/isc-projects/bind9/bin/named/.libs/named -D tcp-ns7 ...https://gitlab.isc.org/isc-projects/bind9/-/jobs/2469476
```
D:tcp:--------------------------------------------------------------------------------
D:tcp:Core was generated by `/builds/isc-projects/bind9/bin/named/.libs/named -D tcp-ns7 -X named.lock -m re'.
D:tcp:Program terminated with signal SIGABRT, Aborted.
D:tcp:#0 0xf7f88069 in __kernel_vsyscall ()
D:tcp:#0 0xf7f88069 in __kernel_vsyscall ()
D:tcp:#1 0xf72a0e02 in raise () from /lib/i386-linux-gnu/libc.so.6
D:tcp:#2 0xf7289306 in abort () from /lib/i386-linux-gnu/libc.so.6
D:tcp:#3 0x5663478e in assertion_failed (file=0xf7ce6750 "quota.c", line=46, type=isc_assertiontype_insist, cond=0xf7ce6908 "__extension__ ({ __auto_type __atomic_load_ptr = ("a->waiting); __typeof__ (*__atomic_load_ptr) __atomic_load_tmp; __atomic_load (__atomic_load_ptr, &__atomic_load_tmp, (5)); __atomic_load_tmp; })"...) at main.c:237
D:tcp:#4 0xf7cab95f in isc_assertion_failed (file=0xf7ce6750 "quota.c", line=46, type=isc_assertiontype_insist, cond=0xf7ce6908 "__extension__ ({ __auto_type __atomic_load_ptr = ("a->waiting); __typeof__ (*__atomic_load_ptr) __atomic_load_tmp; __atomic_load (__atomic_load_ptr, &__atomic_load_tmp, (5)); __atomic_load_tmp; })"...) at assertions.c:49
D:tcp:#5 0xf7cc1ce5 in isc_quota_destroy (quota=0xf422e078) at quota.c:46
D:tcp:#6 0xf7a6592b in ns_server_detach (sctxp=0xf4ee7108) at server.c:139
D:tcp:#7 0x56644360 in named_server_destroy (serverp=0x566986c8 <named_g_server>) at server.c:10358
D:tcp:#8 0x56636897 in cleanup () at main.c:1262
D:tcp:#9 main (argc=18, argv=0xff828604) at main.c:1492
D:tcp:--------------------------------------------------------------------------------
D:tcp:full backtrace from tcp/ns7/core.19616 saved in tcp/ns7/core.19616-backtrace.txt
```
I've seen this one before intermittently...Not plannedhttps://gitlab.isc.org/isc-projects/bind9/-/issues/3058SUMMARY: ThreadSanitizer: data race in read2023-11-02T17:02:21ZOndřej SurýSUMMARY: ThreadSanitizer: data race in readThis almost seems like we are passing some buffer to isc_task that libuv is still using.
```
==================
WARNING: ThreadSanitizer: data race (pid=22062)
Write of size 8 at 0x7fdcbeac0000 by thread T9:
#0 read <null> (libtsa...This almost seems like we are passing some buffer to isc_task that libuv is still using.
```
==================
WARNING: ThreadSanitizer: data race (pid=22062)
Write of size 8 at 0x7fdcbeac0000 by thread T9:
#0 read <null> (libtsan.so.0+0x4ace2)
#1 uv__read /usr/src/libuv-v1.42.0/src/unix/stream.c:1164 (libuv.so.1+0x227e1)
#2 isc__trampoline_run /builds/isc-projects/bind9/lib/isc/trampoline.c:185 (libisc-9.17.20.so+0x7b0e1)
Previous read of size 8 at 0x7fdcbeac0000 by thread T8:
#0 memmove <null> (libtsan.so.0+0x5da6e)
#1 memmove /usr/include/bits/string_fortified.h:36 (libisc-9.17.20.so+0x453d9)
#2 isc_buffer_copyregion /builds/isc-projects/bind9/lib/isc/buffer.c:530 (libisc-9.17.20.so+0x453d9)
#3 dns_zone_forwardupdate /builds/isc-projects/bind9/lib/dns/zone.c:18408 (libdns-9.17.20.so+0x22081d)
#4 forward_action /builds/isc-projects/bind9/lib/ns/update.c:3748 (libns-9.17.20.so+0x516d6)
#5 task_run /builds/isc-projects/bind9/lib/isc/task.c:827 (libisc-9.17.20.so+0x7237a)
#6 isc_task_run /builds/isc-projects/bind9/lib/isc/task.c:907 (libisc-9.17.20.so+0x7237a)
#7 isc__nm_async_task netmgr/netmgr.c:835 (libisc-9.17.20.so+0x1e9ab)
#8 process_netievent netmgr/netmgr.c:914 (libisc-9.17.20.so+0x27efb)
#9 process_queue netmgr/netmgr.c:1008 (libisc-9.17.20.so+0x28a2a)
#10 process_all_queues netmgr/netmgr.c:754 (libisc-9.17.20.so+0x29353)
#11 async_cb netmgr/netmgr.c:783 (libisc-9.17.20.so+0x29353)
#12 uv__async_io /usr/src/libuv-v1.42.0/src/unix/async.c:163 (libuv.so.1+0x110ef)
#13 isc__trampoline_run /builds/isc-projects/bind9/lib/isc/trampoline.c:185 (libisc-9.17.20.so+0x7b0e1)
Location is heap block of size 1310720 at 0x7fdcbeac0000 allocated by main thread:
#0 malloc <null> (libtsan.so.0+0x32919)
#1 mallocx /builds/isc-projects/bind9/lib/isc/jemalloc_shim.h:33 (libisc-9.17.20.so+0x5b02a)
#2 mem_get /builds/isc-projects/bind9/lib/isc/mem.c:343 (libisc-9.17.20.so+0x5b02a)
#3 isc__mem_get /builds/isc-projects/bind9/lib/isc/mem.c:758 (libisc-9.17.20.so+0x5b02a)
#4 isc__netmgr_create netmgr/netmgr.c:319 (libisc-9.17.20.so+0x1f2a4)
#5 isc_managers_create /builds/isc-projects/bind9/lib/isc/managers.c:39 (libisc-9.17.20.so+0x59ef2)
#6 create_managers /builds/isc-projects/bind9/bin/named/main.c:920 (named+0x424a19)
#7 setup /builds/isc-projects/bind9/bin/named/main.c:1184 (named+0x424a19)
#8 main /builds/isc-projects/bind9/bin/named/main.c:1452 (named+0x424a19)
Thread T9 'isc-net-0008' (tid=22096, running) created by main thread at:
#0 pthread_create <null> (libtsan.so.0+0x5bf45)
#1 isc_thread_create /builds/isc-projects/bind9/lib/isc/thread.c:79 (libisc-9.17.20.so+0x7466d)
#2 isc__netmgr_create netmgr/netmgr.c:328 (libisc-9.17.20.so+0x1f34b)
#3 isc_managers_create /builds/isc-projects/bind9/lib/isc/managers.c:39 (libisc-9.17.20.so+0x59ef2)
#4 create_managers /builds/isc-projects/bind9/bin/named/main.c:920 (named+0x424a19)
#5 setup /builds/isc-projects/bind9/bin/named/main.c:1184 (named+0x424a19)
#6 main /builds/isc-projects/bind9/bin/named/main.c:1452 (named+0x424a19)
Thread T8 'isc-net-0007' (tid=22094, running) created by main thread at:
#0 pthread_create <null> (libtsan.so.0+0x5bf45)
#1 isc_thread_create /builds/isc-projects/bind9/lib/isc/thread.c:79 (libisc-9.17.20.so+0x7466d)
#2 isc__netmgr_create netmgr/netmgr.c:328 (libisc-9.17.20.so+0x1f34b)
#3 isc_managers_create /builds/isc-projects/bind9/lib/isc/managers.c:39 (libisc-9.17.20.so+0x59ef2)
#4 create_managers /builds/isc-projects/bind9/bin/named/main.c:920 (named+0x424a19)
#5 setup /builds/isc-projects/bind9/bin/named/main.c:1184 (named+0x424a19)
#6 main /builds/isc-projects/bind9/bin/named/main.c:1452 (named+0x424a19)
SUMMARY: ThreadSanitizer: data race (/lib64/libtsan.so.0+0x4ace2) in read
==================
ThreadSanitizer: reported 1 warnings
```Not plannedhttps://gitlab.isc.org/isc-projects/bind9/-/issues/2953Resolver issues with refactored dispatch code2023-11-02T17:02:19ZMichał KępieńResolver issues with refactored dispatch codeThis issue attempts to describe various issues with resolver behavior
found after merging !4601 (#2401). Most of these issues are
intermittent, so it is important to keep track of them somewhere in
order to not forget that they exist. ...This issue attempts to describe various issues with resolver behavior
found after merging !4601 (#2401). Most of these issues are
intermittent, so it is important to keep track of them somewhere in
order to not forget that they exist. We should get to the bottom of all
of these issues before we release BIND 9.18.0.
1. [x] **Recursive Perflab tests cause the resolver to stop responding.**
This issue might be the simplest to start with because the behavior
observed seems to be consistent rather than intermittent. Namely,
all Perflab jobs which test a resolver seem to crank out a response
rate of some 70-120 kQPS at the beginning of the test and then...
the resolver stops responding indefinitely. While Perflab was not
designed with recursive tests in mind and therefore we can treat its
recursive results with a grain of salt, it certainly should not be
reporting zeros all over the place.
- https://perflab.isc.org/#/config/run/5bf195dd83ba91a870b2976f/
- https://perflab.isc.org/#/config/run/5cd6a166643076f6c1f6c26f/
- https://perflab.isc.org/#/config/run/5db74b6264458967f762143a/
- https://perflab.isc.org/#/config/run/5db74b7264458967f762143b/
- https://perflab.isc.org/#/config/run/5db74c2764458967f7621440/
- https://perflab.isc.org/#/config/run/5db74c3464458967f7621441/
(Resolved by !5500.)
2. [x] **`respdiff` tests are *sometimes* slow.**
Ever since we merged the dispatch branch, the `respdiff` tests
started failing *intermittently* for `main` (and only `main`)
because of timeouts.
- [job 2016337][1]: pass, ~2m30s per each 10,000 queries
- [job 2016622][2]: pass, ~2m45s per each 10,000 queries
- [job 2017990][3]: pass, ~2m30s per each 10,000 queries
- [job 2020093][4]: fail, 7+ minutes per each 10,000 queries
- [job 2023057][5]: fail, 16+ minutes per each 10,000 queries
- [job 2023490][6]: pass, ~2m40s per each 10,000 queries
I do not think varying CI runner stress can be blamed for this, not
for discrepancies this large. It also never happened before merging
!4601, AFAIK.
3. [x] **A lot of "stress" test graph indicate growing memory use.** #3002
While testing October BIND 9 releases, one of the 1-hour "stress"
tests ran in recursive mode for BIND 9.17.19 yielded a graph which
indicates that memory use growth over time might be an issue.
https://wiki.isc.org/bin/viewfile/QA/BindQaResults_9_11_36?filename=bind-9.17.19-linux-amd64-recursive-1h.png;rev=1
However, that phenomenon was not observable for other OS/arch
combinations this specific code revision was tested with.
It was also not observable on the *same* OS/arch combination for a
very similar code revision (the code differences should not have any
effect on memory use patterns):
https://wiki.isc.org/bin/viewfile/QA/BindQaResults_9_11_36?filename=bind-9.17.19-linux-amd64-recursive-1h.png;rev=2
Pre-release tests run for BIND 9.17.20 confirmed that memory leaks
are a common thing when `named` is used as a recursive resolver.
More details are available in #3002.
The "stress" tests are run on isolated VMs and despite being pretty
synthetic (fixed traffic pattern, everything happens on one machine,
etc.), they have a history of being very stable, so typical issues
like test host load varying over time etc. are not a factor here.
4. [x] **Lame servers with IPv6 unreachable cause hang on shutdown.** #2927
5. [x] **resolver test fails intermittently** #3013
See https://gitlab.isc.org/isc-projects/bind9/-/jobs/2054296
```
I:resolver:query count error: 6 NS records: expected queries 10, actual 11
I:resolver:failed
```
6. [x] **Assertion failed in `dns_resolver_logfetch()`** #2962
7. [x] **Assertion failed in `dns_dispatch_gettcp()`** #2963
8. [x] **Assertion failed in `dns_resolver_destroyfetch()`** #2969
9. [x] **ThreadSanitizer issues with adb** #2978 #2979
10. [x] **fctx_cancelquery() attempts to process a query which has already been freed** #3018
11. [x] **premature TCP connection closure leaks fetch contexts (hang on shutdown)** #3026
12. [ ] **validator loops can cause shutdown hang** #3033
13. [ ] **ADB finds for a broken zone may cause fetch contexts to hang** #3037
14. [ ] **ASAN error in fctx_cancelquery()** #3102
I decided to open a single issue for all of the above problems because I
sense they are somehow related and I hope that fixing the root cause of
one of them will eliminate the other ones as well.
[1]: https://gitlab.isc.org/isc-projects/bind9/-/jobs/2016337
[2]: https://gitlab.isc.org/isc-projects/bind9/-/jobs/2016622
[3]: https://gitlab.isc.org/isc-projects/bind9/-/jobs/2017990
[4]: https://gitlab.isc.org/isc-projects/bind9/-/jobs/2020093
[5]: https://gitlab.isc.org/isc-projects/bind9/-/jobs/2023057
[6]: https://gitlab.isc.org/isc-projects/bind9/-/jobs/2023490Not plannedhttps://gitlab.isc.org/isc-projects/bind9/-/issues/2730[ISC-support #18552] Logging category for notify/xfer related messages2024-03-27T13:17:04ZChuck Stearns[ISC-support #18552] Logging category for notify/xfer related messages### Description
Logging category for notify/xfer related messages
### Request
The notify category does not include some messages that end up in the general category. There are also some messages that might be better placed in xfer-in....### Description
Logging category for notify/xfer related messages
### Request
The notify category does not include some messages that end up in the general category. There are also some messages that might be better placed in xfer-in. For instance, "notify from" and "refused notify from non-master". The intent is to have all messages useful for troubleshooting an aspect of operation in one log. For example, if troubleshooting zone transfer issues, the relevant messages would be in the transfer.log. This segregation also facilitates some noise reduction when using dynamic severity.
### Links / referencesNot plannedhttps://gitlab.isc.org/isc-projects/bind9/-/issues/2719ThreadSanitizer: data race between ns_client_endrequest->rdataset_disassociat...2022-03-01T09:56:24ZOndřej SurýThreadSanitizer: data race between ns_client_endrequest->rdataset_disassociate and rmzone->free_rbtdbFull report here (it doesn't happen in the CI, just locally):
```
==================
WARNING: ThreadSanitizer: data race (pid=1434821)
Write of size 8 at 0x7b98000603a8 by thread T1 (mutexes: write M599395980743702552):
#0 memset <...Full report here (it doesn't happen in the CI, just locally):
```
==================
WARNING: ThreadSanitizer: data race (pid=1434821)
Write of size 8 at 0x7b98000603a8 by thread T1 (mutexes: write M599395980743702552):
#0 memset <null> (named+0x445d29)
#1 mem_put /home/ondrej/Projects/bind9/lib/isc/mem.c:361:3 (libisc-9.17.13.so+0xd7a1c)
#2 isc__mem_free /home/ondrej/Projects/bind9/lib/isc/mem.c:1012:2 (libisc-9.17.13.so+0xd6f17)
#3 isc__mem_put /home/ondrej/Projects/bind9/lib/isc/mem.c:777:3 (libisc-9.17.13.so+0xd8ec8)
#4 free_rbtdb /home/ondrej/Projects/bind9/lib/dns/rbtdb.c:1203:2 (libdns-9.17.13.so+0x1c9a83)
#5 maybe_free_rbtdb /home/ondrej/Projects/bind9/lib/dns/rbtdb.c:1288:4 (libdns-9.17.13.so+0x1d9310)
#6 detach /home/ondrej/Projects/bind9/lib/dns/rbtdb.c:1300:3 (libdns-9.17.13.so+0x1cab3c)
#7 dns_db_detach /home/ondrej/Projects/bind9/lib/dns/db.c:155:2 (libdns-9.17.13.so+0x83d9b)
#8 zone_detachdb /home/ondrej/Projects/bind9/lib/dns/zone.c:17150:2 (libdns-9.17.13.so+0x40117e)
#9 zone_unload /home/ondrej/Projects/bind9/lib/dns/zone.c:11928:2 (libdns-9.17.13.so+0x3deee2)
#10 dns_zone_unload /home/ondrej/Projects/bind9/lib/dns/zone.c:11863:2 (libdns-9.17.13.so+0x3deca2)
#11 rmzone /home/ondrej/Projects/bind9/bin/named/server.c:14368:3 (named+0x4fbd3b)
#12 task_run /home/ondrej/Projects/bind9/lib/isc/task.c:816:5 (libisc-9.17.13.so+0xffd06)
#13 isc_task_run /home/ondrej/Projects/bind9/lib/isc/task.c:896:10 (libisc-9.17.13.so+0xff4f5)
#14 isc__nm_async_task /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:863:11 (libisc-9.17.13.so+0x47a8e)
#15 process_netievent /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:942:3 (libisc-9.17.13.so+0x3c0dc)
#16 process_queue /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:1032:16 (libisc-9.17.13.so+0x4792a)
#17 process_all_queues /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:783:25 (libisc-9.17.13.so+0x4774f)
#18 async_cb /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:812:6 (libisc-9.17.13.so+0x35482)
#19 uv__async_io /home/ondrej/Projects/tsan/libuv/src/unix/async.c:163:5 (libuv.so.1+0x15389)
#20 uv__io_poll /home/ondrej/Projects/tsan/libuv/src/unix/linux-core.c:462:11 (libuv.so.1+0x2ebb6)
#21 uv_run /home/ondrej/Projects/tsan/libuv/src/unix/core.c:392:5 (libuv.so.1+0x159ac)
#22 nm_thread /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:718:11 (libisc-9.17.13.so+0x3555e)
#23 isc__trampoline_run /home/ondrej/Projects/bind9/lib/isc/trampoline.c:184:11 (libisc-9.17.13.so+0x108746)
Previous atomic read of size 8 at 0x7b98000603a8 by thread T2:
#0 __tsan_atomic64_load <null> (named+0x487e0e)
#1 isc_rwlock_unlock /home/ondrej/Projects/bind9/lib/isc/rwlock.c:584:8 (libisc-9.17.13.so+0xf1287)
#2 detachnode /home/ondrej/Projects/bind9/lib/dns/rbtdb.c:5508:2 (libdns-9.17.13.so+0x1d1c0d)
#3 rdataset_disassociate /home/ondrej/Projects/bind9/lib/dns/rbtdb.c:8862:2 (libdns-9.17.13.so+0x1e4354)
#4 dns_rdataset_disassociate /home/ondrej/Projects/bind9/lib/dns/rdataset.c:111:2 (libdns-9.17.13.so+0x2d86cc)
#5 msgresetnames /home/ondrej/Projects/bind9/lib/dns/message.c:467:5 (libdns-9.17.13.so+0x142f07)
#6 msgreset /home/ondrej/Projects/bind9/lib/dns/message.c:542:2 (libdns-9.17.13.so+0x13613a)
#7 dns_message_reset /home/ondrej/Projects/bind9/lib/dns/message.c:762:2 (libdns-9.17.13.so+0x13609f)
#8 ns_client_endrequest /home/ondrej/Projects/bind9/lib/ns/client.c:212:2 (libns-9.17.13.so+0x16362)
#9 ns__client_reset_cb /home/ondrej/Projects/bind9/lib/ns/client.c:1536:2 (libns-9.17.13.so+0x155cd)
#10 nmhandle_detach_cb /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:1848:3 (libisc-9.17.13.so+0x40b3f)
#11 isc__nmhandle_detach /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:1804:3 (libisc-9.17.13.so+0x39a4f)
#12 isc___nm_uvreq_put /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:2462:3 (libisc-9.17.13.so+0x41b04)
#13 isc__nm_async_sendcb /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:2748:2 (libisc-9.17.13.so+0x46837)
#14 isc__nm_sendcb /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:2722:3 (libisc-9.17.13.so+0x41721)
#15 udp_send_cb /home/ondrej/Projects/bind9/lib/isc/netmgr/udp.c:560:2 (libisc-9.17.13.so+0x75549)
#16 uv__udp_run_completed /home/ondrej/Projects/tsan/libuv/src/unix/udp.c (libuv.so.1+0x2b9f9)
#17 uv__udp_io /home/ondrej/Projects/tsan/libuv/src/unix/udp.c:184:5 (libuv.so.1+0x2c94c)
#18 uv__run_pending /home/ondrej/Projects/tsan/libuv/src/unix/core.c:825:5 (libuv.so.1+0x15b87)
#19 uv_run /home/ondrej/Projects/tsan/libuv/src/unix/core.c:384:19 (libuv.so.1+0x15977)
#20 nm_thread /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:718:11 (libisc-9.17.13.so+0x3555e)
#21 isc__trampoline_run /home/ondrej/Projects/bind9/lib/isc/trampoline.c:184:11 (libisc-9.17.13.so+0x108746)
Location is heap block of size 11464 at 0x7b9800060000 allocated by thread T1:
#0 malloc <null> (named+0x43a74b)
#1 default_memalloc /home/ondrej/Projects/bind9/lib/isc/mem.c:411:8 (libisc-9.17.13.so+0xddffe)
#2 mem_get /home/ondrej/Projects/bind9/lib/isc/mem.c:343:8 (libisc-9.17.13.so+0xd8331)
#3 mem_allocateunlocked /home/ondrej/Projects/bind9/lib/isc/mem.c:918:7 (libisc-9.17.13.so+0xd9810)
#4 isc__mem_allocate /home/ondrej/Projects/bind9/lib/isc/mem.c:935:7 (libisc-9.17.13.so+0xd8195)
#5 isc__mem_get /home/ondrej/Projects/bind9/lib/isc/mem.c:740:11 (libisc-9.17.13.so+0xd7f8f)
#6 dns_rbtdb_create /home/ondrej/Projects/bind9/lib/dns/rbtdb.c:8631:22 (libdns-9.17.13.so+0x1c538e)
#7 dns_db_create /home/ondrej/Projects/bind9/lib/dns/db.c:118:13 (libdns-9.17.13.so+0x83693)
#8 axfr_makedb /home/ondrej/Projects/bind9/lib/dns/xfrin.c:292:11 (libdns-9.17.13.so+0x3c0105)
#9 axfr_init /home/ondrej/Projects/bind9/lib/dns/xfrin.c:280:2 (libdns-9.17.13.so+0x3bf8da)
#10 xfr_rr /home/ondrej/Projects/bind9/lib/dns/xfrin.c:597:4 (libdns-9.17.13.so+0x3beb45)
#11 xfrin_recv_done /home/ondrej/Projects/bind9/lib/dns/xfrin.c:1430:5 (libdns-9.17.13.so+0x3bd2fd)
#12 isc__nm_async_readcb /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:2706:2 (libisc-9.17.13.so+0x463f8)
#13 isc__nm_readcb /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:2681:3 (libisc-9.17.13.so+0x45eae)
#14 isc__nm_tcpdns_processbuffer /home/ondrej/Projects/bind9/lib/isc/netmgr/tcpdns.c:817:2 (libisc-9.17.13.so+0x574fd)
#15 processbuffer /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:2257:11 (libisc-9.17.13.so+0x4413f)
#16 isc__nm_process_sock_buffer /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:2282:25 (libisc-9.17.13.so+0x43fb5)
#17 isc__nm_tcpdns_read_cb /home/ondrej/Projects/bind9/lib/isc/netmgr/tcpdns.c:880:2 (libisc-9.17.13.so+0x57c28)
#18 uv__read /home/ondrej/Projects/tsan/libuv/src/unix/stream.c:1239:7 (libuv.so.1+0x280bc)
#19 uv__stream_io /home/ondrej/Projects/tsan/libuv/src/unix/stream.c:1306:5 (libuv.so.1+0x25cef)
#20 uv__io_poll /home/ondrej/Projects/tsan/libuv/src/unix/linux-core.c:462:11 (libuv.so.1+0x2ebb6)
#21 uv_run /home/ondrej/Projects/tsan/libuv/src/unix/core.c:392:5 (libuv.so.1+0x159ac)
#22 nm_thread /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:718:11 (libisc-9.17.13.so+0x3555e)
#23 isc__trampoline_run /home/ondrej/Projects/bind9/lib/isc/trampoline.c:184:11 (libisc-9.17.13.so+0x108746)
Mutex M599395980743702552 is already destroyed.
Thread T1 'isc-net-0000' (tid=1434862, running) created by main thread at:
#0 pthread_create <null> (named+0x43bf6b)
#1 isc_thread_create /home/ondrej/Projects/bind9/lib/isc/pthreads/thread.c:79:8 (libisc-9.17.13.so+0x10b706)
#2 isc__netmgr_create /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:347:3 (libisc-9.17.13.so+0x3535e)
#3 isc_managers_create /home/ondrej/Projects/bind9/lib/isc/managers.c:39:2 (libisc-9.17.13.so+0xd433e)
#4 create_managers /home/ondrej/Projects/bind9/bin/named/main.c:941:11 (named+0x4e4c71)
#5 setup /home/ondrej/Projects/bind9/bin/named/main.c:1216:11 (named+0x4e26d5)
#6 main /home/ondrej/Projects/bind9/bin/named/main.c:1507:2 (named+0x4e0e2b)
Thread T2 'isc-net-0001' (tid=1434882, running) created by main thread at:
#0 pthread_create <null> (named+0x43bf6b)
#1 isc_thread_create /home/ondrej/Projects/bind9/lib/isc/pthreads/thread.c:79:8 (libisc-9.17.13.so+0x10b706)
#2 isc__netmgr_create /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:347:3 (libisc-9.17.13.so+0x3535e)
#3 isc_managers_create /home/ondrej/Projects/bind9/lib/isc/managers.c:39:2 (libisc-9.17.13.so+0xd433e)
#4 create_managers /home/ondrej/Projects/bind9/bin/named/main.c:941:11 (named+0x4e4c71)
#5 setup /home/ondrej/Projects/bind9/bin/named/main.c:1216:11 (named+0x4e26d5)
#6 main /home/ondrej/Projects/bind9/bin/named/main.c:1507:2 (named+0x4e0e2b)
SUMMARY: ThreadSanitizer: data race (/home/ondrej/Projects/bind9/bin/named/.libs/named+0x445d29) in memset
==================
==================
WARNING: ThreadSanitizer: data race (pid=1434821)
Write of size 8 at 0x7b98000603b0 by thread T1 (mutexes: write M599395980743702552):
#0 memset <null> (named+0x445d29)
#1 mem_put /home/ondrej/Projects/bind9/lib/isc/mem.c:361:3 (libisc-9.17.13.so+0xd7a1c)
#2 isc__mem_free /home/ondrej/Projects/bind9/lib/isc/mem.c:1012:2 (libisc-9.17.13.so+0xd6f17)
#3 isc__mem_put /home/ondrej/Projects/bind9/lib/isc/mem.c:777:3 (libisc-9.17.13.so+0xd8ec8)
#4 free_rbtdb /home/ondrej/Projects/bind9/lib/dns/rbtdb.c:1203:2 (libdns-9.17.13.so+0x1c9a83)
#5 maybe_free_rbtdb /home/ondrej/Projects/bind9/lib/dns/rbtdb.c:1288:4 (libdns-9.17.13.so+0x1d9310)
#6 detach /home/ondrej/Projects/bind9/lib/dns/rbtdb.c:1300:3 (libdns-9.17.13.so+0x1cab3c)
#7 dns_db_detach /home/ondrej/Projects/bind9/lib/dns/db.c:155:2 (libdns-9.17.13.so+0x83d9b)
#8 zone_detachdb /home/ondrej/Projects/bind9/lib/dns/zone.c:17150:2 (libdns-9.17.13.so+0x40117e)
#9 zone_unload /home/ondrej/Projects/bind9/lib/dns/zone.c:11928:2 (libdns-9.17.13.so+0x3deee2)
#10 dns_zone_unload /home/ondrej/Projects/bind9/lib/dns/zone.c:11863:2 (libdns-9.17.13.so+0x3deca2)
#11 rmzone /home/ondrej/Projects/bind9/bin/named/server.c:14368:3 (named+0x4fbd3b)
#12 task_run /home/ondrej/Projects/bind9/lib/isc/task.c:816:5 (libisc-9.17.13.so+0xffd06)
#13 isc_task_run /home/ondrej/Projects/bind9/lib/isc/task.c:896:10 (libisc-9.17.13.so+0xff4f5)
#14 isc__nm_async_task /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:863:11 (libisc-9.17.13.so+0x47a8e)
#15 process_netievent /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:942:3 (libisc-9.17.13.so+0x3c0dc)
#16 process_queue /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:1032:16 (libisc-9.17.13.so+0x4792a)
#17 process_all_queues /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:783:25 (libisc-9.17.13.so+0x4774f)
#18 async_cb /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:812:6 (libisc-9.17.13.so+0x35482)
#19 uv__async_io /home/ondrej/Projects/tsan/libuv/src/unix/async.c:163:5 (libuv.so.1+0x15389)
#20 uv__io_poll /home/ondrej/Projects/tsan/libuv/src/unix/linux-core.c:462:11 (libuv.so.1+0x2ebb6)
#21 uv_run /home/ondrej/Projects/tsan/libuv/src/unix/core.c:392:5 (libuv.so.1+0x159ac)
#22 nm_thread /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:718:11 (libisc-9.17.13.so+0x3555e)
#23 isc__trampoline_run /home/ondrej/Projects/bind9/lib/isc/trampoline.c:184:11 (libisc-9.17.13.so+0x108746)
Previous atomic read of size 8 at 0x7b98000603b0 by thread T2:
#0 __tsan_atomic64_load <null> (named+0x487e0e)
#1 isc_rwlock_unlock /home/ondrej/Projects/bind9/lib/isc/rwlock.c:583:7 (libisc-9.17.13.so+0xf1247)
#2 detachnode /home/ondrej/Projects/bind9/lib/dns/rbtdb.c:5508:2 (libdns-9.17.13.so+0x1d1c0d)
#3 rdataset_disassociate /home/ondrej/Projects/bind9/lib/dns/rbtdb.c:8862:2 (libdns-9.17.13.so+0x1e4354)
#4 dns_rdataset_disassociate /home/ondrej/Projects/bind9/lib/dns/rdataset.c:111:2 (libdns-9.17.13.so+0x2d86cc)
#5 msgresetnames /home/ondrej/Projects/bind9/lib/dns/message.c:467:5 (libdns-9.17.13.so+0x142f07)
#6 msgreset /home/ondrej/Projects/bind9/lib/dns/message.c:542:2 (libdns-9.17.13.so+0x13613a)
#7 dns_message_reset /home/ondrej/Projects/bind9/lib/dns/message.c:762:2 (libdns-9.17.13.so+0x13609f)
#8 ns_client_endrequest /home/ondrej/Projects/bind9/lib/ns/client.c:212:2 (libns-9.17.13.so+0x16362)
#9 ns__client_reset_cb /home/ondrej/Projects/bind9/lib/ns/client.c:1536:2 (libns-9.17.13.so+0x155cd)
#10 nmhandle_detach_cb /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:1848:3 (libisc-9.17.13.so+0x40b3f)
#11 isc__nmhandle_detach /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:1804:3 (libisc-9.17.13.so+0x39a4f)
#12 isc___nm_uvreq_put /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:2462:3 (libisc-9.17.13.so+0x41b04)
#13 isc__nm_async_sendcb /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:2748:2 (libisc-9.17.13.so+0x46837)
#14 isc__nm_sendcb /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:2722:3 (libisc-9.17.13.so+0x41721)
#15 udp_send_cb /home/ondrej/Projects/bind9/lib/isc/netmgr/udp.c:560:2 (libisc-9.17.13.so+0x75549)
#16 uv__udp_run_completed /home/ondrej/Projects/tsan/libuv/src/unix/udp.c (libuv.so.1+0x2b9f9)
#17 uv__udp_io /home/ondrej/Projects/tsan/libuv/src/unix/udp.c:184:5 (libuv.so.1+0x2c94c)
#18 uv__run_pending /home/ondrej/Projects/tsan/libuv/src/unix/core.c:825:5 (libuv.so.1+0x15b87)
#19 uv_run /home/ondrej/Projects/tsan/libuv/src/unix/core.c:384:19 (libuv.so.1+0x15977)
#20 nm_thread /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:718:11 (libisc-9.17.13.so+0x3555e)
#21 isc__trampoline_run /home/ondrej/Projects/bind9/lib/isc/trampoline.c:184:11 (libisc-9.17.13.so+0x108746)
Location is heap block of size 11464 at 0x7b9800060000 allocated by thread T1:
#0 malloc <null> (named+0x43a74b)
#1 default_memalloc /home/ondrej/Projects/bind9/lib/isc/mem.c:411:8 (libisc-9.17.13.so+0xddffe)
#2 mem_get /home/ondrej/Projects/bind9/lib/isc/mem.c:343:8 (libisc-9.17.13.so+0xd8331)
#3 mem_allocateunlocked /home/ondrej/Projects/bind9/lib/isc/mem.c:918:7 (libisc-9.17.13.so+0xd9810)
#4 isc__mem_allocate /home/ondrej/Projects/bind9/lib/isc/mem.c:935:7 (libisc-9.17.13.so+0xd8195)
#5 isc__mem_get /home/ondrej/Projects/bind9/lib/isc/mem.c:740:11 (libisc-9.17.13.so+0xd7f8f)
#6 dns_rbtdb_create /home/ondrej/Projects/bind9/lib/dns/rbtdb.c:8631:22 (libdns-9.17.13.so+0x1c538e)
#7 dns_db_create /home/ondrej/Projects/bind9/lib/dns/db.c:118:13 (libdns-9.17.13.so+0x83693)
#8 axfr_makedb /home/ondrej/Projects/bind9/lib/dns/xfrin.c:292:11 (libdns-9.17.13.so+0x3c0105)
#9 axfr_init /home/ondrej/Projects/bind9/lib/dns/xfrin.c:280:2 (libdns-9.17.13.so+0x3bf8da)
#10 xfr_rr /home/ondrej/Projects/bind9/lib/dns/xfrin.c:597:4 (libdns-9.17.13.so+0x3beb45)
#11 xfrin_recv_done /home/ondrej/Projects/bind9/lib/dns/xfrin.c:1430:5 (libdns-9.17.13.so+0x3bd2fd)
#12 isc__nm_async_readcb /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:2706:2 (libisc-9.17.13.so+0x463f8)
#13 isc__nm_readcb /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:2681:3 (libisc-9.17.13.so+0x45eae)
#14 isc__nm_tcpdns_processbuffer /home/ondrej/Projects/bind9/lib/isc/netmgr/tcpdns.c:817:2 (libisc-9.17.13.so+0x574fd)
#15 processbuffer /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:2257:11 (libisc-9.17.13.so+0x4413f)
#16 isc__nm_process_sock_buffer /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:2282:25 (libisc-9.17.13.so+0x43fb5)
#17 isc__nm_tcpdns_read_cb /home/ondrej/Projects/bind9/lib/isc/netmgr/tcpdns.c:880:2 (libisc-9.17.13.so+0x57c28)
#18 uv__read /home/ondrej/Projects/tsan/libuv/src/unix/stream.c:1239:7 (libuv.so.1+0x280bc)
#19 uv__stream_io /home/ondrej/Projects/tsan/libuv/src/unix/stream.c:1306:5 (libuv.so.1+0x25cef)
#20 uv__io_poll /home/ondrej/Projects/tsan/libuv/src/unix/linux-core.c:462:11 (libuv.so.1+0x2ebb6)
#21 uv_run /home/ondrej/Projects/tsan/libuv/src/unix/core.c:392:5 (libuv.so.1+0x159ac)
#22 nm_thread /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:718:11 (libisc-9.17.13.so+0x3555e)
#23 isc__trampoline_run /home/ondrej/Projects/bind9/lib/isc/trampoline.c:184:11 (libisc-9.17.13.so+0x108746)
Mutex M599395980743702552 is already destroyed.
Thread T1 'isc-net-0000' (tid=1434862, running) created by main thread at:
#0 pthread_create <null> (named+0x43bf6b)
#1 isc_thread_create /home/ondrej/Projects/bind9/lib/isc/pthreads/thread.c:79:8 (libisc-9.17.13.so+0x10b706)
#2 isc__netmgr_create /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:347:3 (libisc-9.17.13.so+0x3535e)
#3 isc_managers_create /home/ondrej/Projects/bind9/lib/isc/managers.c:39:2 (libisc-9.17.13.so+0xd433e)
#4 create_managers /home/ondrej/Projects/bind9/bin/named/main.c:941:11 (named+0x4e4c71)
#5 setup /home/ondrej/Projects/bind9/bin/named/main.c:1216:11 (named+0x4e26d5)
#6 main /home/ondrej/Projects/bind9/bin/named/main.c:1507:2 (named+0x4e0e2b)
Thread T2 'isc-net-0001' (tid=1434882, running) created by main thread at:
#0 pthread_create <null> (named+0x43bf6b)
#1 isc_thread_create /home/ondrej/Projects/bind9/lib/isc/pthreads/thread.c:79:8 (libisc-9.17.13.so+0x10b706)
#2 isc__netmgr_create /home/ondrej/Projects/bind9/lib/isc/netmgr/netmgr.c:347:3 (libisc-9.17.13.so+0x3535e)
#3 isc_managers_create /home/ondrej/Projects/bind9/lib/isc/managers.c:39:2 (libisc-9.17.13.so+0xd433e)
#4 create_managers /home/ondrej/Projects/bind9/bin/named/main.c:941:11 (named+0x4e4c71)
#5 setup /home/ondrej/Projects/bind9/bin/named/main.c:1216:11 (named+0x4e26d5)
#6 main /home/ondrej/Projects/bind9/bin/named/main.c:1507:2 (named+0x4e0e2b)
SUMMARY: ThreadSanitizer: data race (/home/ondrej/Projects/bind9/bin/named/.libs/named+0x445d29) in memset
==================
ThreadSanitizer: reported 2 warningsNot plannedMark AndrewsMark Andrewshttps://gitlab.isc.org/isc-projects/bind9/-/issues/2340Enable logging of rpz re-writes to dnstap.2024-03-27T13:54:38ZPeter DaviesEnable logging of rpz re-writes to dnstap.### Description
Enable logging of rpz re-writes to dnstap.
The ability to send rpz rewrite information that is generated by category rpz to the dnstap output stream.
[RT #17273](https://support.isc.org/Ticket/Display.html?id=17273)### Description
Enable logging of rpz re-writes to dnstap.
The ability to send rpz rewrite information that is generated by category rpz to the dnstap output stream.
[RT #17273](https://support.isc.org/Ticket/Display.html?id=17273)Not plannedEvan HuntEvan Hunthttps://gitlab.isc.org/isc-projects/bind9/-/issues/459[RT 39964] logging of NXDOMAIN query-responses (response source and type)2024-03-13T13:46:50ZVicky Riskvicky@isc.org[RT 39964] logging of NXDOMAIN query-responses (response source and type)Edited/compressed from the original in classic bugs-RT
for analyzing queries resulting in NXDOMAIN responses...
Please add the following to normal query log:
a) what kind of answer was given (nxrrset, rrset (how many) or servfail)
b) w...Edited/compressed from the original in classic bugs-RT
for analyzing queries resulting in NXDOMAIN responses...
Please add the following to normal query log:
a) what kind of answer was given (nxrrset, rrset (how many) or servfail)
b) where did the answer came from (authorative, from cache or was it the result of a recursive search)
The actual content of the answer is not needed outside some very special debug-cases and for these cases you have to do a complete network trace anyway.
spawned from #39253: dnstap wish-list: Query log limited by zone/domain & Answer logging
Reference to https://support.isc.org/Ticket/Display.html?id=8385 added
----
* This is response, not query information
<from Ray>
NB: recording these either means two separate log entries (one for query, one for response) or if they're merged that the query log will now be in response order rather than request order.
------
This request is for 'normal' query logging, but many have asked for this via **dnstap** as well. We would love to get this in dnstap if that is possible, realizing there is a standards/schema issue with dnstap.
------
Tagging with 9.13.3 because we would really like to try for this in 9.14.0. This is a fairly long standing and frequently-heard request.Not planned