panic: acquiring blockable sleep lock with spinlock or critical section held (kernel_lock) &kernel_lock (3)

4 views
Skip to first unread message

syzbot

unread,
Sep 2, 2021, 3:50:22 AM9/2/21
to syzkaller-o...@googlegroups.com
Hello,

syzbot found the following issue on:

HEAD commit: e42df31d2641 Update project tag line, shorten some err() c..
git tree: openbsd
console output: https://syzkaller.appspot.com/x/log.txt?x=101f084d300000
kernel config: https://syzkaller.appspot.com/x/.config?x=bf87b6915a88cd0d
dashboard link: https://syzkaller.appspot.com/bug?extid=062fd9ad0ebf2c6ec2a1
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=1245f513300000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=15796549300000

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+062fd9...@syzkaller.appspotmail.com

login: panic: acquiring blockable sleep lock with spinlock or critical section held (kernel_lock) &kernel_lock
Stopped at db_enter+0x18: addq $0x8,%rsp
TID PID UID PRFLAGS PFLAGS CPU COMMAND
*315860 25353 0 0 0 0 syz-executor9951
db_enter() at db_enter+0x18 sys/arch/amd64/amd64/db_interface.c:440
panic(ffffffff82466219) at panic+0x177 sys/kern/subr_prf.c:202
witness_checkorder(ffffffff8283ff70,9,0) at witness_checkorder+0x11eb sys/kern/subr_witness.c:833
__mp_lock(ffffffff8283fd68) at __mp_lock+0xa1 read_rflags machine/cpufunc.h:195 [inline]
__mp_lock(ffffffff8283fd68) at __mp_lock+0xa1 intr_disable machine/cpufunc.h:216 [inline]
__mp_lock(ffffffff8283fd68) at __mp_lock+0xa1 sys/kern/kern_lock.c:142
intr_handler(ffff80002123a9f0,ffff800000255c80) at intr_handler+0x5e sys/arch/amd64/amd64/intr.c:532
Xintr_ioapic_edge19_untramp() at Xintr_ioapic_edge19_untramp+0x18f
pool_do_get(ffffffff8283e878,9,ffff80002123ab98) at pool_do_get+0x93 sys/kern/subr_pool.c:722
pool_get(ffffffff8283e878,9) at pool_get+0xeb sys/kern/subr_pool.c:584
vm_create(ffff800000b29000,ffff800021192fc8) at vm_create+0xad sys/arch/amd64/amd64/vmm.c:1497
vmmioctl(a00,c5005601,ffff800000b29000,1,ffff800021192fc8) at vmmioctl+0x1f2
VOP_IOCTL(fffffd806e062670,c5005601,ffff800000b29000,1,fffffd807f7d8900,ffff800021192fc8) at VOP_IOCTL+0x9a sys/kern/vfs_vops.c:295
vn_ioctl(fffffd806e4b94d0,c5005601,ffff800000b29000,ffff800021192fc8) at vn_ioctl+0xba sys/kern/vfs_vnops.c:531
sys_ioctl(ffff800021192fc8,ffff80002123af88,ffff80002123afd0) at sys_ioctl+0x4a2
syscall(ffff80002123b050) at syscall+0x5a9 mi_syscall sys/sys/syscall_mi.h:102 [inline]
syscall(ffff80002123b050) at syscall+0x5a9 sys/arch/amd64/amd64/trap.c:587
end trace frame: 0xffff80002123b0d0, count: 0
https://www.openbsd.org/ddb.html describes the minimum info required in bug
reports. Insufficient info makes it difficult to find and fix bugs.
ddb{0}>
ddb{0}> set $lines = 0
ddb{0}> set $maxwidth = 0
ddb{0}> show panic
*cpu0: acquiring blockable sleep lock with spinlock or critical section held (kernel_lock) &kernel_lock
ddb{0}> trace
db_enter() at db_enter+0x18 sys/arch/amd64/amd64/db_interface.c:440
panic(ffffffff82466219) at panic+0x177 sys/kern/subr_prf.c:202
witness_checkorder(ffffffff8283ff70,9,0) at witness_checkorder+0x11eb sys/kern/subr_witness.c:833
__mp_lock(ffffffff8283fd68) at __mp_lock+0xa1 read_rflags machine/cpufunc.h:195 [inline]
__mp_lock(ffffffff8283fd68) at __mp_lock+0xa1 intr_disable machine/cpufunc.h:216 [inline]
__mp_lock(ffffffff8283fd68) at __mp_lock+0xa1 sys/kern/kern_lock.c:142
intr_handler(ffff80002123a9f0,ffff800000255c80) at intr_handler+0x5e sys/arch/amd64/amd64/intr.c:532
Xintr_ioapic_edge19_untramp() at Xintr_ioapic_edge19_untramp+0x18f
pool_do_get(ffffffff8283e878,9,ffff80002123ab98) at pool_do_get+0x93 sys/kern/subr_pool.c:722
pool_get(ffffffff8283e878,9) at pool_get+0xeb sys/kern/subr_pool.c:584
vm_create(ffff800000b29000,ffff800021192fc8) at vm_create+0xad sys/arch/amd64/amd64/vmm.c:1497
vmmioctl(a00,c5005601,ffff800000b29000,1,ffff800021192fc8) at vmmioctl+0x1f2
VOP_IOCTL(fffffd806e062670,c5005601,ffff800000b29000,1,fffffd807f7d8900,ffff800021192fc8) at VOP_IOCTL+0x9a sys/kern/vfs_vops.c:295
vn_ioctl(fffffd806e4b94d0,c5005601,ffff800000b29000,ffff800021192fc8) at vn_ioctl+0xba sys/kern/vfs_vnops.c:531
sys_ioctl(ffff800021192fc8,ffff80002123af88,ffff80002123afd0) at sys_ioctl+0x4a2
syscall(ffff80002123b050) at syscall+0x5a9 mi_syscall sys/sys/syscall_mi.h:102 [inline]
syscall(ffff80002123b050) at syscall+0x5a9 sys/arch/amd64/amd64/trap.c:587
Xsyscall() at Xsyscall+0x128
end of kernel
end trace frame: 0x7f7ffffdac50, count: -15
ddb{0}> show registers
rdi 0
rsi 0x1
rbp 0xffff80002123a7e0
rbx 0xffffffff82828bff cpu_info_full_primary+0x2bff
rdx 0x8b
rcx 0x2
rax 0x68
r8 0xffffffff820a9ca4 kprintf+0x144
r9 0x1
r10 0x6046129a8a9802d2
r11 0xcec86b18299705d2
r12 0xffffffff82828a00 cpu_info_full_primary+0x2a00
r13 0
r14 0
r15 0x1
rip 0xffffffff8230ccb8 db_enter+0x18
cs 0x8
rflags 0x246
rsp 0xffff80002123a7d0
ss 0x10
db_enter+0x18: addq $0x8,%rsp
ddb{0}> show proc
PROC (syz-executor9951) pid=315860 stat=onproc
flags process=0 proc=0
pri=50, usrpri=86, nice=20
forw=0xffffffffffffffff, list=0xffff8000ffff7a50,0xffffffff82960ef0
process=0xffff80002120ae20 user=0xffff800021236000, vmspace=0xfffffd806c4dce70
estcpu=36, cpticks=1, pctcpu=0.0
user=0, sys=0, intr=1
ddb{0}> ps
PID TID PPID UID S FLAGS WAIT COMMAND
*25353 315860 13704 0 7 0 syz-executor9951
13704 415395 21688 0 3 0x80 nanoslp syz-executor9951
87722 518561 21688 0 3 0x80 nanoslp syz-executor9951
21688 4384 22616 0 3 0x82 nanoslp syz-executor9951
22616 357576 94494 0 3 0x10008a sigsusp ksh
94494 199091 99446 0 3 0x9a select sshd
99436 358155 1 0 3 0x100083 ttyin getty
99446 152571 1 0 3 0x88 select sshd
87724 319674 37838 74 3 0x100092 bpf pflogd
37838 338290 1 0 3 0x80 netio pflogd
75008 102996 14572 73 3 0x100090 kqread syslogd
14572 57829 1 0 3 0x100082 netio syslogd
17764 57577 1 0 3 0x100080 kqread resolvd
8338 394680 35919 77 3 0x100092 kqread dhcpleased
97799 42735 35919 77 3 0x100092 kqread dhcpleased
35919 120687 1 0 3 0x80 kqread dhcpleased
66533 3072 0 0 3 0x14200 bored smr
73571 178286 0 0 3 0x14200 pgzero zerothread
37559 441759 0 0 3 0x14200 aiodoned aiodoned
57064 388576 0 0 3 0x14200 syncer update
68303 461272 0 0 3 0x14200 cleaner cleaner
11159 20175 0 0 3 0x14200 reaper reaper
12981 84404 0 0 3 0x14200 pgdaemon pagedaemon
60936 259850 0 0 3 0x14200 bored crynlk
65987 295234 0 0 3 0x14200 bored crypto
13763 26779 0 0 3 0x14200 bored viomb
37265 498455 0 0 3 0x40014200 acpi0 acpi0
81446 300728 0 0 7 0x40014200 idle1
10370 90987 0 0 3 0x14200 bored softnet
52109 298933 0 0 3 0x14200 bored systqmp
3882 301460 0 0 3 0x14200 bored systq
3489 433229 0 0 3 0x40014200 bored softclock
37476 447208 0 0 3 0x40014200 idle0
1 20801 0 0 3 0x82 wait init
0 0 -1 0 3 0x10200 scheduler swapper
ddb{0}> show all locks
CPU 0:
exclusive mutex vmpool r = 0 (0xffffffff8283e888)
#0 witness_lock+0x4b0 stacktrace_save sys/sys/stacktrace.h:36 [inline]
#0 witness_lock+0x4b0 sys/kern/subr_witness.c:1182
#1 mtx_enter_try+0x100
#2 mtx_enter+0x4b sys/kern/kern_lock.c:266
#3 pool_get+0xbf sys/kern/subr_pool.c:581
#4 vm_create+0xad sys/arch/amd64/amd64/vmm.c:1497
#5 vmmioctl+0x1f2
#6 VOP_IOCTL+0x9a sys/kern/vfs_vops.c:295
#7 vn_ioctl+0xba sys/kern/vfs_vnops.c:531
#8 sys_ioctl+0x4a2
#9 syscall+0x5a9 mi_syscall sys/sys/syscall_mi.h:102 [inline]
#9 syscall+0x5a9 sys/arch/amd64/amd64/trap.c:587
#10 Xsyscall+0x128
ddb{0}> show malloc
Type InUse MemUse HighUse Limit Requests Type Lim
devbuf 10111 6416K 6417K 78643K 11201 0
pcb 13 8K 8K 78643K 13 0
rtable 62 2K 2K 78643K 112 0
ifaddr 29 8K 8K 78643K 30 0
counters 40 33K 33K 78643K 40 0
ioctlops 1 2K 4K 78643K 1717 0
mount 1 1K 1K 78643K 1 0
log 0 0K 0K 78643K 6 0
vnodes 1183 74K 75K 78643K 1188 0
UFS quota 1 32K 32K 78643K 1 0
UFS mount 5 36K 36K 78643K 5 0
shm 2 1K 1K 78643K 2 0
VM map 2 1K 1K 78643K 2 0
sem 2 0K 0K 78643K 2 0
dirhash 12 2K 2K 78643K 12 0
ACPI 1697 195K 286K 78643K 12598 0
file desc 1 0K 0K 78643K 1 0
proc 67 87K 87K 78643K 278 0
NFS srvsock 1 0K 0K 78643K 1 0
NFS daemon 1 16K 16K 78643K 1 0
in_multi 11 0K 0K 78643K 11 0
ether_multi 1 0K 0K 78643K 1 0
ISOFS mount 1 32K 32K 78643K 1 0
MSDOSFS mount 1 16K 16K 78643K 1 0
ttys 19 95K 95K 78643K 19 0
exec 0 0K 2K 78643K 348 0
pagedep 1 8K 8K 78643K 1 0
inodedep 1 32K 32K 78643K 1 0
newblk 1 0K 0K 78643K 1 0
VM swap 7 26K 26K 78643K 7 0
UVM amap 567 3855K 3855K 78643K 2937 0
UVM aobj 3 2K 2K 78643K 3 0
memdesc 1 4K 4K 78643K 1 0
crypto data 1 1K 1K 78643K 1 0
NDP 4 0K 0K 78643K 4 0
temp 23 4193K 4257K 78643K 2435 0
kqueue 9 12K 12K 78643K 9 0
SYN cache 2 16K 16K 78643K 2 0
ddb{0}> show all pools
Name Size Requests Fail Releases Pgreq Pgrel Npage Hiwat Minpg Maxpg Idle
plcache 128 22 0 0 1 0 1 1 0 8 0
rtpcb 120 17 0 14 1 0 1 1 0 8 0
rtentry 112 23 0 1 1 0 1 1 0 8 0
unpcb 120 35 0 20 1 0 1 1 0 8 0
syncache 296 5 0 5 2 1 1 1 0 8 1
tcpcb 736 8 0 5 1 0 1 1 0 8 0
arp 120 2 0 0 1 0 1 1 0 8 0
inpcb 304 32 0 26 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
pfstitem 24 9 0 7 2 1 1 1 0 8 0
pfstkey 112 9 0 7 2 1 1 1 0 8 0
pfstate 320 9 0 7 2 1 1 1 0 8 0
pfrule 1360 21 0 16 2 1 1 2 0 8 0
art_heap8 4096 1 0 0 1 0 1 1 0 8 0
art_heap4 256 96 0 0 6 0 6 6 0 8 0
art_table 32 97 0 0 1 0 1 1 0 8 0
art_node 16 22 0 2 1 0 1 1 0 8 0
dirhash 1024 17 0 0 3 0 3 3 0 8 0
dino2pl 256 1653 0 259 88 0 88 88 0 8 0
ffsino 272 1653 0 259 93 0 93 93 0 8 0
nchpl 144 2066 0 514 58 0 58 58 0 8 0
uvmvnodes 72 1663 0 0 31 0 31 31 0 8 0
vnodes 224 1663 0 0 98 0 98 98 0 8 0
namei 1024 5338 0 5338 2 1 1 1 0 8 1
percpumem 16 32 0 0 1 0 1 1 0 8 0
vcpupl 2048 237 0 0 30 0 30 30 0 8 0
vmpool 560 237 0 0 17 0 17 17 0 8 0
scxspl 216 5144 0 5144 14 13 1 8 0 8 1
plimitpl 152 16 0 9 1 0 1 1 0 8 0
sigapl 424 495 0 461 4 0 4 4 0 8 0
knotepl 112 25 0 0 1 0 1 1 0 8 0
kqueuepl 216 5 0 0 1 0 1 1 0 8 0
pipepl 336 69 0 66 2 1 1 1 0 8 0
fdescpl 496 479 0 461 3 0 3 3 0 8 0
filepl 152 1558 0 1499 3 0 3 3 0 8 0
lockfpl 104 6 0 4 1 0 1 1 0 8 0
lockfspl 48 4 0 2 1 0 1 1 0 8 0
sessionpl 144 18 0 9 1 0 1 1 0 8 0
pgrppl 48 18 0 9 1 0 1 1 0 8 0
ucredpl 96 69 0 57 1 0 1 1 0 8 0
zombiepl 144 461 0 460 2 1 1 1 0 8 0
processpl 1072 495 0 460 3 0 3 3 0 8 0
procpl 672 495 0 460 3 0 3 3 0 8 0
sockpl 480 84 0 60 5 1 4 4 0 8 0
mcl8k 8192 5 0 0 1 0 1 1 0 8 0
mcl4k 4096 3 0 0 1 0 1 1 0 8 0
mcl2k 2048 82 0 0 10 0 10 10 0 8 0
mtagpl 96 3 0 0 1 0 1 1 0 8 0
mbufpl 256 142 0 0 9 0 9 9 0 8 0
bufpl 280 2256 0 93 155 0 155 155 0 8 0
anonpl 24 37569 0 34796 20 3 17 17 0 186 0
amapchunkpl 152 4735 0 4567 9 2 7 8 0 158 0
amappl16 200 334 0 91 13 0 13 13 0 8 0
amappl15 192 2 0 1 1 0 1 1 0 8 0
amappl14 184 1 0 1 1 1 0 1 0 8 0
amappl13 176 18 0 17 2 1 1 1 0 8 0
amappl12 168 5 0 5 1 1 0 1 0 8 0
amappl11 160 46 0 31 1 0 1 1 0 8 0
amappl10 152 29 0 25 1 0 1 1 0 8 0
amappl9 144 213 0 211 1 0 1 1 0 8 0
amappl8 136 274 0 274 2 1 1 1 0 8 1
amappl7 128 52 0 45 1 0 1 1 0 8 0
amappl6 120 90 0 82 1 0 1 1 0 8 0
amappl5 112 196 0 180 1 0 1 1 0 8 0
amappl4 104 764 0 742 1 0 1 1 0 8 0
amappl3 96 47 0 44 1 0 1 1 0 8 0
amappl2 88 400 0 355 3 1 2 2 0 8 1
amappl1 80 10124 0 9725 11 2 9 9 0 8 0
amappl 88 2451 0 2139 7 0 7 7 0 92 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 64 2 0 0 1 0 1 1 0 8 0
uaddrrnd 24 716 0 461 2 0 2 2 0 8 0
uaddrbest 32 2 0 0 1 0 1 1 0 8 0
uaddr 24 716 0 461 2 0 2 2 0 8 0
vmmpekpl 168 6534 0 6517 1 0 1 1 0 8 0
vmmpepl 168 31264 0 29853 67 5 62 62 0 357 0
vmsppl 368 715 0 461 24 0 24 24 0 8 0
rwobjpl 56 8130 0 7087 17 2 15 15 0 8 0
pdppl 4096 1440 0 1159 300 18 282 282 0 8 1
pvpl 32 136647 0 132069 43 5 38 38 0 265 1
pmappl 224 715 0 461 15 0 15 15 0 8 0
extentpl 40 58 0 40 1 0 1 1 0 8 0
phpool 112 576 0 23 16 0 16 16 0 8 0
ddb{0}> machine ddbcpu 0
Invalid cpu 0
ddb{0}> trace
db_enter() at db_enter+0x18 sys/arch/amd64/amd64/db_interface.c:440
panic(ffffffff82466219) at panic+0x177 sys/kern/subr_prf.c:202
witness_checkorder(ffffffff8283ff70,9,0) at witness_checkorder+0x11eb sys/kern/subr_witness.c:833
__mp_lock(ffffffff8283fd68) at __mp_lock+0xa1 read_rflags machine/cpufunc.h:195 [inline]
__mp_lock(ffffffff8283fd68) at __mp_lock+0xa1 intr_disable machine/cpufunc.h:216 [inline]
__mp_lock(ffffffff8283fd68) at __mp_lock+0xa1 sys/kern/kern_lock.c:142
intr_handler(ffff80002123a9f0,ffff800000255c80) at intr_handler+0x5e sys/arch/amd64/amd64/intr.c:532
Xintr_ioapic_edge19_untramp() at Xintr_ioapic_edge19_untramp+0x18f
pool_do_get(ffffffff8283e878,9,ffff80002123ab98) at pool_do_get+0x93 sys/kern/subr_pool.c:722
pool_get(ffffffff8283e878,9) at pool_get+0xeb sys/kern/subr_pool.c:584
vm_create(ffff800000b29000,ffff800021192fc8) at vm_create+0xad sys/arch/amd64/amd64/vmm.c:1497
vmmioctl(a00,c5005601,ffff800000b29000,1,ffff800021192fc8) at vmmioctl+0x1f2
VOP_IOCTL(fffffd806e062670,c5005601,ffff800000b29000,1,fffffd807f7d8900,ffff800021192fc8) at VOP_IOCTL+0x9a sys/kern/vfs_vops.c:295
vn_ioctl(fffffd806e4b94d0,c5005601,ffff800000b29000,ffff800021192fc8) at vn_ioctl+0xba sys/kern/vfs_vnops.c:531
sys_ioctl(ffff800021192fc8,ffff80002123af88,ffff80002123afd0) at sys_ioctl+0x4a2
syscall(ffff80002123b050) at syscall+0x5a9 mi_syscall sys/sys/syscall_mi.h:102 [inline]
syscall(ffff80002123b050) at syscall+0x5a9 sys/arch/amd64/amd64/trap.c:587
Xsyscall() at Xsyscall+0x128
end of kernel
end trace frame: 0x7f7ffffdac50, count: -15
ddb{0}> machine ddbcpu 1
Stopped at x86_ipi_db+0x1a: addq $0x8,%rsp
x86_ipi_db(ffff800020d38ff0) at x86_ipi_db+0x1a sys/arch/amd64/amd64/db_interface.c:393
x86_ipi_handler() at x86_ipi_handler+0xb7 sys/arch/amd64/amd64/ipi.c:106
Xresume_lapic_ipi() at Xresume_lapic_ipi+0x23
acpicpu_idle() at acpicpu_idle+0x2eb sys/dev/acpi/acpicpu.c:1206
sched_idle(ffff800020d38ff0) at sched_idle+0x417 sys/kern/kern_sched.c:178
end trace frame: 0x0, count: 10
ddb{1}> trace
x86_ipi_db(ffff800020d38ff0) at x86_ipi_db+0x1a sys/arch/amd64/amd64/db_interface.c:393
x86_ipi_handler() at x86_ipi_handler+0xb7 sys/arch/amd64/amd64/ipi.c:106
Xresume_lapic_ipi() at Xresume_lapic_ipi+0x23
acpicpu_idle() at acpicpu_idle+0x2eb sys/dev/acpi/acpicpu.c:1206
sched_idle(ffff800020d38ff0) at sched_idle+0x417 sys/kern/kern_sched.c:178
end trace frame: 0x0, count: -5


---
This report is generated by a bot. It may contain errors.
See https://goo.gl/tpsmEJ for more information about syzbot.
syzbot engineers can be reached at syzk...@googlegroups.com.

syzbot will keep track of this issue. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.
syzbot can test patches for this issue, for details see:
https://goo.gl/tpsmEJ#testing-patches

Anton Lindqvist

unread,
Sep 7, 2021, 1:04:10 PM9/7/21
to syzbot, syzkaller-o...@googlegroups.com
#syz fix: vmm(4): grab kernel lock before vmspace init
Reply all
Reply to author
Forward
0 new messages