syzbot


panic: lock (rwlock) vcpulock not locked

Status: fixed on 2021/09/06 04:40
Reported-by: syzbot+1dab11e14aa7a159cadf@syzkaller.appspotmail.com
Fix commit: 5f3d69798ad5 vmm(4): fix vcpu locking issues reported by syzbot
First crash: 456d, last: 456d

Sample crash report:
panic: lock (rwlock) vcpulock not locked
Stopped at      db_enter+0x18:  addq    $0x8,%rsp
    TID    PID    UID     PRFLAGS     PFLAGS  CPU  COMMAND
*281555  56206      0           0          0    1  syz-executor9310
  75593  81265      0        0x12        0x8    0  sshd
db_enter() at db_enter+0x18 sys/arch/amd64/amd64/db_interface.c:440
panic(ffffffff82431be5) at panic+0x177 sys/kern/subr_prf.c:202
witness_assert(ffff800021234bb0,4) at witness_assert+0x3ef sys/kern/subr_witness.c:1950
vcpu_reload_vmcs_vmx(ffff800021234800) at vcpu_reload_vmcs_vmx+0x30 sys/arch/amd64/amd64/vmm.c:1768
vcpu_writeregs_vmx(ffff800021234800,b3,1,ffff800000b07410) at vcpu_writeregs_vmx+0x4a sys/arch/amd64/amd64/vmm.c:2096
vmmioctl(a00,82485608,ffff800000b07400,1,ffff80002121efc0) at vmmioctl+0x175
VOP_IOCTL(fffffd806e4f3ad0,82485608,ffff800000b07400,1,fffffd807f7d8780,ffff80002121efc0) at VOP_IOCTL+0x9a sys/kern/vfs_vops.c:295
vn_ioctl(fffffd806e49ca28,82485608,ffff800000b07400,ffff80002121efc0) at vn_ioctl+0xba sys/kern/vfs_vnops.c:531
sys_ioctl(ffff80002121efc0,ffff8000212311d8,ffff800021231220) at sys_ioctl+0x4a2
syscall(ffff8000212312a0) at syscall+0x5a9 mi_syscall sys/sys/syscall_mi.h:102 [inline]
syscall(ffff8000212312a0) at syscall+0x5a9 sys/arch/amd64/amd64/trap.c:587
Xsyscall() at Xsyscall+0x128
end of kernel
end trace frame: 0x7f7fffffac70, count: 4
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{1}> 
ddb{1}> set $lines = 0
ddb{1}> set $maxwidth = 0
ddb{1}> show panic
*cpu1: lock (rwlock) vcpulock not locked
ddb{1}> trace
db_enter() at db_enter+0x18 sys/arch/amd64/amd64/db_interface.c:440
panic(ffffffff82431be5) at panic+0x177 sys/kern/subr_prf.c:202
witness_assert(ffff800021234bb0,4) at witness_assert+0x3ef sys/kern/subr_witness.c:1950
vcpu_reload_vmcs_vmx(ffff800021234800) at vcpu_reload_vmcs_vmx+0x30 sys/arch/amd64/amd64/vmm.c:1768
vcpu_writeregs_vmx(ffff800021234800,b3,1,ffff800000b07410) at vcpu_writeregs_vmx+0x4a sys/arch/amd64/amd64/vmm.c:2096
vmmioctl(a00,82485608,ffff800000b07400,1,ffff80002121efc0) at vmmioctl+0x175
VOP_IOCTL(fffffd806e4f3ad0,82485608,ffff800000b07400,1,fffffd807f7d8780,ffff80002121efc0) at VOP_IOCTL+0x9a sys/kern/vfs_vops.c:295
vn_ioctl(fffffd806e49ca28,82485608,ffff800000b07400,ffff80002121efc0) at vn_ioctl+0xba sys/kern/vfs_vnops.c:531
sys_ioctl(ffff80002121efc0,ffff8000212311d8,ffff800021231220) at sys_ioctl+0x4a2
syscall(ffff8000212312a0) at syscall+0x5a9 mi_syscall sys/sys/syscall_mi.h:102 [inline]
syscall(ffff8000212312a0) at syscall+0x5a9 sys/arch/amd64/amd64/trap.c:587
Xsyscall() at Xsyscall+0x128
end of kernel
end trace frame: 0x7f7fffffac70, count: -11
ddb{1}> show registers
rdi                                0
rsi                              0x1
rbp               0xffff800021230cb0
rbx               0xffff800020d39bff
rdx                             0x8b
rcx                              0x2
rax                             0x29
r8                0xffffffff81a0be34    kprintf+0x144
r9                               0x1
r10               0x29245c6bdc66ef74
r11                0x2b74850c5937833
r12               0xffff800020d39a00
r13                                0
r14                                0
r15                              0x1
rip               0xffffffff81e3e908    db_enter+0x18
cs                               0x8
rflags                         0x246
rsp               0xffff800021230ca0
ss                              0x10
db_enter+0x18:  addq    $0x8,%rsp
ddb{1}> show proc
PROC (syz-executor9310) pid=281555 stat=onproc
    flags process=0 proc=0
    pri=55, usrpri=55, nice=20
    forw=0xffffffffffffffff, list=0xffff80002121ed20,0xffffffff82913618
    process=0xffff80002120a190 user=0xffff80002122c000, vmspace=0xfffffd806f1beb88
    estcpu=10, cpticks=0, pctcpu=0.0
    user=0, sys=0, intr=0
ddb{1}> ps
   PID     TID   PPID    UID  S       FLAGS  WAIT          COMMAND
*56206  281555  64067      0  7           0                syz-executor9310
 64067  199194  54285      0  3        0x82  nanoslp       syz-executor9310
 54285   49588  81265      0  3    0x10008a  sigsusp       ksh
 81265   75593   5606      0  7        0x1a                sshd
 68922  469208      1      0  3    0x100083  ttyin         getty
  5606  413813      1      0  3        0x88  select        sshd
 92223  306765  93454     74  3    0x100092  bpf           pflogd
 93454  407883      1      0  3        0x80  netio         pflogd
 33558  429473  44225     73  3    0x100090  kqread        syslogd
 44225  470534      1      0  3    0x100082  netio         syslogd
 51182  150900      1      0  3    0x100080  kqread        resolvd
 34615  315689  50440     77  3    0x100092  kqread        dhcpleased
  7043  388100  50440     77  3    0x100092  kqread        dhcpleased
 50440  281101      1      0  3        0x80  kqread        dhcpleased
 80480  345808      0      0  3     0x14200  bored         smr
 73601  308887      0      0  3     0x14200  pgzero        zerothread
  1549  342978      0      0  3     0x14200  aiodoned      aiodoned
 16878  413252      0      0  3     0x14200  syncer        update
 75734  138900      0      0  3     0x14200  cleaner       cleaner
 24078   42306      0      0  3     0x14200  reaper        reaper
 28978  467441      0      0  3     0x14200  pgdaemon      pagedaemon
 48926  389136      0      0  3     0x14200  bored         crynlk
 85269  106349      0      0  3     0x14200  bored         crypto
 39118  150192      0      0  3     0x14200  bored         viomb
 80353  184756      0      0  3  0x40014200  acpi0         acpi0
 12246  449722      0      0  3  0x40014200                idle1
 45108  148239      0      0  2     0x14200                softnet
 12088  149797      0      0  3     0x14200  bored         systqmp
 63724  509842      0      0  3     0x14200  bored         systq
 74356  293773      0      0  3  0x40014200  bored         softclock
 46199  290697      0      0  3  0x40014200                idle0
     1   41103      0      0  3        0x82  wait          init
     0       0     -1      0  3     0x10200  scheduler     swapper
ddb{1}> show all locks
Process 81265 (sshd) thread 0xffff80002121e2a0 (75593)
exclusive rwlock netlock r = 0 (0xffffffff827cea90)
#0  witness_lock+0x4b0 stacktrace_save sys/sys/stacktrace.h:36 [inline]
#0  witness_lock+0x4b0 sys/kern/subr_witness.c:1182
#1  solock+0x86 sys/kern/uipc_socket2.c:295
#2  sosend+0x22a sys/kern/uipc_socket.c:506
#3  dofilewritev+0x1a3 sys/kern/sys_generic.c:365
#4  sys_write+0x83 sys/kern/sys_generic.c:285
#5  syscall+0x5a9 mi_syscall sys/sys/syscall_mi.h:102 [inline]
#5  syscall+0x5a9 sys/arch/amd64/amd64/trap.c:587
#6  Xsyscall+0x128
ddb{1}> 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      1K       4K  78643K      1482        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    84     20K      20K  78643K      1736        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      1966        0
         kqueue     9     12K      12K  78643K         9        0
      SYN cache     2     16K      16K  78643K         2        0
ddb{1}> 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        2     1     0     1     1     0     8    0
pfstkey    112        9    0        2     1     0     1     1     0     8    0
pfstate    320        9    0        2     1     0     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       97    0        0     7     0     7     7     0     8    0
art_table   32       98    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     1413    0       23    87     0    87    87     0     8    0
ffsino     272     1413    0       23    93     0    93    93     0     8    0
nchpl      144     1588    0       40    58     0    58    58     0     8    0
uvmvnodes   72     1423    0        0    26     0    26    26     0     8    0
vnodes     224     1423    0        0    84     0    84    84     0     8    0
namei      1024    4149    0     4149     2     1     1     1     0     8    1
percpumem   16       32    0        0     1     0     1     1     0     8    0
vcpupl     2048       1    0        0     1     0     1     1     0     8    0
vmpool     560        1    0        0     1     0     1     1     0     8    0
scxspl     216     3685    0     3685    10     9     1     8     0     8    1
plimitpl   152       16    0        9     1     0     1     1     0     8    0
sigapl     424      257    0      225     5     0     5     5     0     8    0
knotepl    112       23    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      241    0      225     3     0     3     3     0     8    0
filepl     152     1087    0     1028     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      225    0      225     2     1     1     1     0     8    1
processpl  1072     257    0      225     3     0     3     3     0     8    0
procpl     672      257    0      225     4     0     4     4     0     8    0
sockpl     480       84    0       60     5     1     4     4     0     8    0
mcl8k      8192       3    0        0     1     0     1     1     0     8    0
mcl4k      4096       2    0        0     1     0     1     1     0     8    0
mcl2k      2048      82    0        0    11     1    10    11     0     8    0
mtagpl      96        3    0        0     1     0     1     1     0     8    0
mbufpl     256      129    0        0     9     0     9     9     0     8    0
bufpl      280     2013    0       93   138     0   138   138     0     8    0
anonpl      24    32796    0    30485    18     3    15    17     0   186    1
amapchunkpl 152    3023    0     2879     8     1     7     8     0   158    0
amappl16   200       97    0       92     1     0     1     1     0     8    0
amappl15   192        1    0        0     1     0     1     1     0     8    0
amappl13   176       20    0       18     1     0     1     1     0     8    0
amappl12   168        1    0        1     1     1     0     1     0     8    0
amappl11   160       42    0       28     1     0     1     1     0     8    0
amappl10   152       23    0       19     1     0     1     1     0     8    0
amappl9    144       21    0       18     1     0     1     1     0     8    0
amappl8    136      272    0      272     2     1     1     1     0     8    1
amappl7    128       52    0       45     1     0     1     1     0     8    0
amappl6    120       87    0       82     1     0     1     1     0     8    0
amappl5    112      577    0      560     1     0     1     1     0     8    0
amappl4    104      525    0      506     1     0     1     1     0     8    0
amappl3     96       49    0       46     1     0     1     1     0     8    0
amappl2     88      403    0      357     3     1     2     2     0     8    0
amappl1     80     7573    0     7191    11     2     9     9     0     8    0
amappl      88     1491    0     1425     2     0     2     2     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      242    0      225     1     0     1     1     0     8    0
uaddrbest   32        2    0        0     1     0     1     1     0     8    0
uaddr       24      242    0      225     1     0     1     1     0     8    0
vmmpekpl   168     6006    0     5988     1     0     1     1     0     8    0
vmmpepl    168    22906    0    22038    44     3    41    41     0   357    1
vmsppl     368      241    0      225     2     0     2     2     0     8    0
rwobjpl     56     7216    0     6660    11     2     9     9     0     8    1
pdppl      4096     492    0      451    64    22    42    48     0     8    1
pvpl        32   112040    0   107824    42     4    38    38     0   265    1
pmappl     224      241    0      225     2     0     2     2     0     8    0
extentpl    40       58    0       40     1     0     1     1     0     8    0
phpool     112      290    0       28     8     0     8     8     0     8    0
ddb{1}> machine ddbcpu 0
Stopped at      x86_ipi_db+0x1a:        addq    $0x8,%rsp
x86_ipi_db(ffffffff82809ff0) 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
__sanitizer_cov_trace_pc() at __sanitizer_cov_trace_pc+0x5f sys/dev/kcov.c:149
__mp_lock(ffffffff82838a18) at __mp_lock+0xa1 read_rflags machine/cpufunc.h:195 [inline]
__mp_lock(ffffffff82838a18) at __mp_lock+0xa1 intr_disable machine/cpufunc.h:216 [inline]
__mp_lock(ffffffff82838a18) at __mp_lock+0xa1 sys/kern/kern_lock.c:142
__mp_acquire_count(ffffffff82838a18,1) at __mp_acquire_count+0x4c sys/kern/kern_lock.c:227
tsleep(ffffffff8292d680,118,ffffffff824f0138,0) at tsleep+0x172
dopselect(ffff80002121e2a0,a,9812625fea0,980d6f0da20,0,0) at dopselect+0x712 sys/kern/sys_generic.c:657
sys_pselect(ffff80002121e2a0,ffff800021211a50,ffff800021211aa0) at sys_pselect+0x13a sys/kern/sys_generic.c:579
syscall(ffff800021211b20) at syscall+0x5a9 mi_syscall sys/sys/syscall_mi.h:102 [inline]
syscall(ffff800021211b20) at syscall+0x5a9 sys/arch/amd64/amd64/trap.c:587
Xsyscall() at Xsyscall+0x128
end of kernel
end trace frame: 0x7f7ffffcbef0, count: 4
ddb{0}> trace
x86_ipi_db(ffffffff82809ff0) 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
__sanitizer_cov_trace_pc() at __sanitizer_cov_trace_pc+0x5f sys/dev/kcov.c:149
__mp_lock(ffffffff82838a18) at __mp_lock+0xa1 read_rflags machine/cpufunc.h:195 [inline]
__mp_lock(ffffffff82838a18) at __mp_lock+0xa1 intr_disable machine/cpufunc.h:216 [inline]
__mp_lock(ffffffff82838a18) at __mp_lock+0xa1 sys/kern/kern_lock.c:142
__mp_acquire_count(ffffffff82838a18,1) at __mp_acquire_count+0x4c sys/kern/kern_lock.c:227
tsleep(ffffffff8292d680,118,ffffffff824f0138,0) at tsleep+0x172
dopselect(ffff80002121e2a0,a,9812625fea0,980d6f0da20,0,0) at dopselect+0x712 sys/kern/sys_generic.c:657
sys_pselect(ffff80002121e2a0,ffff800021211a50,ffff800021211aa0) at sys_pselect+0x13a sys/kern/sys_generic.c:579
syscall(ffff800021211b20) at syscall+0x5a9 mi_syscall sys/sys/syscall_mi.h:102 [inline]
syscall(ffff800021211b20) at syscall+0x5a9 sys/arch/amd64/amd64/trap.c:587
Xsyscall() at Xsyscall+0x128
end of kernel
end trace frame: 0x7f7ffffcbef0, count: -11
ddb{0}> machine ddbcpu 1
Stopped at      db_enter+0x18:  addq    $0x8,%rsp
db_enter() at db_enter+0x18 sys/arch/amd64/amd64/db_interface.c:440
panic(ffffffff82431be5) at panic+0x177 sys/kern/subr_prf.c:202
witness_assert(ffff800021234bb0,4) at witness_assert+0x3ef sys/kern/subr_witness.c:1950
vcpu_reload_vmcs_vmx(ffff800021234800) at vcpu_reload_vmcs_vmx+0x30 sys/arch/amd64/amd64/vmm.c:1768
vcpu_writeregs_vmx(ffff800021234800,b3,1,ffff800000b07410) at vcpu_writeregs_vmx+0x4a sys/arch/amd64/amd64/vmm.c:2096
vmmioctl(a00,82485608,ffff800000b07400,1,ffff80002121efc0) at vmmioctl+0x175
VOP_IOCTL(fffffd806e4f3ad0,82485608,ffff800000b07400,1,fffffd807f7d8780,ffff80002121efc0) at VOP_IOCTL+0x9a sys/kern/vfs_vops.c:295
vn_ioctl(fffffd806e49ca28,82485608,ffff800000b07400,ffff80002121efc0) at vn_ioctl+0xba sys/kern/vfs_vnops.c:531
sys_ioctl(ffff80002121efc0,ffff8000212311d8,ffff800021231220) at sys_ioctl+0x4a2
syscall(ffff8000212312a0) at syscall+0x5a9 mi_syscall sys/sys/syscall_mi.h:102 [inline]
syscall(ffff8000212312a0) at syscall+0x5a9 sys/arch/amd64/amd64/trap.c:587
Xsyscall() at Xsyscall+0x128
end of kernel
end trace frame: 0x7f7fffffac70, count: 4
ddb{1}> trace
db_enter() at db_enter+0x18 sys/arch/amd64/amd64/db_interface.c:440
panic(ffffffff82431be5) at panic+0x177 sys/kern/subr_prf.c:202
witness_assert(ffff800021234bb0,4) at witness_assert+0x3ef sys/kern/subr_witness.c:1950
vcpu_reload_vmcs_vmx(ffff800021234800) at vcpu_reload_vmcs_vmx+0x30 sys/arch/amd64/amd64/vmm.c:1768
vcpu_writeregs_vmx(ffff800021234800,b3,1,ffff800000b07410) at vcpu_writeregs_vmx+0x4a sys/arch/amd64/amd64/vmm.c:2096
vmmioctl(a00,82485608,ffff800000b07400,1,ffff80002121efc0) at vmmioctl+0x175
VOP_IOCTL(fffffd806e4f3ad0,82485608,ffff800000b07400,1,fffffd807f7d8780,ffff80002121efc0) at VOP_IOCTL+0x9a sys/kern/vfs_vops.c:295
vn_ioctl(fffffd806e49ca28,82485608,ffff800000b07400,ffff80002121efc0) at vn_ioctl+0xba sys/kern/vfs_vnops.c:531
sys_ioctl(ffff80002121efc0,ffff8000212311d8,ffff800021231220) at sys_ioctl+0x4a2
syscall(ffff8000212312a0) at syscall+0x5a9 mi_syscall sys/sys/syscall_mi.h:102 [inline]
syscall(ffff8000212312a0) at syscall+0x5a9 sys/arch/amd64/amd64/trap.c:587
Xsyscall() at Xsyscall+0x128
end of kernel
end trace frame: 0x7f7fffffac70, count: -11
ddb{1}> 

Crashes (1):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci-openbsd-multicore 2021/09/01 04:47 openbsd 444296aeff58 7eb7e152 .config log report syz C panic: lock (rwlock) vcpulock not locked
* Struck through repros no longer work on HEAD.