witness: lock order reversal: 1st 0xffffffff839a0d90 &sched_lock (&sched_lock) 2nd 0xffff8000299dee30 &cq->cq_mtx (&cq->cq_mtx) lock order [1] &sched_lock (&sched_lock) -> [2] &cq->cq_mtx (&cq->cq_mtx) #0 mtx_enter+0x95 sys/kern/kern_lock.c:406 #1 clockintr_cancel+0x2f sys/kern/kern_clockintr.c:323 #2 mi_switch+0x187 sys/kern/sched_bsd.c:376 #3 ast+0x15a mi_ast sys/sys/syscall_mi.h:252 [inline] #3 ast+0x15a sys/arch/amd64/amd64/trap.c:739 #4 Xsyscall+0x156 lock order [2] &cq->cq_mtx (&cq->cq_mtx) -> [1] &sched_lock (&sched_lock) #0 mtx_enter+0x95 sys/kern/kern_lock.c:406 #1 sleep_setup+0xed sys/kern/kern_synch.c:304 #2 msleep_nsec+0x10b sys/kern/kern_synch.c:217 #3 dt_ioctl_record_stop+0xbc sys/dev/dt/dt_dev.c:589 #4 dtclose+0x109 dt_pcb_purge sys/dev/dt/dt_dev.c:-1 [inline] #4 dtclose+0x109 sys/dev/dt/dt_dev.c:239 #5 spec_close+0x466 sys/kern/spec_vnops.c:-1 #6 VOP_CLOSE+0x132 sys/kern/vfs_vops.c:156 #7 vn_closefile+0x12b vn_close sys/kern/vfs_vnops.c:292 [inline] #7 vn_closefile+0x12b sys/kern/vfs_vnops.c:615 #8 fdrop+0x121 sys/kern/kern_descrip.c:1280 #9 closef+0x192 sys/kern/kern_descrip.c:1264 #10 fdfree+0x116 sys/kern/kern_descrip.c:1195 #11 exit1+0x576 sys/kern/kern_exit.c:215 #12 sys_exit+0x1a sys/kern/kern_exit.c:-1 #13 syscall+0xb17 mi_syscall sys/sys/syscall_mi.h:176 [inline] #13 syscall+0xb17 sys/arch/amd64/amd64/trap.c:775 #14 Xsyscall+0x128 Stopped at db_enter+0x25: addq $0x8,%rsp ddb{1}> ddb{1}> set $lines = 0 ddb{1}> set $maxwidth = 0 ddb{1}> show panic the kernel did not panic ddb{1}> trace db_enter() at db_enter+0x25 sys/arch/amd64/amd64/db_interface.c:438 witness_checkorder(ffff8000299dee30,9,0) at witness_checkorder+0x10d1 sys/kern/subr_witness.c:-1 mtx_enter(ffff8000299dee20) at mtx_enter+0x95 sys/kern/kern_lock.c:406 clockintr_cancel(ffff8000299de2f8) at clockintr_cancel+0x2f sys/kern/kern_clockintr.c:323 mi_switch() at mi_switch+0x187 sys/kern/sched_bsd.c:376 ast(ffff80003c421160) at ast+0x15a mi_ast sys/sys/syscall_mi.h:252 [inline] ast(ffff80003c421160) at ast+0x15a sys/arch/amd64/amd64/trap.c:739 Xsyscall() at Xsyscall+0x156 end of kernel end trace frame: 0xf75af6304b0, count: -7 ddb{1}> show registers rdi 0 rsi 0 rbp 0xffff80003c420f60 rbx 0 rdx 0 rcx 0xffff8000fffe6550 rax 0xffff8000299ddff0 r8 0xffff80003c420e40 r9 0x8080808080808080 r10 0xf5384e79294262e5 r11 0x76cf9be23a8998cc r12 0xfffffd8003f4c300 r13 0xfffffd800473cd58 r14 0x3 r15 0xffffffff8341ef74 substchar+0x514d rip 0xffffffff81be7eb5 db_enter+0x25 cs 0x8 rflags 0x246 rsp 0xffff80003c420f50 ss 0x10 db_enter+0x25: addq $0x8,%rsp ddb{1}> show proc PROC (syz-executor) tid=129247 pid=63873 tcnt=4 stat=run flags process=4000000 proc=4000000 runpri=50, usrpri=50, slppri=32, nice=20 wchan=0x0, wmesg=, ps_single=0x0 scnt=0 ecnt=0 forw=0x0, list=0xffff8000fffe74e0,0xffff8000fffe62c8 process=0xffff80003c40d830 user=0xffff80003c41c000, vmspace=0xfffffd800eff9d78 estcpu=36, cpticks=0, pctcpu=0.0, user=0, sys=0, intr=0 ddb{1}> ps PID TID PPID UID S FLAGS WAIT COMMAND 63873 330613 91472 0 2 0x4000000 syz-executor *63873 129247 91472 0 2 0x4000000 syz-executor 63873 387394 91472 0 2 0x4000000 syz-executor 63873 30546 91472 0 3 0x4000080 fsleep syz-executor 89373 415174 39592 0 7 0x10 syz-executor 89373 418993 39592 0 2 0x4000090 syz-executor 41402 443433 17379 0 3 0x80 nanoslp syz-executor 41402 96808 17379 0 3 0x4000080 ttyout syz-executor 41402 160106 17379 0 3 0x4000080 fsleep syz-executor 38999 100550 95197 0 2 0 syz-executor 38999 398423 95197 0 2 0x4000000 syz-executor 38999 122489 95197 0 3 0x4000080 fsleep syz-executor 38999 302792 95197 0 2 0x4000000 syz-executor 35633 117529 23751 0 2 0 syz-executor 58710 185494 0 0 3 0x14280 nfsidl nfsio 22440 231446 0 0 3 0x14280 nfsidl nfsio 44226 159476 86405 0 2 0 syz-executor 44226 396017 86405 0 3 0x4000080 fsleep syz-executor 44226 322691 86405 0 3 0x4000080 fsleep syz-executor 57174 91001 90721 0 2 0 syz-executor 57174 213291 90721 0 3 0x4000080 fsleep syz-executor 57174 201620 90721 0 3 0x4000080 fsleep syz-executor 55926 332116 35599 0 3 0x100082 sbwait ndp 35599 428045 29214 0 3 0x10008a sigsusp sh 90721 420953 33094 0 3 0x82 nanoslp syz-executor 86405 205609 33094 0 3 0x82 nanoslp syz-executor 91472 98952 33094 0 3 0x82 nanoslp syz-executor 95197 140036 33094 0 3 0x82 nanoslp syz-executor 23751 497501 33094 0 3 0x82 nanoslp syz-executor 17379 155520 33094 0 3 0x82 nanoslp syz-executor 29214 204815 33094 0 3 0x82 wait syz-executor 39592 522431 33094 0 3 0x82 nanoslp syz-executor 33094 434836 69014 0 3 0x82 kqread syz-executor 69014 190186 18411 0 3 0x10008a sigsusp ksh 18411 325972 73681 0 3 0x98 kqread sshd-session 73681 371795 61377 0 3 0x92 kqread sshd-session 16148 76013 1 0 3 0x100083 ttyin getty 61377 194406 1 0 3 0x88 kqread sshd 57588 272746 76831 74 3 0x1100092 bpf pflogd 76831 37424 1 0 3 0x80 sbwait pflogd 58467 399079 98208 73 3 0x1100090 kqread syslogd 98208 473293 1 0 3 0x100082 sbwait syslogd 82107 284738 1 0 3 0x100080 kqread resolvd 89329 275421 50998 77 3 0x100092 kqread dhcpleased 31098 349060 50998 77 3 0x100092 kqread dhcpleased 50998 10522 1 0 3 0x80 kqread dhcpleased 63842 111427 0 0 3 0x14200 pause smr 52979 206308 0 0 2 0x14200 zerothread 51420 400490 0 0 3 0x14200 aiodoned aiodoned 78457 3142 0 0 3 0x14200 syncer update 13352 4443 0 0 3 0x14200 cleaner cleaner 15008 233391 0 0 3 0x14200 reaper reaper 71212 10366 0 0 3 0x14200 pgdaemon pagedaemon 57692 200130 0 0 3 0x14200 bored viomb 5581 509445 0 0 3 0x40014200 acpi0 acpi0 3767 436098 0 0 3 0x40014200 idle1 64646 399835 0 0 3 0x14200 bored softnet1 29938 35607 0 0 3 0x14200 bored softnet0 12003 410164 0 0 3 0x14200 bored systqmp 72095 352586 0 0 3 0x14200 bored systq 36946 44668 0 0 3 0x14200 tmoslp softclockmp 53556 319497 0 0 3 0x40014200 tmoslp softclock 4375 72298 0 0 3 0x40014200 idle0 1 240792 0 0 3 0x82 wait init 0 0 -1 0 3 0x10010200 scheduler swapper ddb{1}> show all locks CPU 0: shared mutex timeout r = 0 (0xffffffff8385fcf0) #0 witness_lock+0x5f1 stacktrace_save sys/sys/stacktrace.h:37 [inline] #0 witness_lock+0x5f1 sys/kern/subr_witness.c:1160 #1 timeout_run+0x131 sys/kern/kern_timeout.c:694 #2 softclock_process_tick_timeout+0x232 sys/kern/kern_timeout.c:756 #3 softclock+0x152 sys/kern/kern_timeout.c:788 #4 softintr_dispatch+0x13b sys/kern/kern_softintr.c:84 #5 dosoftint+0x54 sys/arch/amd64/amd64/intr.c:862 #6 Xsoftclock+0x27 CPU 1: exclusive mutex &sched_lock r = 0 (0xffffffff839a0d90) #0 witness_lock+0x5f1 stacktrace_save sys/sys/stacktrace.h:37 [inline] #0 witness_lock+0x5f1 sys/kern/subr_witness.c:1160 #1 mtx_enter+0x4b4 sys/kern/kern_lock.c:487 #2 preempt+0x35 sys/kern/sched_bsd.c:338 #3 ast+0x15a mi_ast sys/sys/syscall_mi.h:252 [inline] #3 ast+0x15a sys/arch/amd64/amd64/trap.c:739 #4 Xsyscall+0x156 Process 89373 (syz-executor) thread 0xffff80003c441a18 (415174) exclusive kernel_lock &kernel_lock r = 0 (0xffffffff83993fc8) #0 witness_lock+0x5f1 stacktrace_save sys/sys/stacktrace.h:37 [inline] #0 witness_lock+0x5f1 sys/kern/subr_witness.c:1160 #1 softintr_dispatch+0x125 sys/kern/kern_softintr.c:83 #2 dosoftint+0x54 sys/arch/amd64/amd64/intr.c:862 #3 Xsoftclock+0x27 ddb{1}> show malloc Type InUse MemUse HighUse Limit Requests Type Lim devbuf 11065 12219K 12283K 166960K 12269 0 pcb 17 12K 12K 166960K 32 0 rtable 215 6K 6K 166960K 360 0 pf 34 17K 21K 166960K 56 0 ifaddr 44 7K 8K 166960K 49 0 ifgroup 55 2K 2K 166960K 59 0 sysctl 1 1K 9K 166960K 5 0 counters 70 37K 37K 166960K 74 0 ioctlops 0 0K 4K 166960K 1523 0 iov 0 0K 12K 166960K 1 0 mount 1 1K 1K 166960K 1 0 log 0 0K 0K 166960K 4 0 vnodes 1373 86K 87K 166960K 1438 0 UFS quota 1 32K 32K 166960K 1 0 UFS mount 5 36K 36K 166960K 5 0 shm 2 1K 5K 166960K 3 0 VM map 2 1K 1K 166960K 2 0 sem 5 0K 0K 166960K 5 0 dirhash 12 2K 2K 166960K 12 0 ACPI 1692 195K 286K 166960K 12470 0 file desc 19 69K 93K 166960K 186 0 proc 75 131K 164K 166960K 537 0 subproc 72 4K 4K 166960K 72 0 NFS srvsock 1 0K 0K 166960K 1 0 NFS daemon 1 16K 16K 166960K 1 0 ip_moptions 0 0K 0K 166960K 1 0 in_multi 102 7K 7K 166960K 105 0 ether_multi 1 0K 0K 166960K 1 0 mrt 0 0K 0K 166960K 2 0 ISOFS mount 1 32K 32K 166960K 1 0 MSDOSFS mount 1 16K 16K 166960K 1 0 ttys 49 228K 228K 166960K 49 0 exec 0 0K 1K 166960K 388 0 fusefs mount 1 32K 32K 166960K 1 0 tdb 3 0K 0K 166960K 3 0 VM swap 8 62K 64K 166960K 10 0 UVM amap 256 162K 175K 166960K 3646 0 UVM aobj 4 2K 2K 166960K 4 0 pinsyscall 45 90K 108K 166960K 1353 0 memdesc 1 4K 4K 166960K 1 0 crypto data 1 1K 1K 166960K 1 0 ip6_options 0 0K 0K 166960K 6 0 NDP 12 0K 1K 166960K 30 0 temp 37 8666K 8731K 166960K 7135 0 kqueue 15 24K 24K 166960K 33 0 SYN cache 2 16K 16K 166960K 2 0 ddb{1}> show all pools Name Size Requests Fail Releases Pgreq Pgrel Npage Hiwat Minpg Maxpg Idle plcache 128 26 0 0 1 0 1 1 0 8 0 rtpcb 120 38 0 34 1 0 1 1 0 8 0 rtentry 176 112 0 13 5 0 5 5 0 8 0 unpcb 144 50 0 33 1 0 1 1 0 8 0 syncache 336 3 0 3 1 1 0 1 0 8 0 tcpcb 736 15 0 9 1 0 1 1 0 8 0 arp 136 18 0 0 1 0 1 1 0 8 0 inpcb 328 102 0 92 2 0 2 2 0 8 1 nd6 152 23 0 0 1 0 1 1 0 8 0 kcovpl 48 8 0 0 1 0 1 1 0 8 0 ppxss 1192 2 0 2 1 1 0 1 0 8 0 pfosfp 40 1428 0 1005 5 0 5 5 0 8 0 pfosfpen 112 1428 0 714 21 0 21 21 0 8 0 pfanchor 1288 1 0 1 1 1 0 1 0 8 0 pfstitem 24 20 0 0 1 0 1 1 0 8 0 pfstkey 128 20 0 0 1 0 1 1 0 8 0 pfstate 448 20 0 0 3 0 3 3 0 8 0 pfrule 1344 23 0 18 2 1 1 2 0 8 0 rttmr 136 1 0 1 1 1 0 1 0 8 0 art_heap8 4096 1 0 0 1 0 1 1 0 8 0 art_heap4 256 483 0 41 31 0 31 31 0 8 1 art_table 40 484 0 41 5 0 5 5 0 8 0 art_node 32 112 0 23 1 0 1 1 0 8 0 semupl 112 1 0 1 1 0 1 1 0 8 1 semapl 112 3 0 0 1 0 1 1 0 8 0 shmpl 112 1 0 0 1 0 1 1 0 8 0 dirhash 1024 17 0 0 3 0 3 3 0 8 0 dino2pl 256 1654 0 136 95 0 95 95 0 8 0 ffsino 296 1654 0 136 117 0 117 117 0 8 0 nchpl 144 1916 0 215 64 0 64 64 0 8 0 vnodes 216 1799 0 0 100 0 100 100 0 8 0 namei 1024 6027 0 6027 2 1 1 1 0 8 1 percpumem 16 52 0 2 1 0 1 1 0 8 0 kstatmem 264 30 0 4 2 0 2 2 0 8 0 scxspl 216 6359 0 6359 3 2 1 2 1 8 1 plimitpl 152 38 0 21 1 0 1 1 0 8 0 sigapl 424 511 0 460 7 1 6 7 0 8 0 knotepl 120 292 0 0 9 0 9 9 0 8 0 kqueuepl 224 32 0 21 1 0 1 1 0 8 0 pipepl 344 121 0 94 3 0 3 3 0 8 0 fdescpl 528 491 0 458 3 0 3 3 0 8 0 filepl 160 1943 0 1657 14 2 12 12 0 8 0 lockfpl 104 29 0 25 1 0 1 1 0 8 0 lockfspl 48 15 0 11 1 0 1 1 0 8 0 sessionpl 144 22 0 13 1 0 1 1 0 8 0 pgrppl 48 30 0 13 1 0 1 1 0 8 0 ucredpl 104 110 0 96 1 0 1 1 0 8 0 zombiepl 144 460 0 460 2 1 1 1 0 8 1 processpl 1232 511 0 460 5 0 5 5 0 8 0 procpl 664 621 0 557 6 0 6 6 0 8 0 sosppl 176 2 0 2 1 1 0 1 0 8 0 sockpl 752 191 0 160 5 1 4 4 0 8 0 mcl64k 65536 1 0 0 1 0 1 1 0 8 0 mcl8k 8192 1 0 0 1 0 1 1 0 8 0 mcl4k 4096 118 0 0 15 0 15 15 0 8 0 mcl2k 2048 35 0 0 5 0 5 5 0 8 0 mtagpl 96 3 0 0 1 0 1 1 0 8 0 mbufpl 256 242 0 0 16 0 16 16 0 8 0 bufpl 280 2480 0 130 168 0 168 168 0 8 0 anonpl 32 3933 0 0 32 0 32 32 0 246 0 amapchunkpl 152 10392 0 9891 29 8 21 26 0 158 1 amappl16 200 2008 0 1986 5 3 2 5 0 8 0 amappl15 192 5 0 5 1 1 0 1 0 8 0 amappl14 184 3 0 3 1 1 0 1 0 8 0 amappl13 176 443 0 441 1 0 1 1 0 8 0 amappl12 168 861 0 817 3 0 3 3 0 8 0 amappl11 160 7 0 7 1 1 0 1 0 8 0 amappl10 152 49 0 35 1 0 1 1 0 8 0 amappl9 144 253 0 253 1 1 0 1 0 8 0 amappl8 136 26 0 24 1 0 1 1 0 8 0 amappl7 128 88 0 87 1 0 1 1 0 8 0 amappl6 120 288 0 273 1 0 1 1 0 8 0 amappl5 112 73 0 63 1 0 1 1 0 8 0 amappl4 104 435 0 402 1 0 1 1 0 8 0 amappl3 96 1649 0 1554 4 1 3 3 0 8 0 amappl2 88 604 0 528 2 0 2 2 0 8 0 amappl1 80 9441 0 8821 15 1 14 15 0 8 0 amappl 88 2876 0 2706 4 0 4 4 0 92 0 uvmvnodes 80 101 0 0 3 0 3 3 0 8 0 dma4096 4096 1 0 1 1 1 0 1 0 8 0 dma1024 1024 1 0 0 1 0 1 1 0 8 0 dma256 256 6 0 6 1 1 0 1 0 8 0 dma128 128 253 0 253 1 1 0 1 0 8 0 dma64 64 6 0 6 1 1 0 1 0 8 0 dma32 32 7 0 7 1 1 0 1 0 8 0 dma16 16 18 0 17 1 0 1 1 0 8 0 aobjpl 72 3 0 0 1 0 1 1 0 8 0 uaddrrnd 24 491 0 458 1 0 1 1 0 8 0 uaddrbest 32 2 0 0 1 0 1 1 0 8 0 uaddr 24 491 0 458 1 0 1 1 0 8 0 vmmpekpl 168 5890 0 5858 2 0 2 2 0 8 0 vmmpepl 168 39318 0 37340 90 2 88 88 0 357 0 vmsppl 488 490 0 458 5 0 5 5 0 8 0 rwobjpl 80 14303 0 13237 25 1 24 25 0 8 0 pdppl 4096 989 0 916 105 32 73 85 0 8 0 pvpl 32 10720 0 0 88 1 87 87 0 265 0 pmappl 256 490 0 458 3 0 3 3 0 8 0 extentpl 40 45 0 27 1 0 1 1 0 8 0 phpool 112 286 0 36 8 0 8 8 0 8 0 ddb{1}> machine ddbcpu 0 Stopped at x86_ipi_db+0x27: addq $0x8,%rsp ddb{0}> trace x86_ipi_db(ffffffff8381aff0) at x86_ipi_db+0x27 sys/arch/amd64/amd64/db_interface.c:394 x86_ipi_handler() at x86_ipi_handler+0xd9 sys/arch/amd64/amd64/ipi.c:106 Xresume_lapic_ipi() at Xresume_lapic_ipi+0x27 mtx_enter(ffffffff839a0d80) at mtx_enter+0x377 sys/kern/kern_lock.c:454 endtsleep(ffff8000fffef770) at endtsleep+0x39 sys/kern/kern_synch.c:540 timeout_run(ffffffff8385fd48,ffff8000fffef808) at timeout_run+0x159 sys/kern/kern_timeout.c:698 softclock_process_tick_timeout(ffff8000fffef808,0) at softclock_process_tick_timeout+0x232 sys/kern/kern_timeout.c:756 softclock(0) at softclock+0x152 sys/kern/kern_timeout.c:788 softintr_dispatch(0) at softintr_dispatch+0x13b sys/kern/kern_softintr.c:84 dosoftint(0) at dosoftint+0x54 sys/arch/amd64/amd64/intr.c:862 Xsoftclock() at Xsoftclock+0x27 end of kernel end trace frame: 0x774fa6d78870, count: -11 ddb{0}> machine ddbcpu 1 Stopped at db_enter+0x25: addq $0x8,%rsp ddb{1}> trace db_enter() at db_enter+0x25 sys/arch/amd64/amd64/db_interface.c:438 witness_checkorder(ffff8000299dee30,9,0) at witness_checkorder+0x10d1 sys/kern/subr_witness.c:-1 mtx_enter(ffff8000299dee20) at mtx_enter+0x95 sys/kern/kern_lock.c:406 clockintr_cancel(ffff8000299de2f8) at clockintr_cancel+0x2f sys/kern/kern_clockintr.c:323 mi_switch() at mi_switch+0x187 sys/kern/sched_bsd.c:376 ast(ffff80003c421160) at ast+0x15a mi_ast sys/sys/syscall_mi.h:252 [inline] ast(ffff80003c421160) at ast+0x15a sys/arch/amd64/amd64/trap.c:739 Xsyscall() at Xsyscall+0x156 end of kernel end trace frame: 0xf75af6304b0, count: -7