Assertion failure in isc_tlsctx_cache_attach()
https://gitlab.isc.org/isc-projects/bind9/-/jobs/2205912
This happened on OpenBSD, but I do not immediately see anything OpenBSD-specific here.
Looking at line numbers, it seems that the failing assertion is:
939 void
940 isc_tlsctx_cache_attach(isc_tlsctx_cache_t *source,
941 isc_tlsctx_cache_t **targetp) {
942 REQUIRE(VALID_TLSCTX_CACHE(source));
943 >>> REQUIRE(targetp != NULL && *targetp == NULL);
944
945 isc_refcount_increment(&source->references);
946
947 *targetp = source;
948 }
The failing assertion was introduced by !5672 (merged) (see #3067 (closed)).
Looking at the relevant code, this crash looks pretty wild because I
cannot immediately see how it could have happened. (I am only judging
from the backtrace and the source code, though, I have not looked at the
actual core dump.) Maybe a race during rndc reconfig?
Click to expand/hide full test output
S:mirror:2022-01-04T04:14:39+0000 T:mirror:1:A A:mirror:System test mirror I:mirror:PORTS:29227,29228,29229,29230,29231,29232,29233,29234,29235,29236,29237,29238,29239 I:mirror:starting servers I:mirror:checking that an unsigned mirror zone is rejected (1) I:mirror:checking that a mirror zone signed using an untrusted key is rejected (2) I:mirror:checking that a mirror zone signed using a CSK without the SEP bit set is accepted (3) I:mirror:checking that an AXFR of an incorrectly signed mirror zone is rejected (4) I:mirror:checking that an AXFR of an updated, correctly signed mirror zone is accepted (5) I:mirror:ns2 server reload successful I:mirror:checking that an IXFR of an incorrectly signed mirror zone is rejected (6) I:mirror:ns2 server reload successful I:mirror:checking that an IXFR of an updated, correctly signed mirror zone is accepted after AXFR failover (7) I:mirror:ns2 server reload successful I:mirror:checking that loading an incorrectly signed mirror zone from disk fails (8) I:mirror:ensuring trust anchor telemetry queries are sent upstream for a mirror zone (9) I:mirror:checking that loading a correctly signed mirror zone from disk succeeds (10) I:mirror:checking that loading a journal for an incorrectly signed mirror zone fails (11) I:mirror:checking that loading a journal for a correctly signed mirror zone succeeds (12) I:mirror:checking delegations sourced from a mirror zone (13) I:mirror:checking that resolution involving a mirror zone works as expected (14) I:mirror:checking that non-recursive queries for names below mirror zone get responded from cache (15) I:mirror:checking that delegations from cache which improve mirror zone delegations are properly handled (16) I:mirror:checking flags set in a DNSKEY response sourced from a mirror zone (17) I:mirror:checking flags set in a SOA response sourced from a mirror zone (18) I:mirror:checking that resolution succeeds with unavailable mirror zone data (19) I:mirror:checking that resolution succeeds with expired mirror zone data (20) I:mirror:checking that clients without cache access cannot retrieve mirror zone data (21) I:mirror:checking that outgoing transfers of mirror zones are disabled by default (22) I:mirror:checking that notifies are disabled by default for mirror zones (23) I:mirror:checking output of "rndc zonestatus" for a mirror zone (24) I:mirror:checking that "rndc reconfig" properly handles a mirror -> secondary zone type change (25) I:mirror:ns3 rndc: connection to remote host closed. I:mirror:ns3 * This may indicate that the I:mirror:ns3 * remote server is using an older I:mirror:ns3 * version of the command protocol, I:mirror:ns3 * this host is not authorized to connect, I:mirror:ns3 * the clocks are not synchronized, I:mirror:ns3 * the key signing algorithm is incorrect, I:mirror:ns3 * or the key is invalid. rndc: connect failed: 10.53.0.3#29239: connection refused I:mirror:exceeded time limit waiting for proof of 'verify-reconfig' being loaded to appear in ns3/named.run I:mirror:failed I:mirror:checking that "rndc reconfig" properly handles a secondary -> mirror zone type change (26) I:mirror:ns3 rndc: connect failed: 10.53.0.3#29239: connection refused rndc: connect failed: 10.53.0.3#29239: connection refused I:mirror:exceeded time limit waiting for proof of 'verify-reconfig' being loaded to appear in ns3/named.run I:mirror:failed I:mirror:checking that a mirror zone can be added using rndc (27) I:mirror:exceeded time limit waiting for proof of 'verify-addzone' being transferred to appear in ns3/named.run I:mirror:failed I:mirror:checking that a mirror zone can be deleted using rndc (28) I:mirror:exceeded time limit waiting for 'zone verify-addzone/IN: mirror zone is no longer in use; reverting to normal recursion' in ns3/named.run I:mirror:failed I:mirror:exit status: 4 I:mirror:stopping servers I:mirror:ns3 died before a SIGTERM was sent I:mirror:stopping servers failed I:mirror:Core dump(s) found: mirror/ns3/named.core D:mirror:backtrace from mirror/ns3/named.core: D:mirror:-------------------------------------------------------------------------------- D:mirror:Core was generated by `named'. D:mirror:Program terminated with signal SIGABRT, Aborted. D:mirror:#0 thrkill () at /tmp/-:3 D:mirror:[Current thread is 1 (process 569235)] D:mirror:#0 thrkill () at /tmp/-:3 D:mirror:#1 0x00000848cb47fdee in _libc_abort () at /usr/src/lib/libc/stdlib/abort.c:51 D:mirror:#2 0x00000845e2c269a3 in assertion_failed (file=, line=, type=, cond=) at main.c:236 D:mirror:#3 0x00000848a30ac260 in isc_assertion_failed (file=0x0, line=6, type=isc_assertiontype_require, cond=0x848cb41f66a "r\001\303d\211\004% ") at assertions.c:47 D:mirror:#4 0x00000848a30d71f4 in isc_tlsctx_cache_attach (source=, targetp=) at tls.c:943 D:mirror:#5 0x00000848abba625e in dns_zonemgr_set_tlsctx_cache (zmgr=0x848bfeee020, tlsctx_cache=0x8485934e520) at zone.c:23652 D:mirror:#6 0x00000845e2c3608e in load_configuration (filename=, server=0x8483918c020, first_time=) at server.c:8440 D:mirror:#7 0x00000845e2c2a3fe in loadconfig (server=0x8483918c020) at server.c:10365 D:mirror:#8 0x00000845e2c2a2ed in named_server_reconfigcommand (server=0x8483918c020) at server.c:10762 D:mirror:#9 0x00000845e2c1efe5 in named_control_docommand (message=, readonly=, text=0x848a26ba708) at control.c:246 D:mirror:#10 0x00000845e2c22467 in control_command (task=, event=) at controlconf.c:389 D:mirror:#11 0x00000848a30d0e2c in task_run (task=0x8487d3d1520) at task.c:827 D:mirror:#12 isc_task_run (task=0x8487d3d1520) at task.c:907 D:mirror:#13 0x00000848a30979ed in isc__nm_async_task (worker=, ev0=0x848a26ba820) at netmgr/netmgr.c:835 D:mirror:#14 process_netievent (worker=0x848941f40c0, ievent=0x848a26ba820) at netmgr/netmgr.c:914 D:mirror:#15 0x00000848a3092ab4 in process_queue (worker=0x848941f40c0, type=) at netmgr/netmgr.c:1008 D:mirror:#16 process_all_queues (worker=0x848941f40c0) at netmgr/netmgr.c:754 D:mirror:#17 async_cb (handle=0x848941f4398) at netmgr/netmgr.c:783 D:mirror:#18 0x00000847ec25a92d in uv.async_io () from /usr/local/lib/libuv.so.3.0 D:mirror:#19 0x00000847ec26c829 in uv.io_poll () from /usr/local/lib/libuv.so.3.0 D:mirror:#20 0x00000847ec25b018 in uv_run () from /usr/local/lib/libuv.so.3.0 D:mirror:#21 0x00000848a3092bfb in nm_thread (worker0=0x848941f40c0) at netmgr/netmgr.c:689 D:mirror:#22 0x00000848a30d9146 in isc__trampoline_run (arg=0x848941e57a0) at trampoline.c:185 D:mirror:#23 0x000008482f9591c1 in _rthread_start (v=) at /usr/src/lib/librthread/rthread.c:96 D:mirror:#24 0x00000848cb43e33a in __tfork_thread () at /usr/src/lib/libc/arch/amd64/sys/tfork_thread.S:84 D:mirror:-------------------------------------------------------------------------------- D:mirror:full backtrace from mirror/ns3/named.core saved in mirror/ns3/named.core-backtrace.txt D:mirror:core dump mirror/ns3/named.core archived as mirror/ns3/named.core.gz R:mirror:FAIL E:mirror:2022-01-04T04:15:53+0000