syzbot


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

Status: fixed on 2021/09/07 20:47
Reported-by: syzbot+062fd9ad0ebf2c6ec2a1@syzkaller.appspotmail.com
Fix commit: 8e114673a836 vmm(4): grab kernel lock before vmspace init
First crash: 455d, last: 452d
similar bugs (5):
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
openbsd panic: acquiring blockable sleep lock with spinlock or critical section held (kernel_lock) &kernel_lock (5) C 104 254d never 3/3 fixed on 2022/03/22 22:28
openbsd panic: acquiring blockable sleep lock with spinlock or critical section held (kernel_lock) &kernel_lock (4) C 249 254d 255d 3/3 fixed on 2022/03/22 10:24
openbsd panic: acquiring blockable sleep lock with spinlock or critical section held (kernel_lock) &kernel_lock 33 1192d 1196d 3/3 fixed on 2019/08/27 19:45
openbsd panic: acquiring blockable sleep lock with spinlock or critical section held (kernel_lock) &kernel_lock (2) C 152 456d 1177d 3/3 fixed on 2021/09/01 16:54
openbsd panic: acquiring blockable sleep lock with spinlock or critical section held (kernel_lock) &kernel_lock (6) C 80 253d 253d 3/3 fixed on 2022/03/24 08:53

Sample crash report:
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

Crashes (2):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci-openbsd-multicore 2021/09/02 07:50 openbsd e42df31d2641 7eb7e152 .config log report syz C panic: acquiring blockable sleep lock with spinlock or critical section held (kernel_lock) &kernel_lock
ci-openbsd-multicore 2021/09/05 15:25 openbsd 94151407c9d6 d236a457 .config log report panic: acquiring blockable sleep lock with spinlock or critical section held (kernel_lock) &kernel_lock
* Struck through repros no longer work on HEAD.