dispatch unit test is unstable
Even after #4392 (closed), we keep seeing failures of the dispatch unit test.
dispatch_getnext:
dispatch_newtcp: Job #3799293 failed for 25cfec4d.
[==========] Running 10 test(s).
[ RUN ] dispatch_gettcp
[ OK ] dispatch_gettcp
[ RUN ] dispatch_newtcp
[ OK ] dispatch_newtcp
[ RUN ] dispatch_timeout_udp_response
[ OK ] dispatch_timeout_udp_response
[ RUN ] dispatchset_create
[ OK ] dispatchset_create
[ RUN ] dispatchset_get
[ OK ] dispatchset_get
[ RUN ] dispatch_timeout_tcp_response
[ OK ] dispatch_timeout_tcp_response
[ RUN ] dispatch_timeout_tcp_connect
[ OK ] dispatch_timeout_tcp_connect
[ RUN ] dispatch_tcp_response
[ OK ] dispatch_tcp_response
[ RUN ] dispatch_tls_response
[ OK ] dispatch_tls_response
[ RUN ] dispatch_getnext
0x2 != 0
[ LINE ] --- dispatch_test.c:419: error: Failure!I:dispatch_test:Core dump found: ./core.23758
D:dispatch_test:backtrace from ./core.23758 start
warning: Can't open file anon_inode:[io_uring] which was expanded to anon_inode:[io_uring] during file-backed mapping note processing
warning: Can't open file anon_inode:[io_uring] which was expanded to anon_inode:[io_uring] during file-backed mapping note processing
warning: Can't open file anon_inode:[io_uring] which was expanded to anon_inode:[io_uring] during file-backed mapping note processing
warning: Can't open file anon_inode:[io_uring] which was expanded to anon_inode:[io_uring] during file-backed mapping note processing
[New LWP 23758]
[New LWP 23799]
[New LWP 23798]
[New LWP 24634]
Downloading separate debug info for /lib/x86_64-linux-gnu/libcmocka.so.0...
Downloading separate debug info for /lib/x86_64-linux-gnu/libuv.so.1...
Downloading separate debug info for /lib/x86_64-linux-gnu/libssl.so.3...
Downloading separate debug info for /lib/x86_64-linux-gnu/libcrypto.so.3...
Downloading separate debug info for /lib/x86_64-linux-gnu/libz.so.1...
Downloading separate debug info for /lib/x86_64-linux-gnu/libjson-c.so.5...
Downloading separate debug info for /lib/x86_64-linux-gnu/libnghttp2.so.14...
Downloading separate debug info for /lib/x86_64-linux-gnu/libxml2.so.2...
Downloading separate debug info for /lib/x86_64-linux-gnu/liburcu.so.8...
Downloading separate debug info for /root/.cache/debuginfod_client/be4446e17e11dc07dd007465b7e3008bc69f905a/debuginfo...
Downloading separate debug info for /lib/x86_64-linux-gnu/liburcu-common.so.8...
Downloading separate debug info for /lib/x86_64-linux-gnu/libgssapi_krb5.so.2...
Downloading separate debug info for /lib/x86_64-linux-gnu/libkrb5.so.3...
Downloading separate debug info for /lib/x86_64-linux-gnu/libmaxminddb.so.0...
Downloading separate debug info for /lib/x86_64-linux-gnu/libfstrm.so.0...
Downloading separate debug info for /lib/x86_64-linux-gnu/libprotobuf-c.so.1...
Downloading separate debug info for /lib/x86_64-linux-gnu/liblmdb.so.0...
Downloading separate debug info for /lib/x86_64-linux-gnu/liburcu-cds.so.8...
Downloading separate debug info for /lib/x86_64-linux-gnu/libicuuc.so.72...
Downloading separate debug info for /root/.cache/debuginfod_client/0bc79e91cbc31da5a4c73b10bff30734ec138da0/debuginfo...
Downloading separate debug info for /lib/x86_64-linux-gnu/liblzma.so.5...
Downloading separate debug info for /lib/x86_64-linux-gnu/libk5crypto.so.3...
Downloading separate debug info for /lib/x86_64-linux-gnu/libcom_err.so.2...
Downloading separate debug info for /lib/x86_64-linux-gnu/libkrb5support.so.0...
Downloading separate debug info for /lib/x86_64-linux-gnu/libkeyutils.so.1...
Downloading separate debug info for /lib/x86_64-linux-gnu/libicudata.so.72...
Downloading separate debug info for /lib/x86_64-linux-gnu/libstdc++.so.6...
Downloading separate debug info for /lib/x86_64-linux-gnu/libgcc_s.so.1...
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `/builds/isc-projects/bind9/tests/dns/.libs/dispatch_test'.
Program terminated with signal SIGABRT, Aborted.
#0 __pthread_kill_implementation (threadid=<optimized out>, signo=signo@entry=6, no_tid=no_tid@entry=0) at ./nptl/pthread_kill.c:44
Download failed: Invalid argument. Continuing without source file ./nptl/./nptl/pthread_kill.c.
44 ./nptl/pthread_kill.c: Inappropriate ioctl for device.
[Current thread is 1 (Thread 0x7f91a32d6b80 (LWP 23758))]
Thread 4 (LWP 24634):
#0 0x0000000000000000 in ?? ()
No symbol table info available.
Backtrace stopped: Cannot access memory at address 0x0
Thread 3 (Thread 0x7f91a304d680 (LWP 23798)):
#0 syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38
No locals.
#1 0x00007f91a55bcbf4 in futex (val3=0, uaddr2=0x0, timeout=0x0, val=-1, op=0, uaddr=0x557352879600) at ../include/urcu/futex.h:81
No locals.
#2 futex_async (timeout=0x0, uaddr2=0x0, val3=0, val=-1, op=0, uaddr=0x557352879600) at ../include/urcu/futex.h:113
ret = <optimized out>
ret = <optimized out>
#3 futex_wait (futex=futex@entry=0x557352879600) at ./src/workqueue.c:135
__func__ = "futex_wait"
#4 0x00007f91a55bd035 in workqueue_thread (arg=0x5573528795c0) at ./src/workqueue.c:246
cbs_tmp_n = <optimized out>
splice_ret = <optimized out>
cbs_tmp_head = {node = {next = 0x55735285fa40}, lock = {__data = {__lock = 0, __count = 0, __owner = 0, __nusers = 0, __kind = 0, __spins = 0, __elision = 0, __list = {__prev = 0x0, __next = 0x0}}, __size = '\000' <repeats 39 times>, __align = 0}}
cbs_tmp_tail = {p = 0x557352898e50}
cbs = <optimized out>
cbcount = <optimized out>
workqueue = 0x5573528795c0
rt = 0
__func__ = "workqueue_thread"
__PRETTY_FUNCTION__ = "workqueue_thread"
#5 0x00007f91a5ea63ec in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:444
ret = <optimized out>
pd = <optimized out>
out = <optimized out>
unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140263530586416, -6319514938243892525, -808, 0, 140723762111680, 140263473598464, 6300488242360924883, 6300493485668219603}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
not_first_call = <optimized out>
#6 0x00007f91a5f26a4c in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81
No locals.
Thread 2 (Thread 0x7f91a284c680 (LWP 23799)):
#0 syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38
No locals.
#1 0x00007f91a626d3ad in futex (val3=0, uaddr2=0x0, timeout=0x0, val=-1, op=0, uaddr=0x557352852020) at ../include/urcu/futex.h:81
No locals.
#2 futex_noasync (timeout=0x0, uaddr2=0x0, val3=0, val=-1, op=0, uaddr=0x557352852020) at ../include/urcu/futex.h:90
ret = <optimized out>
ret = <optimized out>
#3 call_rcu_wait (crdp=0x557352851fe0) at ./src/urcu-call-rcu-impl.h:248
__func__ = "call_rcu_wait"
#4 call_rcu_thread (arg=0x557352851fe0) at ./src/urcu-call-rcu-impl.h:400
cbs_tmp_n = <optimized out>
splice_ret = <optimized out>
cbs_tmp_head = {node = {next = 0x55735287d778}, lock = {__data = {__lock = 0, __count = 0, __owner = 0, __nusers = 0, __kind = 0, __spins = 0, __elision = 0, __list = {__prev = 0x0, __next = 0x0}}, __size = '\000' <repeats 39 times>, __align = 0}}
cbs_tmp_tail = {p = 0x557352876df0}
cbs = <optimized out>
cbcount = <optimized out>
crdp = 0x557352851fe0
rt = 0
__func__ = "call_rcu_thread"
__PRETTY_FUNCTION__ = "call_rcu_thread"
#5 0x00007f91a5ea63ec in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:444
ret = <optimized out>
pd = <optimized out>
out = <optimized out>
unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140263530586416, -6319514938243892525, -808, 115, 140723762111824, 140263465205760, 6300491538211453651, 6300493485668219603}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
not_first_call = <optimized out>
#6 0x00007f91a5f26a4c in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81
No locals.
Thread 1 (Thread 0x7f91a32d6b80 (LWP 23758)):
#0 __pthread_kill_implementation (threadid=<optimized out>, signo=signo@entry=6, no_tid=no_tid@entry=0) at ./nptl/pthread_kill.c:44
tid = <optimized out>
ret = 0
pd = <optimized out>
old_mask = {__val = {24576}}
ret = <optimized out>
#1 0x00007f91a5ea815f in __pthread_kill_internal (signo=6, threadid=<optimized out>) at ./nptl/pthread_kill.c:78
No locals.
#2 0x00007f91a5e5a472 in __GI_raise (sig=sig@entry=6) at ../sysdeps/posix/raise.c:26
ret = <optimized out>
#3 0x00007f91a5e444b2 in __GI_abort () at ./stdlib/abort.c:79
save_stage = 1
act = {__sigaction_handler = {sa_handler = 0x20, sa_sigaction = 0x20}, sa_mask = {__val = {93953797214704, 140263484650848, 4294934528, 7, 140263531945088, 7, 0, 12880216814053340279, 9278577283777313019, 6439199540737383679, 93953794348112, 140263536447415, 140263530288466, 8, 140263530288466, 0}}, sa_flags = 1373274116, sa_restorer = 0x1a3}
#4 0x00007f91a63b7f45 in exit_test (quit_application=1) at ./src/cmocka.c:404
env = 0x7ffccdda8a0a "1"
abort_test = <optimized out>
#5 0x00007f91a63b7fda in _fail (file=file@entry=0x557351da8004 "dispatch_test.c", line=line@entry=419) at ./src/cmocka.c:2196
output = <optimized out>
#6 0x00007f91a63ba0bf in _assert_int_equal (a=<optimized out>, b=b@entry=0, file=file@entry=0x557351da8004 "dispatch_test.c", line=line@entry=419) at ./src/cmocka.c:1800
No locals.
#7 0x0000557351da695a in response_getnext (result=<optimized out>, region=<optimized out>, arg=0x55735283e170) at dispatch_test.c:419
test = 0x55735283e170
#8 0x00007f91a60596e5 in udp_recv (handle=0x557352899450, eresult=ISC_R_TIMEDOUT, region=0x7ffccdda6bb0, arg=<optimized out>) at dispatch.c:618
resp = 0x557352898340
disp = <optimized out>
id = 0
dres = <optimized out>
source = {magic = 1384304336, base = 0x6e8, length = 1494, used = 0, current = 3453643520, active = 32764, extra = 1384304336, dynamic = 115, link = {prev = 0x7f91a64127d8 <add_trace_entry+296>, next = 0x8}, mctx = 0x1a800000000}
flags = 3453643280
peer = {type = {sa = {sa_family = 27408, sa_data = "\332\315\374\177\000\000\212GA\246\221\177\000"}, sin = {sin_family = 27408, sin_port = 52698, sin_addr = {s_addr = 32764}, sin_zero = "\212GA\246\221\177\000"}, sin6 = {sin6_family = 27408, sin6_port = 52698, sin6_flowinfo = 32764, sin6_addr = {__in6_u = {__u6_addr8 = "\212GA\246\221\177\000\000 k\332\315\374\177\000", __u6_addr16 = {18314, 42561, 32657, 0, 27424, 52698, 32764, 0}, __u6_addr32 = {2789296010, 32657, 3453643552, 32764}}}, sin6_scope_id = 1384603504}, ss = {ss_family = 27408, __ss_padding = "\332\315\374\177\000\000\212GA\246\221\177\000\000 k\332\315\374\177\000\000p_\207RsU\000\000p_\207RsU\000\000\240\255\264RsU\000\000\000\000\000\000\000\000\000\000`\232\203RsU\000\000`k\332\315\374\177\000\000\324EA\246\221\177\000\000@k\332\315\374\177\000\000{\240C\246\221\177\000\000\000\000\000\000\000\000\000\000\326\005", '\000' <repeats 13 times>, __ss_align = 93953794203504}}, length = 1384603504, link = {prev = 0x7f91a643a07b, next = 0x0}}
netaddr = {family = 2789449851, type = {in = {s_addr = 32657}, in6 = {__in6_u = {__u6_addr8 = "\221\177\000\000\240\255\264RsU\000\000w\264\2517", __u6_addr16 = {32657, 0, 44448, 21172, 21875, 0, 46199, 14249}, __u6_addr32 = {32657, 1387572640, 21875, 933868663}}}, un = "\221\177\000\000\240\255\264RsU\000\000w\264\2517\363\270\277\262%\310%\001\304\370\241\215\221\237\355\250li\301\345\000\000\000\000\000\000\000\000\b\000\000\000\000\000\000\000\320k\332\315\374\177\000\0008e\207RsU\000\000\001", '\000' <repeats 15 times>, "`\232\203RsU\000\000\240\255\264RsU\000\000\320\316\202RsU\000"}, zone = 64}
match = 32764
timeout = <optimized out>
respond = <optimized out>
now = {seconds = 1533, nanoseconds = 0}
done = <optimized out>
#9 0x00007f91a63e8f28 in isc___nm_readcb (arg=<optimized out>) at netmgr/netmgr.c:1764
uvreq = 0x557352b4ada0
region = {base = 0x0, length = 0}
#10 isc__nm_readcb (sock=sock@entry=0x557352875f70, uvreq=<optimized out>, eresult=eresult@entry=ISC_R_TIMEDOUT, async=async@entry=false) at netmgr/netmgr.c:1779
No locals.
#11 0x00007f91a63e9009 in isc__nmsocket_readtimeout_cb (timer=0x5573528763b0) at netmgr/netmgr.c:1113
req = <optimized out>
sock = 0x557352875f70
#12 0x00007f91a638def6 in uv__run_timers (loop=loop@entry=0x55735287c5b0) at ./src/timer.c:178
heap_node = 0x557352876418
handle = 0x5573528763b0
#13 0x00007f91a639243a in uv_run (loop=loop@entry=0x55735287c5b0, mode=mode@entry=UV_RUN_DEFAULT) at ./src/unix/core.c:465
timeout = <optimized out>
r = <optimized out>
can_sleep = <optimized out>
#14 0x00007f91a640f554 in loop_thread (arg=arg@entry=0x55735287c590) at loop.c:282
loop = 0x55735287c590
r = <optimized out>
__func__ = "loop_thread"
ret = <optimized out>
#15 0x00007f91a641f893 in thread_body (wrap=0x55735283e170) at thread.c:85
func = 0x7f91a640f4d0 <loop_thread>
arg = 0x55735287c590
ret = 0x0
jemalloc_enforce_init = 0x557352b52d00
#16 isc_thread_main (func=func@entry=0x7f91a640f4d0 <loop_thread>, arg=0x55735287c590) at thread.c:116
No locals.
#17 0x00007f91a64106ac in isc_loopmgr_run (loopmgr=0x55735287d4c0) at loop.c:454
__func__ = "isc_loopmgr_run"
#18 0x0000557351da5766 in run_test_dispatch_getnext (state=<optimized out>) at dispatch_test.c:741
setup_loop = 0x0
teardown_loop = 0x0
#19 0x00007f91a63ba8f8 in cmocka_run_one_test_or_fixture (function_name=0x557351da813c "dispatch_getnext", test_func=0x557351da5740 <run_test_dispatch_getnext>, setup_func=setup_func@entry=0x0, teardown_func=teardown_func@entry=0x0, state=<optimized out>, state@entry=0x55735282ac80, heap_check_point=heap_check_point@entry=0x0) at ./src/cmocka.c:2801
check_point = 0x7f91a32d68d0
handle_exceptions = <optimized out>
current_state = 0x0
rc = 0
#20 0x00007f91a63bafdb in cmocka_run_one_tests (test_state=0x55735282ac70) at ./src/cmocka.c:2909
start = {tv_sec = 1700007173, tv_nsec = 801457005}
finish = {tv_sec = 0, tv_nsec = 0}
rc = 0
start = <optimized out>
finish = <optimized out>
rc = <optimized out>
#21 _cmocka_run_group_tests (group_name=group_name@entry=0x557351da806e "tests", tests=tests@entry=0x557351da9be0 <tests>, num_tests=num_tests@entry=10, group_setup=group_setup@entry=0x0, group_teardown=group_teardown@entry=0x0) at ./src/cmocka.c:3040
cmtest = 0x55735282ac70
test_number = 10
cm_tests = 0x55735282aac0
group_check_point = <optimized out>
group_state = 0x0
total_tests = <optimized out>
total_failed = <optimized out>
total_passed = 9
total_executed = 9
total_errors = 0
total_skipped = 0
total_runtime = 20.010910813999995
i = 9
rc = <optimized out>
#22 0x0000557351da5493 in main () at dispatch_test.c:855
r = <optimized out>
D:dispatch_test:backtrace from ./core.23758 end
FAIL dispatch_test (exit status: 134)