syzbot


panic: vputonfreelist: lock count is not zero

Status: fixed on 2020/03/27 17:30
Reported-by: syzbot+767d6deb1a647850a0ca@syzkaller.appspotmail.com
Fix commit: 2a9890d8c8d9 Relax the lockcount assertion in vputonfreelist(). Back when I fixed several problems with the vnode exclusive lock implementation, I overlooked the fact that a vnode can be in a state where the usecount is zero while the holdcount still being positive. There could still be threads waiting on the vnode lock in uvn_io() as long as the holdcount is positive.
First crash: 939d, last: 939d
Patch testing requests:
Created Duration User Patch Repo Result
2020/02/29 09:30 20m anton@basename.se https://github.com/mptre/openbsd-src syzkaller OK

Sample crash report:
login: panic: vputonfreelist: lock count is not zero
Stopped at      db_enter+0x18:  addq    $0x8,%rsp
    TID    PID    UID     PRFLAGS     PFLAGS  CPU  COMMAND
 195858  20127      0           0          0    1  syz-executor8348
* 73242  45679      0           0  0x4000000    0K syz-executor8348
db_enter() at db_enter+0x18 sys/arch/amd64/amd64/db_interface.c:398
panic(ffffffff8226d206) at panic+0x15c sys/kern/subr_prf.c:207
vputonfreelist(fffffd8079c16840) at vputonfreelist+0x139 sys/kern/vfs_subr.c:711
vn_closefile(fffffd806dbb5d20,ffff800020ae7ae8) at vn_closefile+0xe2 sys/kern/vfs_vnops.c:615
fdrop(fffffd806dbb5d20,ffff800020ae7ae8) at fdrop+0xc2 sys/kern/kern_descrip.c:1276
sys_ftruncate(ffff800020ae7ae8,ffff800020b75018,ffff800020b75060) at sys_ftruncate+0x21f sys/kern/vfs_syscalls.c:2860
syscall(ffff800020b750e0) at syscall+0x4a4 mi_syscall sys/sys/syscall_mi.h:102 [inline]
syscall(ffff800020b750e0) at syscall+0x4a4 sys/arch/amd64/amd64/trap.c:570
Xsyscall() at Xsyscall+0x128
end of kernel
end trace frame: 0xd463dd4a710, count: 7
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
vputonfreelist: lock count is not zero
ddb{0}> trace
db_enter() at db_enter+0x18 sys/arch/amd64/amd64/db_interface.c:398
panic(ffffffff8226d206) at panic+0x15c sys/kern/subr_prf.c:207
vputonfreelist(fffffd8079c16840) at vputonfreelist+0x139 sys/kern/vfs_subr.c:711
vn_closefile(fffffd806dbb5d20,ffff800020ae7ae8) at vn_closefile+0xe2 sys/kern/vfs_vnops.c:615
fdrop(fffffd806dbb5d20,ffff800020ae7ae8) at fdrop+0xc2 sys/kern/kern_descrip.c:1276
sys_ftruncate(ffff800020ae7ae8,ffff800020b75018,ffff800020b75060) at sys_ftruncate+0x21f sys/kern/vfs_syscalls.c:2860
syscall(ffff800020b750e0) at syscall+0x4a4 mi_syscall sys/sys/syscall_mi.h:102 [inline]
syscall(ffff800020b750e0) at syscall+0x4a4 sys/arch/amd64/amd64/trap.c:570
Xsyscall() at Xsyscall+0x128
end of kernel
end trace frame: 0xd463dd4a710, count: -8
ddb{0}> show registers
rdi                                0
rsi                              0x1
rbp               0xffff800020b74d80
rbx               0xffff800020b74e30
rdx                             0x8b
rcx                              0x2
rax                              0x1
r8                0xffffffff81fb607f    kprintf+0x16f
r9                               0x1
r10               0xbe2ecbc765fae2bb
r11               0xbaa3ab3fcc213999
r12                     0x3000000008
r13               0xffff800020b74d90
r14                            0x100
r15                              0x1
rip               0xffffffff8219a9e8    db_enter+0x18
cs                               0x8
rflags                         0x246
rsp               0xffff800020b74d70
ss                              0x10
db_enter+0x18:  addq    $0x8,%rsp
ddb{0}> show proc
PROC (syz-executor8348) pid=73242 stat=onproc
    flags process=0 proc=4000000<THREAD>
    pri=17, usrpri=60, nice=20
    forw=0xffffffffffffffff, list=0xffff800020ae6768,0xffff800020ae6298
    process=0xffff800020a9d2e0 user=0xffff800020b70000, vmspace=0xfffffd807f000cf0
    estcpu=10, cpticks=0, pctcpu=0.0
    user=0, sys=0, intr=0
ddb{0}> ps
   PID     TID   PPID    UID  S       FLAGS  WAIT          COMMAND
 20127  195858  90740      0  7           0                syz-executor8348
 20127  207563  90740      0  3   0x4000080  poll          syz-executor8348
 45679  485053  91033      0  3        0x80  nanosleep     syz-executor8348
 45679  355269  91033      0  2   0x4000000                syz-executor8348
 45679  153576  91033      0  3   0x4000080  poll          syz-executor8348
*45679   73242  91033      0  7   0x4000000                syz-executor8348
 45679  239103  91033      0  3   0x4000080  fsleep        syz-executor8348
 91033  476555  56905      0  3        0x80  nanosleep     syz-executor8348
 90740  473515  56905      0  3        0x80  nanosleep     syz-executor8348
 56905  433568   3835      0  3        0x82  nanosleep     syz-executor8348
  3835   46644  48727      0  3    0x10008a  pause         ksh
 48727  417836  60741      0  3        0x92  select        sshd
 94830  169206      1      0  3    0x100083  ttyin         getty
 60741  120297      1      0  3        0x80  select        sshd
 21999  357243  35443     74  3    0x100092  bpf           pflogd
 35443  207008      1      0  3        0x80  netio         pflogd
 68076  381186  10922     73  3    0x100090  kqread        syslogd
 10922  321445      1      0  3    0x100082  netio         syslogd
   206  213009      1     77  3    0x100090  poll          dhclient
 97635  351294      1      0  3        0x80  poll          dhclient
 18033  156044      0      0  3     0x14200  bored         smr
 26697  344571      0      0  3     0x14200  pgzero        zerothread
 50004  325788      0      0  3     0x14200  aiodoned      aiodoned
 16888   42834      0      0  3     0x14200  syncer        update
 49430  449639      0      0  3     0x14200  cleaner       cleaner
  1157  487162      0      0  3     0x14200  reaper        reaper
 99249  435812      0      0  3     0x14200  pgdaemon      pagedaemon
 21773  474466      0      0  3     0x14200  bored         crynlk
 33474  499476      0      0  3     0x14200  bored         crypto
 30713  511756      0      0  3  0x40014200  acpi0         acpi0
 99636  390416      0      0  3  0x40014200                idle1
 20609  262663      0      0  3     0x14200  bored         softnet
 33589  377415      0      0  3     0x14200  bored         systqmp
 10141  160496      0      0  3     0x14200  bored         systq
 89076  196263      0      0  3  0x40014200  bored         softclock
 99376  465301      0      0  3  0x40014200                idle0
     1   99157      0      0  3        0x82  wait          init
     0       0     -1      0  3     0x10200  scheduler     swapper
ddb{0}> show all locks
Process 45679 (syz-executor8348) thread 0xffff800020ae7ae8 (73242)
exclusive kernel_lock &kernel_lock r = 1 (0xffffffff82641eb8)
#0  witness_lock+0x52e sys/kern/subr_witness.c:1164
#1  __mp_acquire_count+0x51 sys/kern/kern_lock.c:227
#2  mi_switch+0x392 sys/kern/sched_bsd.c:435
#3  sleep_finish+0x113 sys/kern/kern_synch.c:415
#4  sleep_finish_all+0x32 sleep_finish_timeout sys/kern/kern_synch.c:444 [inline]
#4  sleep_finish_all+0x32 sys/kern/kern_synch.c:206
#5  tsleep+0x1cc sys/kern/kern_synch.c:155
#6  biowait+0xa6 sys/kern/vfs_bio.c:1255
#7  bwrite+0x1e4 sys/kern/vfs_bio.c:765
#8  ffs_update+0x2c2 sys/ufs/ffs/ffs_inode.c:113
#9  ffs_truncate+0x285
#10 ufs_setattr+0x6b0 sys/ufs/ufs/ufs_vnops.c:408
#11 VOP_SETATTR+0xc6 sys/kern/vfs_vops.c:229
#12 sys_ftruncate+0x1e0 sys/kern/vfs_syscalls.c:2856
#13 syscall+0x4a4 mi_syscall sys/sys/syscall_mi.h:102 [inline]
#13 syscall+0x4a4 sys/arch/amd64/amd64/trap.c:570
#14 Xsyscall+0x128
ddb{0}> show malloc
           Type InUse  MemUse  HighUse   Limit  Requests Type Lim
         devbuf  9462   6393K    6394K  78643K     10553        0
            pcb    13      8K       8K  78643K        13        0
         rtable    61      2K       2K  78643K       127        0
         ifaddr    29      8K       8K  78643K        30        0
       counters    39     33K      33K  78643K        39        0
       ioctlops     0      0K       4K  78643K      1467        0
            iov     0      0K      12K  78643K       686        0
          mount     1      1K       1K  78643K         1        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  1809    196K     290K  78643K     12766        0
      file desc     1      0K       0K  78643K         1        0
           proc    59     63K      71K  78643K       358        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       1K  78643K       177        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    70      3K      12K  78643K      2636        0
       UVM aobj     2      2K       2K  78643K         2        0
        memdesc     1      4K       4K  78643K         1        0
    crypto data     1      1K       1K  78643K         1        0
            NDP     4      0K       0K  78643K         4        0
           temp    24   3009K    3073K  78643K      1666        0
         kqueue     2      2K       2K  78643K         2        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
arp         64        2    0        0     1     0     1     1     0     8    0
plcache    128       20    0        0     1     0     1     1     0     8    0
rtpcb       80       15    0       13     1     0     1     1     0     8    0
rtentry    112       23    0        1     1     0     1     1     0     8    0
unpcb      120       29    0       19     1     0     1     1     0     8    0
syncache   264        5    0        5     2     2     0     1     0     8    0
tcpcb      544        8    0        5     1     0     1     1     0     8    0
inpcb      280       29    0       23     1     0     1     1     0     8    0
pfosfp      40      846    0      423     5     0     5     5     0     8    0
pfosfpen   112     1428    0      714    21     0    21    21     0     8    0
pfstitem    24        9    0        7     1     0     1     1     0     8    0
pfstkey    112        9    0        7     1     0     1     1     0     8    0
pfstate    328        9    0        7     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       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
dino1pl    128     1402    0       16    45     0    45    45     0     8    0
ffsino     272     1402    0       16    93     0    93    93     0     8    0
nchpl      144     1577    0       34    58     0    58    58     0     8    0
uvmvnodes   72     1412    0        0    26     0    26    26     0     8    0
vnodes     208     1412    0        0    75     0    75    75     0     8    0
namei      1024    4429    0     4429     2     1     1     1     0     8    1
percpumem   16       30    0        0     1     0     1     1     0     8    0
scxspl     192     4332    0     4331    11    10     1     7     0     8    0
plimitpl   152       14    0        8     1     0     1     1     0     8    0
sigapl     424      566    0      534     4     0     4     4     0     8    0
futexpl     56     3113    0     3112     1     0     1     1     0     8    0
knotepl    112        5    0        0     1     0     1     1     0     8    0
kqueuepl   144        1    0        0     1     0     1     1     0     8    0
pipelkpl    48      751    0      744     2     1     1     1     0     8    0
pipepl     120     1502    0     1490     2     1     1     1     0     8    0
fdescpl    496      551    0      534     3     0     3     3     0     8    0
filepl     152     3022    0     2968     3     0     3     3     0     8    0
lockfpl    104     1377    0     1376     1     0     1     1     0     8    0
lockfspl    48      522    0      521     1     0     1     1     0     8    0
sessionpl  112       18    0        9     1     0     1     1     0     8    0
pgrppl      48       18    0        9     1     0     1     1     0     8    0
ucredpl     96       53    0       44     1     0     1     1     0     8    0
zombiepl   144      534    0      534     2     1     1     1     0     8    1
processpl  960      566    0      534     5     0     5     5     0     8    0
procpl     624     1712    0     1675     4     0     4     4     0     8    0
sockpl     400       73    0       55     2     0     2     2     0     8    0
mcl4k      4096       3    0        0     1     0     1     1     0     8    0
mcl2k      2048      82    0        0    11     0    11    11     0     8    0
mtagpl      80        1    0        0     1     0     1     1     0     8    0
mbufpl     256      119    0        0     7     0     7     7     0     8    0
bufpl      280     2870    0       79   200     0   200   200     0     8    0
anonpl      16    40411    0    39086    13     7     6    11     0   124    0
amapchunkpl 152    3178    0     3126     3     0     3     3     0   158    0
amappl16   192     1170    0     1166     4     3     1     4     0     8    0
amappl15   184        1    0        0     1     0     1     1     0     8    0
amappl14   176        1    0        1     1     1     0     1     0     8    0
amappl13   168       14    0       13     2     1     1     1     0     8    0
amappl12   160        1    0        1     1     1     0     1     0     8    0
amappl11   152       73    0       55     1     0     1     1     0     8    0
amappl10   144       10    0        8     1     0     1     1     0     8    0
amappl9    136      236    0      235     1     0     1     1     0     8    0
amappl8    128      580    0      574     1     0     1     1     0     8    0
amappl7    120       91    0       83     1     0     1     1     0     8    0
amappl6    112       15    0       15     2     2     0     1     0     8    0
amappl5    104      132    0      118     1     0     1     1     0     8    0
amappl4     96      481    0      455     1     0     1     1     0     8    0
amappl3     88       99    0       93     1     0     1     1     0     8    0
amappl2     80     3907    0     3838     3     1     2     2     0     8    0
amappl1     72    22995    0    22540    16     6    10    16     0     8    0
amappl      80     1902    0     1872     1     0     1     1     0    84    0
dma4096    4096       1    0        1     1     1     0     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        1    0        0     1     0     1     1     0     8    0
uaddrrnd    24      551    0      534     1     0     1     1     0     8    0
uaddrbest   32        2    0        0     1     0     1     1     0     8    0
uaddr       24      551    0      534     1     0     1     1     0     8    0
vmmpekpl   168    12462    0    12435     2     0     2     2     0     8    0
vmmpepl    168    57554    0    56570    62    17    45    51     0   357    2
vmsppl     368      550    0      534     2     0     2     2     0     8    0
pdppl      4096    1109    0     1068     6     0     6     6     0     8    0
pvpl        32   121409    0   118244    43    15    28    36     0   265    1
pmappl     232      550    0      534     1     0     1     1     0     8    0
extentpl    40       46    0       29     1     0     1     1     0     8    0
phpool     112      143    0        4     4     0     4     4     0     8    0

Crashes (2):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci-openbsd-multicore 2020/02/28 04:47 openbsd c6faab6d3d04 c88c7b75 .config log report syz C
ci-openbsd-multicore 2020/02/28 03:45 openbsd c6faab6d3d04 c88c7b75 .config log report
* Struck through repros no longer work on HEAD.