syzbot


witness: exclusive lock of (rwlock) vmmaplk while share locked

Status: fixed on 2022/03/15 07:00
Reported-by: syzbot+3db4f891b8f949dc6753@syzkaller.appspotmail.com
Fix commit: 447db83cf4f0 Revert holding a read lock on the map while copying out data during sysctl(2).
First crash: 985d, last: 985d

Sample crash report:
login: witness: exclusive lock of (rwlock) vmmaplk while share locked
panic: share->excl
Stopped at      db_enter+0x18:  addq    $0x8,%rsp
    TID    PID    UID     PRFLAGS     PFLAGS  CPU  COMMAND
*113695  65708      0         0x2          0    0K syz-executor3957314175
 169270  17344      0        0x12          0    1  sshd
db_enter() at db_enter+0x18 sys/arch/amd64/amd64/db_interface.c:440
panic(ffffffff8257690f) at panic+0x177 sys/kern/subr_prf.c:202
witness_checkorder(fffffd800872ea28,9,0) at witness_checkorder+0x11bd witness_debugger sys/kern/subr_witness.c:2505 [inline]
witness_checkorder(fffffd800872ea28,9,0) at witness_checkorder+0x11bd sys/kern/subr_witness.c:772
rw_enter(fffffd800872ea18,21) at rw_enter+0xd1 sys/kern/kern_rwlock.c:250
vm_map_lock_ln(fffffd800872ea10,0,1000) at vm_map_lock_ln+0xda sys/uvm/uvm_map.c:5466
uvm_map_extract(fffffd800872ea10,7f7ffffd1000,1000,ffff8000211c1a30,0) at uvm_map_extract+0x173 sys/uvm/uvm_map.c:4530
uvm_io(fffffd800872ea10,ffff8000211c1ac8,0) at uvm_io+0x127 sys/uvm/uvm_io.c:100
sysctl_proc_args(ffff8000211c1f18,2,20000080,ffff8000211c1f48,ffff8000ffff6010) at sysctl_proc_args+0x24b sys/kern/kern_sysctl.c:1790
kern_sysctl(ffff8000211c1f14,3,20000080,ffff8000211c1f48,0,0,99898603ac1efdc2) at kern_sysctl+0xfd sys/kern/kern_sysctl.c:449
sys_sysctl(ffff8000ffff6010,ffff8000211c1fb8,ffff8000211c2010) at sys_sysctl+0x209 sys/kern/kern_sysctl.c:249
syscall(ffff8000211c2080) at syscall+0x489 mi_syscall sys/sys/syscall_mi.h:102 [inline]
syscall(ffff8000211c2080) at syscall+0x489 sys/arch/amd64/amd64/trap.c:585
Xsyscall() at Xsyscall+0x128
end of kernel
end trace frame: 0x7f7ffffd1140, count: 3
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: share->excl
ddb{0}> trace
db_enter() at db_enter+0x18 sys/arch/amd64/amd64/db_interface.c:440
panic(ffffffff8257690f) at panic+0x177 sys/kern/subr_prf.c:202
witness_checkorder(fffffd800872ea28,9,0) at witness_checkorder+0x11bd witness_debugger sys/kern/subr_witness.c:2505 [inline]
witness_checkorder(fffffd800872ea28,9,0) at witness_checkorder+0x11bd sys/kern/subr_witness.c:772
rw_enter(fffffd800872ea18,21) at rw_enter+0xd1 sys/kern/kern_rwlock.c:250
vm_map_lock_ln(fffffd800872ea10,0,1000) at vm_map_lock_ln+0xda sys/uvm/uvm_map.c:5466
uvm_map_extract(fffffd800872ea10,7f7ffffd1000,1000,ffff8000211c1a30,0) at uvm_map_extract+0x173 sys/uvm/uvm_map.c:4530
uvm_io(fffffd800872ea10,ffff8000211c1ac8,0) at uvm_io+0x127 sys/uvm/uvm_io.c:100
sysctl_proc_args(ffff8000211c1f18,2,20000080,ffff8000211c1f48,ffff8000ffff6010) at sysctl_proc_args+0x24b sys/kern/kern_sysctl.c:1790
kern_sysctl(ffff8000211c1f14,3,20000080,ffff8000211c1f48,0,0,99898603ac1efdc2) at kern_sysctl+0xfd sys/kern/kern_sysctl.c:449
sys_sysctl(ffff8000ffff6010,ffff8000211c1fb8,ffff8000211c2010) at sys_sysctl+0x209 sys/kern/kern_sysctl.c:249
syscall(ffff8000211c2080) at syscall+0x489 mi_syscall sys/sys/syscall_mi.h:102 [inline]
syscall(ffff8000211c2080) at syscall+0x489 sys/arch/amd64/amd64/trap.c:585
Xsyscall() at Xsyscall+0x128
end of kernel
end trace frame: 0x7f7ffffd1140, count: -12
ddb{0}> show registers
rdi                                0
rsi                              0x1
rbp               0xffff8000211c1690
rbx               0xffffffff829bbbff    cpu_info_full_primary+0x2bff
rdx                            0x3fd
rcx                                0
rax                             0x13
r8                 0x101010101010101
r9                0x8080808080808080
r10               0xee9c8df8b92c7d45
r11               0xaccdb1dc1d9c1e9a
r12               0xffffffff829bba00    cpu_info_full_primary+0x2a00
r13                                0
r14                                0
r15                              0x1
rip               0xffffffff8138d658    db_enter+0x18
cs                               0x8
rflags                         0x246
rsp               0xffff8000211c1680
ss                              0x10
db_enter+0x18:  addq    $0x8,%rsp
ddb{0}> show proc
PROC (syz-executor3957314175) pid=113695 stat=onproc
    flags process=2<EXEC> proc=0
    pri=50, usrpri=50, nice=20
    forw=0xffffffffffffffff, list=0xffff8000ffff62b0,0xffffffff82b3d400
    process=0xffff80002116c438 user=0xffff8000211bd000, vmspace=0xfffffd800872ea10
    estcpu=0, cpticks=0, pctcpu=0.0
    user=0, sys=0, intr=0
ddb{0}> ps
   PID     TID   PPID    UID  S       FLAGS  WAIT          COMMAND
*65708  113695  69200      0  7         0x2                syz-executor3957314175
 69200  115287  17344      0  3    0x10008a  sigsusp       ksh
 17344  169270  83724      0  7        0x12                sshd
 38883  403732      1      0  3    0x100083  ttyin         getty
 83724   54595      1      0  3        0x88  kqread        sshd
  4896  306634    963     73  3   0x1100090  kqread        syslogd
   963  290255      1      0  3    0x100082  netio         syslogd
 82198  131956      1      0  3    0x100080  kqread        resolvd
 18661   67631  12859     77  3    0x100092  kqread        dhcpleased
 25981  113973  12859     77  3    0x100092  kqread        dhcpleased
 12859   21825      1      0  3        0x80  kqread        dhcpleased
 35955   75859      0      0  3     0x14200  bored         smr
 55522  276782      0      0  3     0x14200  pgzero        zerothread
 62851  429170      0      0  3     0x14200  aiodoned      aiodoned
 82567  471426      0      0  3     0x14200  syncer        update
  1485  303103      0      0  3     0x14200  cleaner       cleaner
 54862  504650      0      0  3     0x14200  reaper        reaper
 57179  481675      0      0  3     0x14200  pgdaemon      pagedaemon
 33486  417824      0      0  3     0x14200  bored         viomb
 83474  446767      0      0  3  0x40014200  acpi0         acpi0
 57898  495666      0      0  3  0x40014200                idle1
 56159  132700      0      0  2     0x14200                softnet
 78181  399224      0      0  3     0x14200  bored         systqmp
 77151  414230      0      0  3     0x14200  bored         systq
 29647  197939      0      0  3  0x40014200  bored         softclock
 82445  508504      0      0  3  0x40014200                idle0
     1  165338      0      0  3        0x82  wait          init
     0       0     -1      0  3     0x10200  scheduler     swapper
ddb{0}> show all locks
Process 65708 (syz-executor3957314175) thread 0xffff8000ffff6010 (113695)
shared rwlock vmmaplk r = 0 (0xfffffd800872ea28)
#0  witness_lock+0x44d
#1  uvm_vslock+0xc8 sys/uvm/uvm_glue.c:129
#2  sys_sysctl+0x2d8 sys/kern/kern_sysctl.c:240
#3  syscall+0x489 mi_syscall sys/sys/syscall_mi.h:102 [inline]
#3  syscall+0x489 sys/arch/amd64/amd64/trap.c:585
#4  Xsyscall+0x128
exclusive rwlock sysctllk r = 0 (0xffffffff82941f10)
#0  witness_lock+0x44d
#1  rw_enter+0x3e1 sys/kern/kern_rwlock.c:310
#2  sys_sysctl+0x1b3 sys/kern/kern_sysctl.c:233
#3  syscall+0x489 mi_syscall sys/sys/syscall_mi.h:102 [inline]
#3  syscall+0x489 sys/arch/amd64/amd64/trap.c:585
#4  Xsyscall+0x128
exclusive kernel_lock &kernel_lock r = 0 (0xffffffff829de988)
#0  witness_lock+0x44d
#1  syscall+0x3ef mi_syscall sys/sys/syscall_mi.h:93 [inline]
#1  syscall+0x3ef sys/arch/amd64/amd64/trap.c:585
#2  Xsyscall+0x128
ddb{0}> show malloc
           Type InUse  MemUse  HighUse   Limit  Requests Type Lim
         devbuf 10143   6388K    6419K  78643K     11233        0
            pcb    13      8K       8K  78643K        13        0
         rtable    62      2K       2K  78643K       108        0
         ifaddr    24      7K       7K  78643K        24        0
       counters    40     33K      33K  78643K        40        0
       ioctlops     0      0K       2K  78643K        25        0
          mount     1      1K       1K  78643K         1        0
            log     0      0K       0K  78643K         5        0
         vnodes  1166     73K      73K  78643K      1179        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     12548        0
      file desc     1      0K       0K  78643K         1        0
           proc    55     74K      75K  78643K       226        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    25    122K     122K  78643K        25        0
           exec     0      0K       2K  78643K       391        0
            tdb     3      0K       0K  78643K         3        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    73      3K       5K  78643K      1951        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     3      0K       0K  78643K         3        0
           temp    20   4694K    4753K  78643K      3051        0
         kqueue    11     16K      18K  78643K        24        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      136       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       25    0       19     1     0     1     1     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     1415    0       38    87     0    87    87     0     8    0
ffsino     272     1415    0       38    92     0    92    92     0     8    0
nchpl      144     1590    0       47    58     0    58    58     0     8    0
uvmvnodes   80     1424    0        0    30     0    30    30     0     8    0
vnodes     224     1424    0        0    84     0    84    84     0     8    0
namei      1024    4131    0     4131     2     1     1     1     0     8    1
percpumem   16       32    0        0     1     0     1     1     0     8    0
scxspl     216     3770    0     3770     2     1     1     2     0     8    1
plimitpl   152       15    0        9     1     0     1     1     0     8    0
sigapl     424      292    0      265     4     0     4     4     0     8    0
knotepl    120       42    0        0     2     0     2     2     0     8    0
kqueuepl   216       20    0       13     1     0     1     1     0     8    0
pipepl     336       79    0       76     2     1     1     1     0     8    0
fdescpl    496      278    0      265     3     0     3     3     0     8    0
filepl     152     1012    0      957     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       17    0        9     1     0     1     1     0     8    0
pgrppl      48       17    0        9     1     0     1     1     0     8    0
ucredpl     96       64    0       54     1     0     1     1     0     8    0
zombiepl   144      265    0      265     2     1     1     1     0     8    1
processpl  1064     292    0      265     3     0     3     3     0     8    0
procpl     672      292    0      265     3     0     3     3     0     8    0
sockpl     480       77    0       53     4     1     3     4     0     8    0
mcl8k      8192       2    0        0     1     0     1     1     0     8    0
mcl4k      4096       2    0        0     1     0     1     1     0     8    0
mcl2k      2048      64    0        0     8     0     8     8     0     8    0
mtagpl      96        3    0        0     1     0     1     1     0     8    0
mbufpl     256      104    0        0     7     0     7     7     0     8    0
bufpl      288     1935    0       86   133     0   133   133     0     8    0
anonpl      24    37988    0    35943    16     2    14    16     0   186    0
amapchunkpl 152    3606    0     3479     7     1     6     7     0   158    0
amappl16   200       27    0       26     2     1     1     1     0     8    0
amappl15   192       59    0       56     1     0     1     1     0     8    0
amappl13   176       32    0       31     2     1     1     1     0     8    0
amappl12   168       15    0       15     2     1     1     1     0     8    1
amappl11   160       46    0       36     1     0     1     1     0     8    0
amappl10   152        5    0        5     1     1     0     1     0     8    0
amappl9    144      447    0      445     1     0     1     1     0     8    0
amappl8    136      339    0      336     1     0     1     1     0     8    0
amappl7    128       60    0       57     1     0     1     1     0     8    0
amappl6    120      107    0       94     1     0     1     1     0     8    0
amappl5    112      163    0      154     1     0     1     1     0     8    0
amappl4    104      578    0      559     1     0     1     1     0     8    0
amappl3     96      113    0      103     1     0     1     1     0     8    0
amappl2     88      336    0      300     1     0     1     1     0     8    0
amappl1     80     8123    0     7772    11     2     9    10     0     8    0
amappl      88     1698    0     1641     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      72        2    0        0     1     0     1     1     0     8    0
uaddrrnd    24      278    0      265     1     0     1     1     0     8    0
uaddrbest   32        2    0        0     1     0     1     1     0     8    0
uaddr       24      278    0      265     1     0     1     1     0     8    0
vmmpekpl   168     5892    0     5877     1     0     1     1     0     8    0
vmmpepl    168    24484    0    23723    46     8    38    45     0   357    1
vmsppl     368      277    0      265     2     0     2     2     0     8    0
rwobjpl     56     8932    0     7000    29     0    29    29     0     8    1
pdppl      4096     563    0      530    52    19    33    45     0     8    0
pvpl        32   123211    0   119421    42     8    34    42     0   265    0
pmappl     248      277    0      265     2     1     1     2     0     8    0
extentpl    40       58    0       38     1     0     1     1     0     8    0
phpool     112      401    0       23    11     0    11    11     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(ffffffff8257690f) at panic+0x177 sys/kern/subr_prf.c:202
witness_checkorder(fffffd800872ea28,9,0) at witness_checkorder+0x11bd witness_debugger sys/kern/subr_witness.c:2505 [inline]
witness_checkorder(fffffd800872ea28,9,0) at witness_checkorder+0x11bd sys/kern/subr_witness.c:772
rw_enter(fffffd800872ea18,21) at rw_enter+0xd1 sys/kern/kern_rwlock.c:250
vm_map_lock_ln(fffffd800872ea10,0,1000) at vm_map_lock_ln+0xda sys/uvm/uvm_map.c:5466
uvm_map_extract(fffffd800872ea10,7f7ffffd1000,1000,ffff8000211c1a30,0) at uvm_map_extract+0x173 sys/uvm/uvm_map.c:4530
uvm_io(fffffd800872ea10,ffff8000211c1ac8,0) at uvm_io+0x127 sys/uvm/uvm_io.c:100
sysctl_proc_args(ffff8000211c1f18,2,20000080,ffff8000211c1f48,ffff8000ffff6010) at sysctl_proc_args+0x24b sys/kern/kern_sysctl.c:1790
kern_sysctl(ffff8000211c1f14,3,20000080,ffff8000211c1f48,0,0,99898603ac1efdc2) at kern_sysctl+0xfd sys/kern/kern_sysctl.c:449
sys_sysctl(ffff8000ffff6010,ffff8000211c1fb8,ffff8000211c2010) at sys_sysctl+0x209 sys/kern/kern_sysctl.c:249
syscall(ffff8000211c2080) at syscall+0x489 mi_syscall sys/sys/syscall_mi.h:102 [inline]
syscall(ffff8000211c2080) at syscall+0x489 sys/arch/amd64/amd64/trap.c:585
Xsyscall() at Xsyscall+0x128
end of kernel
end trace frame: 0x7f7ffffd1140, count: -12
ddb{0}> machine ddbcpu 1
Stopped at      x86_ipi_db+0x1a:        addq    $0x8,%rsp
x86_ipi_db(ffff800020ce8ff0) 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
__mp_lock(ffffffff829de780) at __mp_lock+0x122 __mp_lock_spin sys/kern/kern_lock.c:116 [inline]
__mp_lock(ffffffff829de780) at __mp_lock+0x122 sys/kern/kern_lock.c:147
syscall(ffff800021180860) at syscall+0x3ef mi_syscall sys/sys/syscall_mi.h:93 [inline]
syscall(ffff800021180860) at syscall+0x3ef sys/arch/amd64/amd64/trap.c:585
Xsyscall() at Xsyscall+0x128
end of kernel
end trace frame: 0x7f7ffffba050, count: 9
ddb{1}> trace
x86_ipi_db(ffff800020ce8ff0) 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
__mp_lock(ffffffff829de780) at __mp_lock+0x122 __mp_lock_spin sys/kern/kern_lock.c:116 [inline]
__mp_lock(ffffffff829de780) at __mp_lock+0x122 sys/kern/kern_lock.c:147
syscall(ffff800021180860) at syscall+0x3ef mi_syscall sys/sys/syscall_mi.h:93 [inline]
syscall(ffff800021180860) at syscall+0x3ef sys/arch/amd64/amd64/trap.c:585
Xsyscall() at Xsyscall+0x128
end of kernel
end trace frame: 0x7f7ffffba050, count: -6
ddb{1}> 

Crashes (9):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2022/03/12 13:30 openbsd d895c343d40b 9e8eaa75 .config console log report syz C ci-openbsd-setuid witness: exclusive lock of (rwlock) vmmaplk while share locked
2022/03/12 16:32 openbsd d895c343d40b 9e8eaa75 .config console log report ci-openbsd-setuid witness: exclusive lock of (rwlock) vmmaplk while share locked
2022/03/12 12:52 openbsd d895c343d40b 9e8eaa75 .config console log report ci-openbsd-setuid witness: exclusive lock of (rwlock) vmmaplk while share locked
2022/03/12 12:52 openbsd d895c343d40b 9e8eaa75 .config console log report ci-openbsd-setuid witness: exclusive lock of (rwlock) vmmaplk while share locked
2022/03/12 12:51 openbsd d895c343d40b 9e8eaa75 .config console log report ci-openbsd-setuid witness: exclusive lock of (rwlock) vmmaplk while share locked
2022/03/12 12:50 openbsd d895c343d40b 9e8eaa75 .config console log report ci-openbsd-setuid witness: exclusive lock of (rwlock) vmmaplk while share locked
2022/03/12 12:46 openbsd d895c343d40b 9e8eaa75 .config console log report ci-openbsd-setuid witness: exclusive lock of (rwlock) vmmaplk while share locked
2022/03/12 12:45 openbsd d895c343d40b 9e8eaa75 .config console log report ci-openbsd-setuid witness: exclusive lock of (rwlock) vmmaplk while share locked
2022/03/12 12:37 openbsd d895c343d40b 9e8eaa75 .config console log report ci-openbsd-setuid witness: exclusive lock of (rwlock) vmmaplk while share locked
* Struck through repros no longer work on HEAD.