login: witness: lock order reversal: 1st 0xffffffff83884e30 &cq->cq_mtx (&cq->cq_mtx) 2nd 0xffffffff8395d808 &sched_lock (&sched_lock) lock order [1] &cq->cq_mtx (&cq->cq_mtx) -> [2] &sched_lock (&sched_lock) #0 mtx_enter+149 #1 sleep_setup+237 #2 msleep_nsec+267 #3 dt_ioctl_record_stop+188 #4 dtclose+265 #5 spec_close+1126 #6 VOP_CLOSE+306 #7 vn_closefile+299 #8 fdrop+289 #9 closef+402 #10 syscall+3028 #11 Xsyscall+296 lock order [2] &sched_lock (&sched_lock) -> [1] &cq->cq_mtx (&cq->cq_mtx) #0 mtx_enter+149 #1 clockintr_cancel+47 #2 mi_switch+391 #3 sleep_finish+728 #4 sys_futex+2960 #5 syscall+3028 #6 Xsyscall+296 Stopped at db_enter+37: addq $8,%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+37 witness_checkorder(ffffffff8395d808,9,0) at witness_checkorder+4305 mtx_enter(ffffffff8395d7f8) at mtx_enter+149 sleep_setup(ffffffff83884e80,220,ffffffff834376d6) at sleep_setup+237 msleep_nsec(ffffffff83884e80,ffffffff83884e20,220,ffffffff834376d6,ffffffffffffffff) at msleep_nsec+267 dt_ioctl_record_stop(ffff800001594000) at dt_ioctl_record_stop+188 dtclose(41e5f,81,2000,ffff80003bc12fb8) at dtclose+265 spec_close(ffff80003c41cd20) at spec_close+1126 VOP_CLOSE(fffffd806193ddb8,81,fffffd80097fd6e8,ffff80003bc12fb8) at VOP_CLOSE+306 vn_closefile(fffffd806c89ba40,ffff80003bc12fb8) at vn_closefile+299 fdrop(fffffd806c89ba40,ffff80003bc12fb8) at fdrop+289 closef(fffffd806c89ba40,ffff80003bc12fb8) at closef+402 syscall(ffff80003c41cf80) at syscall+3028 Xsyscall() at Xsyscall+296 end of kernel end trace frame: 0x9e287934f70, count: -14 ddb{1}> show registers rdi 0 rsi 524288 acpi_pdirpa+441969 rbp 18446603337232140784 rbx 0 rdx 18446603336243591680 rcx 18446603337223712696 rax 524287 acpi_pdirpa+441968 r8 18446603337232140496 r9 9259542123273814144 r10 15355851264896139671 r11 17564001860556248145 r12 18446741324996857408 r13 18446741325005172056 r14 3 r15 18446744071616745774 substchar+42319 rip 18446744071580260309 db_enter+37 cs 8 rflags 582 rsp 18446603337232140768 ss 16 db_enter+37: addq $8,%rsp ddb{1}> show proc PROC (syz-executor) tid=293878 pid=8248 tcnt=2 stat=onproc flags process=0 proc=4000000 runpri=32, usrpri=50, slppri=32, nice=20 wchan=0x0, wmesg=, ps_single=0x0 scnt=0 ecnt=0 forw=0xffffffffffffffff, list=0xffff80003bc122c0,0xffff80003bc13cc0 process=0xffff80003c4bd368 user=0xffff80003c418000, vmspace=0xfffffd806b3aa7c0 estcpu=36, cpticks=0, pctcpu=0.0, user=0, sys=0, intr=0 ddb{1}> ps PID TID PPID UID S FLAGS WAIT COMMAND 63332 147085 96850 0 2 0 syz-executor 63332 312293 96850 0 3 0x4000080 fsleep syz-executor 63332 384692 96850 0 2 0x4000000 syz-executor 63332 510473 96850 0 2 0x4000000 syz-executor 8248 285063 83952 0 7 0 syz-executor * 8248 293878 83952 0 7 0x4000000 syz-executor 62945 445982 36953 0 2 0 syz-executor 62945 388793 36953 0 3 0x4000000 smrbar syz-executor 60849 312763 62776 0 2 0 syz-executor 42423 172925 31471 0 3 0x2 biowait syz-executor 1511 229804 1 0 3 0x100083 ttyin getty 6265 60302 0 0 3 0x14280 nfsidl nfsio 68954 462404 0 0 3 0x14280 nfsidl nfsio 69509 475634 0 0 3 0x14280 nfsidl nfsio 28906 150661 0 0 3 0x14280 nfsidl nfsio 11328 308280 0 0 3 0x14280 nfsidl nfsio 2209 504612 0 0 3 0x14280 nfsidl nfsio 86400 329424 0 0 3 0x14280 nfsidl nfsio 53090 497506 0 0 3 0x14280 nfsidl nfsio 27375 93632 0 0 3 0x14280 nfsidl nfsio 86481 517548 0 0 3 0x14280 nfsidl nfsio 33707 34918 0 0 3 0x14280 nfsidl nfsio 72626 477829 0 0 3 0x14280 nfsidl nfsio 85407 421685 0 0 3 0x14280 nfsidl nfsio 98483 104401 0 0 3 0x14280 nfsidl nfsio 75052 363527 0 0 3 0x14280 nfsidl nfsio 55489 180697 0 0 3 0x14280 nfsidl nfsio 60533 150278 0 0 3 0x14280 nfsidl nfsio 44196 146122 0 0 3 0x14280 nfsidl nfsio 28244 521679 0 0 3 0x14280 nfsidl nfsio 29082 447340 0 0 3 0x14280 nfsidl nfsio 14874 455123 31471 0 3 0x82 nanoslp syz-executor 62776 394698 31471 0 2 0x2 syz-executor 16848 455624 31471 0 3 0x82 wait syz-executor 36953 374091 31471 0 2 0x2 syz-executor 83952 479233 31471 0 3 0x82 nanoslp syz-executor 29598 179303 31471 0 3 0x2 biowait syz-executor 96850 238041 31471 0 3 0x82 nanoslp syz-executor 31471 28326 67279 0 2 0x2 syz-executor 67279 477468 15616 0 3 0x10008a sigsusp ksh 15616 193785 72475 0 3 0x98 kqread sshd-session 72475 163546 80533 0 3 0x92 kqread sshd-session 80533 456116 1 0 3 0x88 kqread sshd 75527 498264 19337 74 3 0x1100092 bpf pflogd 19337 3648 1 0 3 0x80 sbwait pflogd 58479 468071 31289 73 3 0x1100090 kqread syslogd 31289 512691 1 0 3 0x100082 sbwait syslogd 26930 143483 1 0 3 0x100080 kqread resolvd 60682 36661 75531 77 3 0x100092 kqread dhcpleased 34520 502182 75531 77 3 0x100092 kqread dhcpleased 75531 316777 1 0 3 0x80 kqread dhcpleased 27148 282846 0 0 3 0x14200 bored smr 72264 71763 0 0 2 0x14200 zerothread 49704 305029 0 0 3 0x14200 aiodoned aiodoned 80550 375166 0 0 3 0x14200 syncer update 64669 503765 0 0 3 0x14200 cleaner cleaner 72202 159145 0 0 3 0x14200 reaper reaper 87643 16103 0 0 3 0x14200 pgdaemon pagedaemon 18311 33385 0 0 3 0x14200 bored viomb 73439 111842 0 0 3 0x40014200 acpi0 acpi0 179 16288 0 0 3 0x40014200 idle1 77078 255859 0 0 3 0x14200 bored softnet1 82237 486106 0 0 3 0x14200 bored softnet0 76565 438494 0 0 3 0x14200 smrbar systqmp 45530 251990 0 0 3 0x14200 bored systq 50373 148409 0 0 3 0x14200 tmoslp softclockmp 77816 170740 0 0 3 0x40014200 tmoslp softclock 61220 154315 0 0 3 0x40014200 idle0 1 147658 0 0 3 0x80082 wait init 0 0 -1 0 3 0x10010200 scheduler swapper ddb{1}> show all locks CPU 1: exclusive mutex &cq->cq_mtx r = 0 (0xffffffff83884e30) #0 witness_lock+1521 #1 mtx_enter+1204 #2 clockintr_unbind+86 #3 dt_ioctl_record_stop+188 #4 dtclose+265 #5 spec_close+1126 #6 VOP_CLOSE+306 #7 vn_closefile+299 #8 fdrop+289 #9 closef+402 #10 syscall+3028 #11 Xsyscall+296 Process 8248 (syz-executor) thread 0xffff80003bc12fb8 (293878) exclusive rwlock dtlk r = 0 (0xffffffff83868938) #0 witness_lock+1521 #1 rw_do_enter_write+1049 #2 dt_ioctl_record_stop+46 #3 dtclose+265 #4 spec_close+1126 #5 VOP_CLOSE+306 #6 vn_closefile+299 #7 fdrop+289 #8 closef+402 #9 syscall+3028 #10 Xsyscall+296 exclusive kernel_lock &kernel_lock r = 0 (0xffffffff839bac88) #0 witness_lock+1521 #1 vn_closefile+65 #2 fdrop+289 #3 closef+402 #4 syscall+3028 #5 Xsyscall+296 exclusive mutex &cq->cq_mtx r = 0 (0xffffffff83884e30) #0 witness_lock+1521 #1 mtx_enter+1204 #2 clockintr_unbind+86 #3 dt_ioctl_record_stop+188 #4 dtclose+265 #5 spec_close+1126 #6 VOP_CLOSE+306 #7 vn_closefile+299 #8 fdrop+289 #9 closef+402 #10 syscall+3028 #11 Xsyscall+296 Process 42423 (syz-executor) thread 0xffff80003c42b4f8 (172925) exclusive rrwlock inode r = 0 (0xfffffd8072e016a0) #0 witness_lock+1521 #1 rw_do_enter_write+1049 #2 rrw_enter+198 #3 VOP_LOCK+189 #4 ufs_ihashins+79 #5 ffs_vget+391 #6 ffs_inode_alloc+633 #7 ufs_mkdir+252 #8 VOP_MKDIR+257 #9 domkdirat+377 #10 syscall+2839 #11 Xsyscall+296 exclusive rrwlock inode r = 0 (0xfffffd806f5147d8) #0 witness_lock+1521 #1 rw_do_enter_write+1049 #2 rrw_enter+198 #3 VOP_LOCK+189 #4 vn_lock+164 #5 vfs_lookup+284 #6 namei+1994 #7 domkdirat+139 #8 syscall+2839 #9 Xsyscall+296 Process 29598 (syz-executor) thread 0xffff8000ffffc538 (179303) exclusive rrwlock inode r = 0 (0xfffffd8072e010d8) #0 witness_lock+1521 #1 rw_do_enter_write+1049 #2 rrw_enter+198 #3 VOP_LOCK+189 #4 vn_lock+164 #5 vget+674 #6 ufs_ihashget+389 #7 ffs_vget+140 #8 ufs_lookup+6710 #9 VOP_LOOKUP+110 #10 vfs_lookup+2362 #11 namei+1994 #12 dounlinkat+193 #13 syscall+2839 #14 Xsyscall+296 exclusive rrwlock inode r = 0 (0xfffffd806daa5320) #0 witness_lock+1521 #1 rw_do_enter_write+1049 #2 rrw_enter+198 #3 VOP_LOCK+189 #4 vn_lock+164 #5 vfs_lookup+284 #6 namei+1994 #7 dounlinkat+193 #8 syscall+2839 #9 Xsyscall+296 Process 76565 (systqmp) thread 0xffff8000ffffe7c8 (438494) shared rwlock systqmp r = 0 (0xffffffff8385da18) #0 witness_lock+1521 #1 taskq_thread+298 #2 proc_trampoline+16 ddb{1}> show malloc Type InUse MemUse HighUse Limit Requests Type Lim devbuf 11118 12180K 13609K 166960K 13964 0 pcb 18 18K 20K 166960K 368 0 rtable 244 15K 16K 166960K 710 0 pf 35 17K 19K 166960K 122 0 ifaddr 42 7K 8K 166960K 121 0 ifgroup 56 2K 2K 166960K 174 0 sysctl 4 1K 9K 166960K 15 0 counters 72 37K 37K 166960K 252 0 ioctlops 0 0K 4K 166960K 1766 0 iov 0 0K 16K 166960K 141 0 mount 1 1K 1K 166960K 1 0 log 0 0K 0K 166960K 4 0 vnodes 1490 94K 95K 166960K 2458 0 UFS quota 1 32K 32K 166960K 1 0 UFS mount 5 36K 36K 166960K 5 0 shm 2 1K 9K 166960K 25 0 VM map 2 1K 1K 166960K 2 0 sem 12 0K 0K 166960K 47 0 dirhash 12 2K 2K 166960K 30 0 ACPI 1692 195K 286K 166960K 12470 0 file desc 16 57K 240K 166960K 1450 0 sigio 0 0K 0K 166960K 29 0 proc 73 115K 164K 166960K 909 0 subproc 72 4K 4K 166960K 136 0 NFS srvsock 1 0K 0K 166960K 1 0 NFS daemon 1 16K 16K 166960K 1 0 ip_moptions 0 0K 0K 166960K 173 0 in_multi 90 6K 7K 166960K 238 0 ether_multi 1 0K 0K 166960K 12 0 mrt 0 0K 0K 166960K 16 0 ISOFS mount 1 32K 32K 166960K 1 0 MSDOSFS mount 1 16K 16K 166960K 1 0 ttys 247 1102K 1102K 166960K 247 0 exec 0 0K 1K 166960K 681 0 fusefs mount 1 32K 32K 166960K 1 0 pfkey data 0 0K 0K 166960K 3 0 tdb 3 0K 0K 166960K 3 0 VM swap 8 62K 64K 166960K 10 0 UVM amap 218 161K 186K 166960K 14521 0 UVM aobj 48 12K 12K 166960K 58 0 pinsyscall 41 82K 100K 166960K 2775 0 memdesc 1 4K 4K 166960K 1 0 crypto data 1 1K 1K 166960K 1 0 ip6_options 0 0K 1K 166960K 106 0 NDP 15 0K 1K 166960K 81 0 temp 66 8677K 8932K 166960K 50141 0 kqueue 13 20K 28K 166960K 219 0 SYN cache 2 8K 16K 166960K 3 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 198 0 195 2 1 1 2 0 8 0 rtentry 176 214 0 120 6 0 6 6 0 8 0 unpcb 144 953 0 935 5 3 2 4 0 8 1 syncache 336 14 0 14 1 0 1 1 0 8 1 tcpqe 32 3 0 3 1 1 0 1 0 8 0 tcpcb 736 636 0 629 22 17 5 22 0 8 2 arp 136 35 0 20 1 0 1 1 0 8 0 inpcb 328 2007 0 1996 29 22 7 26 0 8 5 nd6 152 50 0 25 2 0 2 2 0 8 0 pkpcb 40 6 0 5 2 1 1 1 0 8 0 kcovpl 48 15 0 7 1 0 1 1 0 8 0 mppekey 1024 1 0 1 1 1 0 1 0 8 0 ppxss 1192 73 0 73 1 0 1 1 0 8 1 pppxif 1504 6 0 6 1 1 0 1 0 8 0 pffrag 232 12 0 2 1 0 1 1 0 482 0 pffrnode 88 11 0 1 1 0 1 1 0 8 0 pffrent 40 17 0 7 1 0 1 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 rttmr 136 3 0 3 1 1 0 1 0 8 0 art_heap8 4096 3 0 0 3 0 3 3 0 8 0 art_heap4 256 892 0 477 32 2 30 31 0 8 3 art_table 40 895 0 477 5 0 5 5 0 8 0 art_node 32 213 0 129 1 0 1 1 0 8 0 sysvmsgpl 40 7 0 4 1 0 1 1 0 8 0 semupl 112 3 0 3 2 2 0 1 0 8 0 semapl 112 45 0 35 1 0 1 1 0 8 0 shmpl 112 47 0 7 2 0 2 2 0 8 0 dirhash 1024 29 0 12 3 0 3 3 0 8 0 dino2pl 256 3934 0 2421 96 0 96 96 0 8 0 ffsino 296 3934 0 2421 117 0 117 117 0 8 0 nchpl 144 5766 0 4047 64 0 64 64 0 8 0 rtmask 32 9 0 9 2 1 1 1 0 8 1 vnodes 216 4575 0 0 255 0 255 255 0 8 0 namei 1024 20407 0 20406 1 0 1 1 0 8 0 percpumem 16 141 0 90 1 0 1 1 0 8 0 vcpupl 3968 6 0 1 1 0 1 1 0 8 0 vmpool 848 8 0 3 1 0 1 1 0 8 0 kstatmem 264 104 0 74 4 1 3 3 0 8 0 scsiplug 72 5 0 5 1 0 1 1 0 8 1 scxspl 216 27857 0 27855 9 8 1 8 1 8 0 plimitpl 152 495 0 478 1 0 1 1 0 8 0 sigapl 424 1739 0 1673 8 0 8 8 0 8 0 knotepl 120 639 0 0 20 0 20 20 0 8 0 kqueuepl 224 547 0 538 6 4 2 5 0 8 1 pipepl 344 292 0 265 9 0 9 9 0 8 6 fdescpl 528 1701 0 1671 3 0 3 3 0 8 0 filepl 160 11046 0 10820 25 7 18 25 0 8 7 lockfpl 104 395 0 393 1 0 1 1 0 8 0 lockfspl 48 166 0 164 1 0 1 1 0 8 0 sessionpl 144 41 0 32 1 0 1 1 0 8 0 pgrppl 48 134 0 117 1 0 1 1 0 8 0 ucredpl 104 1686 0 1673 1 0 1 1 0 8 0 zombiepl 144 1675 0 1673 1 0 1 1 0 8 0 processpl 1232 1739 0 1673 6 0 6 6 0 8 0 procpl 664 3810 0 3739 8 0 8 8 0 8 0 sosppl 176 15 0 15 2 1 1 1 0 8 1 sockpl 752 3203 0 3170 43 32 11 37 0 8 6 mcl64k 65536 9 0 0 2 0 2 2 0 8 0 mcl16k 16384 1 0 0 1 0 1 1 0 8 0 mcl8k 8192 4 0 0 1 0 1 1 0 8 0 mcl4k 4096 123 0 0 16 0 16 16 0 8 0 mcl2k2 2112 1 0 0 1 0 1 1 0 8 0 mcl2k 2048 27 0 0 4 0 4 4 0 8 0 mtagpl 96 10 0 0 1 0 1 1 0 8 0 mbufpl 256 303 0 0 19 0 19 19 0 8 0 bufpl 280 10006 0 3870 439 0 439 439 0 8 0 anonpl 32 13705 0 0 111 0 111 111 0 246 0 amapchunkpl 152 48005 0 47612 43 9 34 43 0 158 17 amappl16 200 5035 0 5004 26 13 13 20 0 8 7 amappl15 192 6 0 6 1 1 0 1 0 8 0 amappl14 184 5 0 5 1 1 0 1 0 8 0 amappl13 176 505 0 504 1 0 1 1 0 8 0 amappl12 168 2138 0 2098 3 1 2 3 0 8 0 amappl11 160 56 0 56 1 1 0 1 0 8 0 amappl10 152 52 0 38 1 0 1 1 0 8 0 amappl9 144 249 0 249 1 1 0 1 0 8 0 amappl8 136 34 0 32 1 0 1 1 0 8 0 amappl7 128 108 0 106 1 0 1 1 0 8 0 amappl6 120 388 0 374 1 0 1 1 0 8 0 amappl5 112 85 0 74 1 0 1 1 0 8 0 amappl4 104 531 0 500 1 0 1 1 0 8 0 amappl3 96 8385 0 8309 4 1 3 3 0 8 0 amappl2 88 1864 0 1789 2 0 2 2 0 8 0 amappl1 80 20350 0 19747 15 0 15 15 0 8 0 amappl 88 13401 0 13262 5 0 5 5 0 92 1 uvmvnodes 80 139 0 0 3 0 3 3 0 8 0 dma4096 4096 1 0 1 1 1 0 1 0 8 0 dma2048 2048 1 0 1 1 1 0 1 0 8 0 dma1024 1024 2 0 1 1 0 1 1 0 8 0 dma256 256 7 0 7 2 2 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 8 0 8 2 2 0 1 0 8 0 dma16 16 19 0 18 1 0 1 1 0 8 0 aobjpl 72 57 0 10 1 0 1 1 0 8 0 uaddrrnd 24 1701 0 1671 1 0 1 1 0 8 0 uaddrbest 32 2 0 0 1 0 1 1 0 8 0 uaddr 24 1701 0 1671 1 0 1 1 0 8 0 vmmpekpl 168 16401 0 16358 3 0 3 3 0 8 0 vmmpepl 168 121629 0 119764 103 5 98 103 0 357 7 vmsppl 488 1700 0 1671 5 0 5 5 0 8 0 rwobjpl 80 34873 0 33783 30 1 29 30 0 8 0 pdppl 4096 3425 0 3353 110 32 78 85 0 8 6 pvpl 32 20079 0 0 162 0 162 162 0 265 0 pmappl 256 1708 0 1674 3 0 3 3 0 8 0 extentpl 40 45 0 27 1 0 1 1 0 8 0 phpool 112 320 0 56 8 0 8 8 0 8 0 ddb{1}> machine ddbcpu 0 Stopped at x86_ipi_db+39: addq $8,%rsp ddb{0}> trace x86_ipi_db(ffffffff83883ff0) at x86_ipi_db+39 x86_ipi_handler() at x86_ipi_handler+217 Xresume_lapic_ipi() at Xresume_lapic_ipi+39 mtx_enter(ffffffff83884e20) at mtx_enter+891 clockintr_dispatch(ffff8000367d1d20) at clockintr_dispatch+1025 lapic_clockintr(0,0) at lapic_clockintr+81 Xresume_lapic_ltimer() at Xresume_lapic_ltimer+42 end of kernel end trace frame: 0x7b5df9865fb0, count: -7 ddb{0}> machine ddbcpu 1 Stopped at db_enter+37: addq $8,%rsp ddb{1}> trace db_enter() at db_enter+37 witness_checkorder(ffffffff8395d808,9,0) at witness_checkorder+4305 mtx_enter(ffffffff8395d7f8) at mtx_enter+149 sleep_setup(ffffffff83884e80,220,ffffffff834376d6) at sleep_setup+237 msleep_nsec(ffffffff83884e80,ffffffff83884e20,220,ffffffff834376d6,ffffffffffffffff) at msleep_nsec+267 dt_ioctl_record_stop(ffff800001594000) at dt_ioctl_record_stop+188 dtclose(41e5f,81,2000,ffff80003bc12fb8) at dtclose+265 spec_close(ffff80003c41cd20) at spec_close+1126 VOP_CLOSE(fffffd806193ddb8,81,fffffd80097fd6e8,ffff80003bc12fb8) at VOP_CLOSE+306 vn_closefile(fffffd806c89ba40,ffff80003bc12fb8) at vn_closefile+299 fdrop(fffffd806c89ba40,ffff80003bc12fb8) at fdrop+289 closef(fffffd806c89ba40,ffff80003bc12fb8) at closef+402 syscall(ffff80003c41cf80) at syscall+3028 Xsyscall() at Xsyscall+296 end of kernel end trace frame: 0x9e287934f70, count: -14