REQUIRE(VALID_NMHANDLE(handle)); assertion failed in isc__nm_async_tcpdnscancel()
The assertion mentioned in the subject happened during the
statschannel system test for main on FreeBSD 12:
https://gitlab.isc.org/isc-private/bind9/-/jobs/1299690
D:statschannel:Core was generated by `/builds/isc-private/bind9/bin/named/.libs/named -D statschannel-ns3 -X named.loc'.
D:statschannel:Program terminated with signal SIGABRT, Aborted.
D:statschannel:#0 0x0000000800fb1c2a in thr_kill () from /lib/libc.so.7
D:statschannel:[Current thread is 1 (LWP 101450)]
D:statschannel:#0 0x0000000800fb1c2a in thr_kill () from /lib/libc.so.7
D:statschannel:#1 0x0000000800fb0084 in raise () from /lib/libc.so.7
D:statschannel:#2 0x0000000800f26279 in abort () from /lib/libc.so.7
D:statschannel:#3 0x0000000000239fb2 in assertion_failed (file=<optimized out>, line=<optimized out>, type=isc_assertiontype_require, cond=<optimized out>) at main.c:254
D:statschannel:#4 0x000000080031094a in isc_assertion_failed (file=0x18c4a <error: Cannot access memory at address 0x18c4a>, line=6, type=isc_assertiontype_require, cond=0x800fb1c4a <thr_self+10> "\017\202\264G") at assertions.c:46
D:statschannel:#5 0x00000008002f922a in isc__nm_tcp_cancelread (handle=<optimized out>) at netmgr/tcp.c:1420
D:statschannel:#6 0x00000008002fb1cd in isc__nm_async_tcpdnscancel (worker=<optimized out>, ev0=<optimized out>) at netmgr/tcpdns.c:1025
D:statschannel:#7 0x00000008002f60eb in process_queue (worker=0x8013dc010, queue=0x801391a00) at netmgr/netmgr.c:675
D:statschannel:#8 0x00000008002f6380 in process_normal_queue (worker=0x18c4a) at netmgr/netmgr.c:594
D:statschannel:#9 0x00000008002f5f5a in process_queues (worker=0x8013dc010) at netmgr/netmgr.c:602
D:statschannel:#10 0x00000008002f2910 in async_cb (handle=<optimized out>) at netmgr/netmgr.c:560
D:statschannel:#11 0x0000000800be3cd2 in ?? () from /usr/local/lib/libuv.so.1
D:statschannel:#12 0x0000000800bf4f09 in uv.io_poll () from /usr/local/lib/libuv.so.1
D:statschannel:#13 0x0000000800be4241 in uv_run () from /usr/local/lib/libuv.so.1
D:statschannel:#14 0x00000008002f298b in nm_thread (worker0=0x8013dc010) at netmgr/netmgr.c:500
D:statschannel:#15 0x0000000800ddcfac in ?? () from /lib/libthr.so.3
D:statschannel:#16 0x0000000000000000 in ?? ()I believe this is a shutdown crash - looks like it could be happening when a transfer is canceled because of server shutdown?
16-Nov-2020 12:04:59.469 transfer of 'example/IN' from 10.53.0.1#32228: connected using 10.53.0.1#32228
16-Nov-2020 12:04:59.470 transfer of 'example/IN' from 10.53.0.1#32228: sent request data
16-Nov-2020 12:04:59.500 transfer of 'example/IN' from 10.53.0.1#32228: failed while receiving responses: operation canceled
16-Nov-2020 12:04:59.500 zone example/IN: zone transfer finished: operation canceled
16-Nov-2020 12:04:59.500 zone_settimer: zone example/IN: enter
16-Nov-2020 12:04:59.500 zone_settimer: zone example/IN: settimer inactive
16-Nov-2020 12:04:59.500 queue_soa_query: zone example/IN: enter
16-Nov-2020 12:04:59.500 transfer of 'example/IN' from 10.53.0.1#32228: Transfer status: operation canceled
16-Nov-2020 12:04:59.500 transfer of 'example/IN' from 10.53.0.1#32228: Transfer completed: 0 messages, 0 records, 0 bytes, 0.030 secs (0 bytes/sec) (serial 0)
16-Nov-2020 12:04:59.500 transfer of 'example/IN' from 10.53.0.1#32228: freeing transfer context
16-Nov-2020 12:04:59.500 netmgr/tcp.c:1420: REQUIRE(((__builtin_expect(!!((handle) != ((void *)0)), 1) && __builtin_expect(!!(((const isc__magic_t *)(handle))->magic == ((('N') << 24 | ('M') << 16 | ('H') << 8 | ('D')))), 1)) && __c11_atomic_load(&(handle)->references, memory_order_seq_cst) > 0)) failed, back trace
16-Nov-2020 12:04:59.501 socket 0x8013be9d0: destroying
16-Nov-2020 12:04:59.501 no longer listening on 10.53.0.3#32228
16-Nov-2020 12:04:59.501 0x239fce <assertion_failed+0x8e> at /builds/isc-private/bind9/bin/named/.libs/named
16-Nov-2020 12:04:59.501 0x80031094a <isc_assertion_failed+0xa> at /builds/isc-private/bind9/lib/isc/.libs/libisc.so.1706
16-Nov-2020 12:04:59.501 0x8002f922a <isc__nm_tcp_cancelread+0x9a> at /builds/isc-private/bind9/lib/isc/.libs/libisc.so.1706
16-Nov-2020 12:04:59.501 0x8002fb1cd <isc__nm_async_tcpdnscancel+0x7d> at /builds/isc-private/bind9/lib/isc/.libs/libisc.so.1706
16-Nov-2020 12:04:59.501 0x8002f60eb <isc__nm_socket_dontfrag+0x24b> at /builds/isc-private/bind9/lib/isc/.libs/libisc.so.1706
16-Nov-2020 12:04:59.501 0x8002f6380 <isc__nm_socket_dontfrag+0x4e0> at /builds/isc-private/bind9/lib/isc/.libs/libisc.so.1706
16-Nov-2020 12:04:59.501 0x8002f5f5a <isc__nm_socket_dontfrag+0xba> at /builds/isc-private/bind9/lib/isc/.libs/libisc.so.1706
16-Nov-2020 12:04:59.501 0x8002f2910 <isc_nm_start+0x420> at /builds/isc-private/bind9/lib/isc/.libs/libisc.so.1706
16-Nov-2020 12:04:59.501 0x800be3cd2 <uv__async_stop+0x1d2> at /usr/local/lib/libuv.so.1
16-Nov-2020 12:04:59.501 0x800bf4f09 <uv__io_poll+0x7f9> at /usr/local/lib/libuv.so.1
16-Nov-2020 12:04:59.501 0x800be4241 <uv_run+0x191> at /usr/local/lib/libuv.so.1
16-Nov-2020 12:04:59.501 0x8002f298b <isc_nm_start+0x49b> at /builds/isc-private/bind9/lib/isc/.libs/libisc.so.1706
16-Nov-2020 12:04:59.501 exiting (due to assertion failure)