Assertion failure in validate_dnskey_dsset_done() when a validator is canceled
Summary
Assertion failure in validator.c:validate_dnskey_dsset_done()
when the validator is canceled.
The validate_dnskey_dsset_done()
function, when called by validate_dnskey_dsset_next_done()
, is missing some code to check for ISC_R_CANCELED
and ISC_R_SHUTTINGDOWN
result codes, and calls validate_async_done()
with a hardcoded result
of DNS_R_NOVALIDSIG
even if the validation is already canceled. That results in an assertion failure, as the proveunsecure()
function called further tries to use val->name
.
The issue was exposed by the #4654 (closed) fix, which resets val->name
to NULL
when the validator is shut down, as it really shouldn't be required by anything else after shutdown.
BIND version affected
- 9.20.x
- 9.21.x
Checked on:
-
main
8a09d54d v9.20.1
Steps to reproduce
This was discovered accidentally when trying to adapt the reproducer at #4898 (comment 487176) to a controlled environment which doesn't require an Internet connection, by using the ns1
and ns2
instances from the dnssec
system test.
I couldn't easily convert this issue to a new system test check, but the crash is reproducible:
Download and extract the testbed archive crash.tar.gz, make sure to acquire and place the required Spamhaus RPZ zones into crash/ns3
, as noted in the #4898 (closed) reproducer linked above.
export BIND9_GIT_DIR="~/dev/bind9"
- Configure BIND 9 system test IP addresses:
$ sudo $BIND9_GIT_DIR/bin/tests/system/ifconfig.sh up
- Start the
ns1
server:cd crash/ns1; $BIND9_GIT_DIR/bin/named/named -n 1 -g -c named.conf
- Start the
run.sh
script incrash/ns3
and wait 10-20 seconds until it crashes:cd crash/ns3; ./run.sh $BIND9_GIT_DIR run1
;
What is the current bug behavior?
Because of #4898 (closed), and until it is fixed, the RPZ processing blocks the offloaded DNSSEC validations, so after the timeout is reached named
shuts down the "hung fetch" (see the log file run1.named.log.gz), but when the validation continues eventually, named
crashes because of the missing validation canceled status checks.
What is the expected correct behavior?
Conclude the offloaded validation step without a crash, even when the validation was canceled in the meanwhile.
Relevant configuration files
Relevant logs
Logs (full: run1.named.log.gz):
00:00:26 02-Sep-2024 13:51:42.573 rpz: large-delta-rpz-2.local: reload done: success
00:00:26 02-Sep-2024 13:51:42.573 view default: validator @0x779b1568d800: no valid signature found (DS)
00:00:26 02-Sep-2024 13:51:42.573 view default: validator @0x779b1568d800: falling back to insecurity proof
00:00:26 02-Sep-2024 13:51:42.573 name.c:2033: REQUIRE(((source) != ((void *)0) && ((const isc__magic_t *)(source))->magic == ((('D') << 24 | ('N') << 16 | ('S') << 8 | ('n'))))) failed
00:00:26 02-Sep-2024 13:51:42.573 lib/isc/.libs/libisc-9.20.1.so(isc_backtrace_log+0x3b) [0x779b1905f8db]
00:00:26 02-Sep-2024 13:51:42.573 bin/named/.libs/named(+0x26c17) [0x586a8174ec17]
00:00:26 02-Sep-2024 13:51:42.573 lib/isc/.libs/libisc-9.20.1.so(isc_assertion_failed+0xa) [0x779b1905f43a]
00:00:26 02-Sep-2024 13:51:42.573 lib/dns/.libs/libdns-9.20.1.so(dns_name_copy+0x197) [0x779b18ca68e7]
00:00:26 02-Sep-2024 13:51:42.573 lib/dns/.libs/libdns-9.20.1.so(+0x1772a9) [0x779b18d772a9]
00:00:26 02-Sep-2024 13:51:42.573 lib/dns/.libs/libdns-9.20.1.so(+0x177fb1) [0x779b18d77fb1]
00:00:26 02-Sep-2024 13:51:42.573 lib/isc/.libs/libisc-9.20.1.so(+0x62c9a) [0x779b1908cc9a]
00:00:26 02-Sep-2024 13:51:42.573 /usr/lib/libuv.so.1(+0x125b0) [0x779b18e7f5b0]
00:00:26 02-Sep-2024 13:51:42.573 /usr/lib/libuv.so.1(+0x9a1b) [0x779b18e76a1b]
00:00:26 02-Sep-2024 13:51:42.573 /usr/lib/libuv.so.1(+0x2730a) [0x779b18e9430a]
00:00:26 02-Sep-2024 13:51:42.573 /usr/lib/libuv.so.1(uv_run+0x1bf) [0x779b18e7c09f]
00:00:26 02-Sep-2024 13:51:42.573 lib/isc/.libs/libisc-9.20.1.so(+0x48dac) [0x779b19072dac]
00:00:26 02-Sep-2024 13:51:42.573 bin/named/.libs/named(main+0xeb9) [0x586a81742969]
00:00:26 02-Sep-2024 13:51:42.573 /usr/lib/libc.so.6(+0x25e08) [0x779b17df9e08]
00:00:26 02-Sep-2024 13:51:42.573 /usr/lib/libc.so.6(__libc_start_main+0x8c) [0x779b17df9ecc]
00:00:26 02-Sep-2024 13:51:42.573 bin/named/.libs/named(_start+0x25) [0x586a81743305]
00:00:26 02-Sep-2024 13:51:42.573 exiting (due to assertion failure)
GDB backtrace:
Thread 1 (Thread 0x79578cd43580 (LWP 895662)):
#0 __pthread_kill_implementation (threadid=<optimized out>, signo=signo@entry=6, no_tid=no_tid@entry=0) at pthread_kill.c:44
tid = <optimized out>
ret = 0
pd = <optimized out>
old_mask = {__val = {0}}
ret = <optimized out>
#1 0x000079578c376463 in __pthread_kill_internal (threadid=<optimized out>, signo=6) at pthread_kill.c:78
No locals.
#2 0x000079578c31d120 in __GI_raise (sig=sig@entry=6) at ../sysdeps/posix/raise.c:26
ret = <optimized out>
#3 0x000079578c3044c3 in __GI_abort () at abort.c:79
save_stage = 1
act = {__sigaction_handler = {sa_handler = 0x20, sa_sigaction = 0x20}, sa_mask = {__val = {0 <repeats 14 times>, 359483201430422016, 0}}, sa_flags = 836570512, sa_restorer = 0x7f1}
#4 0x00005dc531d65aaa in assertion_failed (file=<optimized out>, line=2033, type=isc_assertiontype_require, cond=0x79578d3e93c0 "((source) != ((void *)0) && ((const isc__magic_t *)(source))->magic == ((('D') << 24 | ('N') << 16 | ('S') << 8 | ('n'))))") at main.c:234
No locals.
#5 0x000079578d4e443a in isc_assertion_failed (file=file@entry=0x79578d3d4bf7 "name.c", line=line@entry=2033, type=type@entry=isc_assertiontype_require, cond=cond@entry=0x79578d3e93c0 "((source) != ((void *)0) && ((const isc__magic_t *)(source))->magic == ((('D') << 24 | ('N') << 16 | ('S') << 8 | ('n'))))") at assertions.c:48
No locals.
#6 0x000079578d2a68e7 in dns_name_copy (source=<optimized out>, dest=dest@entry=0x7ffcbdbe7600) at name.c:2033
target = 0x0
ndata = 0x0
#7 0x000079578d3772a9 in proveunsecure (val=0x795789c8d800, have_ds=have_ds@entry=false, resume=resume@entry=false) at validator.c:3172
result = <optimized out>
namebuf = '\000' <repeats 64 times>, "large-delta-rpz-2.local", '\000' <repeats 706 times>...
fixedsecroot = {name = {magic = 1145983854, ndata = 0x0, length = 0, labels = 0, attributes = {absolute = false, readonly = false, dynamic = false, dynoffsets = false, nocompress = false, cache = false, answer = false, ncache = false, chaining = false, chase = false, wildcard = false, prerequisite = false, update = false, hasupdaterec = false}, offsets = 0x7ffcbdbe7658 "'\aG\215Wy", buffer = 0x7ffcbdbe76d8, link = {prev = 0xffffffffffffffff, next = 0xffffffffffffffff}, list = {head = 0x0, tail = 0x0}, hashmap = 0x0}, offsets = "'\aG\215Wy\000\000@w\276\275\374\177\000\000\340\204L\214Wy\000\000C\000\000\000\000\000\000\000\260w\276\275\374\177\000\000C\000\000\000\000\000\000\000C\000\000\000\000\000\000\000\002\000#]\n5\000\003", '\000' <repeats 20 times>, "\020\000\000\000", '\377' <repeats 16 times>, "C\000\000\000\000\000\022\000\360_L\214\000\001\000\000\000\000\000\000\000\000\000", buffer = {magic = 1114990113, base = 0x7ffcbdbe7718, length = 255, used = 0, current = 0, active = 0, extra = 0, dynamic = false, link = {prev = 0xffffffffffffffff, next = 0xffffffffffffffff}, mctx = 0x0}, data = "\200x\276\275\374\177\000\000@w\276\275\374\177\000\000ݯߌWy\000\000\000\000\000\000\000\000\000\000\340\204L\214Wy\000\000\001\000\000\000\v\000\000\000\000\000\000\000\001", '\000' <repeats 27 times>, "\020\000\000\000\000\000\000\00027-Aug-2024 13:24:54.693\000\000\000\000\023\000\000\000\000\000\000\000\001\000\000\000\024\000\000\000\000\000\000\000\001\000\000\000\025\000\000\000\000\000\000\000\001\000\000\0002024-08-27T13:24:54.693Z", '\000' <repeats 20 times>, "\001\000\000\000\023\000"...}
secroot = 0x7ffcbdbe7600
labels = <optimized out>
#8 0x000079578d377fb1 in validate_async_done (val=<optimized out>, result=DNS_R_NOVALIDSIG) at validator.c:1804
saved_result = DNS_R_NOVALIDSIG
#9 0x000079578d511c9a in isc__after_work_cb (req=<optimized out>, status=0) at work.c:42
work = 0x795736e5eee0
loop = 0x795789c43800
__func__ = "isc__after_work_cb"
#10 0x000079578cdeb5b0 in ?? () from /usr/lib/libuv.so.1
No symbol table info available.
#11 0x000079578cde2a1b in ?? () from /usr/lib/libuv.so.1
No symbol table info available.
#12 0x000079578ce0030a in ?? () from /usr/lib/libuv.so.1
No symbol table info available.
#13 0x000079578cde809f in uv_run () from /usr/lib/libuv.so.1
No symbol table info available.
#14 0x000079578d4f7dac in loop_thread (arg=0x795789c43800) at loop.c:288
loop = 0x795789c43800
r = <optimized out>
__func__ = "loop_thread"
ret = <optimized out>
#15 0x00005dc531d66969 in main (argc=<optimized out>, argv=<optimized out>) at main.c:1575
result = <optimized out>
GDB debugging:
(gdb) frame 7
#7 0x000079578d3772a9 in proveunsecure (val=0x795789c8d800, have_ds=have_ds@entry=false, resume=resume@entry=false) at validator.c:3172
3172 dns_name_copy(val->name, secroot);
(gdb) p val
$1 = (dns_validator_t *) 0x795789c8d800
(gdb) p *val
$2 = {magic = 1449225279, view = 0x795789d2c400, loop = 0x795789c43800, tid = 0, references = 1, name = 0x0, type = 48, cb = 0x79578d34fc30 <validated>, arg = 0x795789c626d0, options = 0,
result = ISC_R_CANCELED, rdataset = 0x795736fdd880, sigrdataset = 0x795736fdd810, message = 0x795736fc6d80, proofs = {0x0, 0x0, 0x0, 0x0}, optout = false, secure = false, attributes = 26,
fetch = 0x0, subvalidator = 0x0, parent = 0x0, keytable = 0x795789c3c7e0, key = 0x0, siginfo = 0x0, labels = 0, nxset = 0x0, keyset = 0x0, dsset = 0x0, fdsset = {magic = 1145983826,
methods = 0x0, link = {prev = 0xffffffffffffffff, next = 0xffffffffffffffff}, rdclass = 0, type = 0, ttl = 0, trust = 0, covers = 0, attributes = 0, count = 4294967295, resign = 0, {
keytable = {node = 0x0, iter = 0x0}, ncache = {raw = 0x0, iter_pos = 0x0, iter_count = 0}, slab = {db = 0x0, node = 0x0, raw = 0x0, iter_pos = 0x0, iter_count = 0, noqname = 0x0,
closest = 0x0}, rdlist = {list = 0x0, iter = 0x0, noqname = 0x0, closest = 0x0, node = 0x0}}}, frdataset = {magic = 1145983826, methods = 0x0, link = {prev = 0xffffffffffffffff,
next = 0xffffffffffffffff}, rdclass = 0, type = 0, ttl = 0, trust = 0, covers = 0, attributes = 0, count = 4294967295, resign = 0, {keytable = {node = 0x0, iter = 0x0}, ncache = {
raw = 0x0, iter_pos = 0x0, iter_count = 0}, slab = {db = 0x0, node = 0x0, raw = 0x0, iter_pos = 0x0, iter_count = 0, noqname = 0x0, closest = 0x0}, rdlist = {list = 0x0, iter = 0x0,
noqname = 0x0, closest = 0x0, node = 0x0}}}, fsigrdataset = {magic = 1145983826, methods = 0x0, link = {prev = 0xffffffffffffffff, next = 0xffffffffffffffff}, rdclass = 0, type = 0,
ttl = 0, trust = 0, covers = 0, attributes = 0, count = 4294967295, resign = 0, {keytable = {node = 0x0, iter = 0x0}, ncache = {raw = 0x0, iter_pos = 0x0, iter_count = 0}, slab = {
db = 0x0, node = 0x0, raw = 0x0, iter_pos = 0x0, iter_count = 0, noqname = 0x0, closest = 0x0}, rdlist = {list = 0x0, iter = 0x0, noqname = 0x0, closest = 0x0, node = 0x0}}},
fname = {name = {magic = 0, ndata = 0x0, length = 0, labels = 0, attributes = {absolute = false, readonly = false, dynamic = false, dynoffsets = false, nocompress = false, cache = false,
answer = false, ncache = false, chaining = false, chase = false, wildcard = false, prerequisite = false, update = false, hasupdaterec = false}, offsets = 0x0, buffer = 0x0, link = {
prev = 0x0, next = 0x0}, list = {head = 0x0, tail = 0x0}, hashmap = 0x0}, offsets = '\000' <repeats 127 times>, buffer = {magic = 0, base = 0x0, length = 0, used = 0, current = 0,
active = 0, extra = 0, dynamic = false, link = {prev = 0x0, next = 0x0}, mctx = 0x0}, data = '\000' <repeats 254 times>}, wild = {name = {magic = 1145983854, ndata = 0x0, length = 0,
labels = 0, attributes = {absolute = false, readonly = false, dynamic = false, dynoffsets = false, nocompress = false, cache = false, answer = false, ncache = false, chaining = false,
chase = false, wildcard = false, prerequisite = false, update = false, hasupdaterec = false}, offsets = 0x795789c8dca0 "", buffer = 0x795789c8dd20, link = {
prev = 0xffffffffffffffff, next = 0xffffffffffffffff}, list = {head = 0x0, tail = 0x0}, hashmap = 0x0}, offsets = '\000' <repeats 127 times>, buffer = {magic = 1114990113,
base = 0x795789c8dd60, length = 255, used = 0, current = 0, active = 0, extra = 0, dynamic = false, link = {prev = 0xffffffffffffffff, next = 0xffffffffffffffff}, mctx = 0x0},
data = '\000' <repeats 254 times>}, closest = {name = {magic = 1145983854, ndata = 0x0, length = 0, labels = 0, attributes = {absolute = false, readonly = false, dynamic = false,
dynoffsets = false, nocompress = false, cache = false, answer = false, ncache = false, chaining = false, chase = false, wildcard = false, prerequisite = false, update = false,
hasupdaterec = false}, offsets = 0x795789c8deb8 "", buffer = 0x795789c8df38, link = {prev = 0xffffffffffffffff, next = 0xffffffffffffffff}, list = {head = 0x0, tail = 0x0},
hashmap = 0x0}, offsets = '\000' <repeats 127 times>, buffer = {magic = 1114990113, base = 0x795789c8df78, length = 255, used = 0, current = 0, active = 0, extra = 0, dynamic = false,
link = {prev = 0xffffffffffffffff, next = 0xffffffffffffffff}, mctx = 0x0}, data = '\000' <repeats 254 times>}, link = {prev = 0xffffffffffffffff, next = 0xffffffffffffffff},
mustbesecure = false, depth = 0, authcount = 0, authfail = 0, start = 1724765081, digest_sha1 = false, supported_algorithm = true, rdata = {data = 0x0, length = 0, rdclass = 0, type = 0,
flags = 0, link = {prev = 0xffffffffffffffff, next = 0xffffffffffffffff}}, resume = false, nvalidations = 0x795736f2589c, nfails = 0x795736f258a0, qc = 0x7957311b4450}
(gdb) p val->name
$3 = (dns_name_t *) 0x0