syzbot


witness: userret: returning with the following locks held:

Status: fixed on 2019/08/27 06:31
Reported-by: syzbot+374d0e7e2400004957f7@syzkaller.appspotmail.com
Fix commit: b808994cf339 When a thread tries to exclusively lock a vnode, the same thread must ensure that any other thread currently trying to acquire the underlying vnode lock has observed that the same vnode is about to be exclusively locked. Such threads must then sleep until the exclusive lock has been released and then try to acquire the lock again. Otherwise, exclusive access to the vnode cannot be guaranteed.
First crash: 1404d, last: 1193d
duplicates (4):
Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
panic:r/managers/multi thcore/kernel/sys/read ADDR cannot exit while holding sleeplocks 1 1368d 1368d 0/3 closed as dup on 2019/08/23 07:18
witness: userret: returningwitness: thread ADDR exiting with the following locks held: 1 1259d 1259d 0/3 closed as dup on 2019/06/22 20:47
witness: thread exiting with locks held syz 679 1193d 1404d 0/3 closed as dup on 2019/02/21 21:47
panic: witness_warn C 26 1404d 1408d 0/3 closed as dup on 2019/01/29 06:51
Patch testing requests:
Created Duration User Patch Repo Result
2019/08/20 14:28 17m anton@basename.se https://github.com/mptre/openbsd-src vn-lock-race OK
2019/08/20 10:01 17m anton@basename.se https://github.com/mptre/openbsd-src vn-lock-race report log
2019/08/20 08:29 16m anton@basename.se https://github.com/mptre/openbsd-src vn-lock-race report log
2019/08/20 07:41 16m anton@basename.se https://github.com/mptre/openbsd-src vn-lock-race report log
2019/08/18 09:59 16m anton@basename.se https://github.com/mptre/openbsd-src vn-lock-race report log
2019/08/17 14:17 16m anton@basename.se https://github.com/mptre/openbsd-src vn-lock-race report log

Sample crash report:
login: witness: userret: returning with the following locks held:
exclusive rrwlock inode r = 0 (0xfffffd8076c5d5f0) locked @ /syzkaller/managers/multicore/kernel/sys/ufs/ufs/ufs_vnops.c:1547
panic: witness_warn
Stopped at      db_enter+0x18:  addq    $0x8,%rsp
    TID    PID    UID     PRFLAGS     PFLAGS  CPU  COMMAND
 270698  73942      0           0      0x480    1  syz-executor6228
*453653  73942      0           0  0x4000000    0  syz-executor6228
db_enter() at db_enter+0x18 sys/arch/amd64/amd64/db_interface.c:399
panic() at panic+0x16c sys/kern/subr_prf.c:208
witness_warn(507bcae4261ef179,0,ffff800020be4970) at witness_warn+0x700 witness_debugger sys/kern/subr_witness.c:2549 [inline]
witness_warn(507bcae4261ef179,0,ffff800020be4970) at witness_warn+0x700 sys/kern/subr_witness.c:1465
userret(d178c027f79620c5) at userret+0x361 sys/kern/kern_sig.c:1899
syscall(c556373217555fb7) at syscall+0x680 mi_syscall_return sys/sys/syscall_mi.h:122 [inline]
syscall(c556373217555fb7) at syscall+0x680 sys/arch/amd64/amd64/trap.c:605
Xsyscall(6,5,ed5f89010b8,0,ed5f8901098,ed5f8901090) at Xsyscall+0x128
end of kernel
end trace frame: 0xed8e6972ad0, count: 9
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}> show panic
witness_warn
ddb{0}> trace
db_enter() at db_enter+0x18 sys/arch/amd64/amd64/db_interface.c:399
panic() at panic+0x16c sys/kern/subr_prf.c:208
witness_warn(507bcae4261ef179,0,ffff800020be4970) at witness_warn+0x700 witness_debugger sys/kern/subr_witness.c:2549 [inline]
witness_warn(507bcae4261ef179,0,ffff800020be4970) at witness_warn+0x700 sys/kern/subr_witness.c:1465
userret(d178c027f79620c5) at userret+0x361 sys/kern/kern_sig.c:1899
syscall(c556373217555fb7) at syscall+0x680 mi_syscall_return sys/sys/syscall_mi.h:122 [inline]
syscall(c556373217555fb7) at syscall+0x680 sys/arch/amd64/amd64/trap.c:605
Xsyscall(6,5,ed5f89010b8,0,ed5f8901098,ed5f8901090) at Xsyscall+0x128
end of kernel
end trace frame: 0xed8e6972ad0, count: -6
ddb{0}> show registers
rdi                                0
rsi                              0x1
rbp               0xffff800020c0af40
rbx               0xffff800020c0afe0
rdx               0xffffffff81f33250    cy_pio_rec+0x41b4
rcx                            0x201
rax                              0x1
r8                0xffffffff81df7814    kprintf+0x174
r9                               0x1
r10               0x7cf76f81e813f7f6
r11               0x795e7570cf214d5b
r12                     0x3000000008
r13               0xffff800020c0af50
r14                            0x100
r15                              0x1
rip               0xffffffff8100c2e8    db_enter+0x18
cs                               0x8
rflags                         0x246
rsp               0xffff800020c0af30
ss                              0x10
db_enter+0x18:  addq    $0x8,%rsp
ddb{0}> show proc
PROC (syz-executor6228) pid=453653 stat=onproc
    flags process=0 proc=4000000<THREAD>
    pri=32, usrpri=86, nice=20
    forw=0xffffffffffffffff, list=0xffff800020be4010,0xffff800020be44d0
    process=0xffff800020bca360 user=0xffff800020c06000, vmspace=0xfffffd806e925710
    estcpu=36, cpticks=2, pctcpu=0.0
    user=0, sys=2, intr=0
ddb{0}> ps
   PID     TID   PPID    UID  S       FLAGS  WAIT          COMMAND
 73942  270698  59418      0  7       0x480                syz-executor6228
*73942  453653  59418      0  7   0x4000000                syz-executor6228
 73942  230439  59418      0  3   0x4000080  fsleep        syz-executor6228
 73942  179925  59418      0  3   0x4000080  fsleep        syz-executor6228
 73942  478723  59418      0  3   0x4000080  fsleep        syz-executor6228
 59418  268678  44260      0  2       0x482                syz-executor6228
 44260  436522  24337      0  3    0x10008a  pause         ksh
 24337  114902  93407      0  3        0x92  select        sshd
 96871  135617      1      0  3    0x100083  ttyin         getty
 93407  256335      1      0  3        0x80  select        sshd
 73530  194253  21231     73  2    0x100010                syslogd
 21231  372363      1      0  3    0x100082  netio         syslogd
 88110  507126      1     77  3    0x100090  poll          dhclient
 57580  250122      1      0  3        0x80  poll          dhclient
 86817  507807      0      0  3     0x14200  pgzero        zerothread
 93105  400105      0      0  3     0x14200  aiodoned      aiodoned
 35533  261527      0      0  3     0x14200  syncer        update
 48959    6084      0      0  3     0x14200  cleaner       cleaner
 68307  205827      0      0  3     0x14200  reaper        reaper
 19355  374577      0      0  3     0x14200  pgdaemon      pagedaemon
  5889   28487      0      0  3     0x14200  bored         crynlk
 97009   36008      0      0  3     0x14200  bored         crypto
  8639  319581      0      0  3  0x40014200  acpi0         acpi0
 46574  116492      0      0  3  0x40014200                idle1
 52318  511356      0      0  3     0x14200  bored         softnet
 86374  441737      0      0  3     0x14200  bored         systqmp
 28510  186753      0      0  3     0x14200  bored         systq
 47051  510633      0      0  3  0x40014200  bored         softclock
 83513  233275      0      0  3  0x40014200                idle0
     1  523314      0      0  3        0x82  wait          init
     0       0     -1      0  3     0x10200  scheduler     swapper
ddb{0}> show all locks
CPU 1:
exclusive sched_lock &sched_lock r = 0 (0xffffffff822f2bb0) locked @ /syzkaller/managers/multicore/kernel/sys/kern/kern_sched.c:162
Process 73942 (syz-executor6228) thread 0xffff800020be4970 (453653)
exclusive rrwlock inode r = 0 (0xfffffd8076c5d5f0) locked @ /syzkaller/managers/multicore/kernel/sys/ufs/ufs/ufs_vnops.c:1547
Process 73530 (syslogd) thread 0xffff800020be5c30 (194253)
exclusive rrwlock inode r = 0 (0xfffffd806ebab6f8) locked @ /syzkaller/managers/multicore/kernel/sys/ufs/ufs/ufs_vnops.c:1547
ddb{0}> show malloc
           Type InUse  MemUse  HighUse   Limit  Requests Type Lim Kern Lim
         devbuf  9445   6315K    6316K  78643K     10532        0        0
            pcb    23      9K       9K  78643K        55        0        0
         rtable    61      2K       2K  78643K       115        0        0
         ifaddr    21      7K       7K  78643K        21        0        0
       counters    39     33K      33K  78643K        39        0        0
       ioctlops     0      0K       2K  78643K        13        0        0
          mount     1      1K       1K  78643K         1        0        0
         vnodes  1166     73K      73K  78643K      1261        0        0
      UFS quota     1     32K      32K  78643K         1        0        0
      UFS mount     5     36K      36K  78643K         5        0        0
            shm     2      1K       1K  78643K         2        0        0
         VM map     2      1K       1K  78643K         2        0        0
            sem     2      0K       0K  78643K         2        0        0
        dirhash    12      2K       2K  78643K        12        0        0
           ACPI  1792    194K     288K  78643K     12592        0        0
      file desc     2      2K       3K  78643K        91        0        0
           proc    40     38K      46K  78643K       201        0        0
    NFS srvsock     1      0K       0K  78643K         1        0        0
     NFS daemon     1     16K      16K  78643K         1        0        0
       in_multi    11      0K       0K  78643K        11        0        0
    ether_multi     1      0K       0K  78643K         1        0        0
    ISOFS mount     1     32K      32K  78643K         1        0        0
  MSDOSFS mount     1     16K      16K  78643K         1        0        0
           ttys    36    159K     159K  78643K        36        0        0
           exec     0      0K       1K  78643K       149        0        0
        pagedep     1      8K       8K  78643K         1        0        0
       inodedep     1     32K      32K  78643K         1        0        0
         newblk     1      0K       0K  78643K         1        0        0
        VM swap     7     26K      26K  78643K         7        0        0
       UVM amap    52      2K       3K  78643K       792        0        0
       UVM aobj     2      2K       2K  78643K         2        0        0
        memdesc     1      4K       4K  78643K         1        0        0
    crypto data     1      1K       1K  78643K         1        0        0
            NDP     3      0K       0K  78643K         3        0        0
           temp    30   2343K    2407K  78643K      1747        0        0
      SYN cache     2     16K      16K  78643K         2        0        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
inpcbpl    280       22    0       16     1     0     1     1     0     8    0
plimitpl   152       13    0        8     1     0     1     1     0     8    0
plcache    128       20    0        0     1     0     1     1     0     8    0
rtentry    112       23    0        1     1     0     1     1     0     8    0
syncache   264        5    0        5     1     0     1     1     0     8    1
tcpcb      544        8    0        5     1     0     1     1     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
dino1pl    128     1502    0      135    45     0    45    45     0     8    0
ffsino     272     1502    0      135    92     0    92    92     0     8    0
nchpl      144     1704    0      179    57     0    57    57     0     8    0
uvmvnodes   72     1511    0        0    28     0    28    28     0     8    0
vnodes     200     1511    0        0    80     0    80    80     0     8    0
namei      1024    4096    0     4096     2     1     1     1     0     8    1
percpumem   16       30    0        0     1     0     1     1     0     8    0
scxspl     192     2662    0     2662     8     2     6     6     0     8    6
sigapl     432      203    0      192     2     0     2     2     0     8    0
futexpl     56      188    0      185     1     0     1     1     0     8    0
knotepl    112        5    0        0     1     0     1     1     0     8    0
kqueuepl   104        1    0        0     1     0     1     1     0     8    0
pipepl     112      114    0      107     2     1     1     1     0     8    0
fdescpl    488      204    0      192     2     0     2     2     0     8    0
filepl     152     1376    0     1325     3     0     3     3     0     8    1
lockfpl     96        6    0        6     1     1     0     1     0     8    0
lockfspl    24        3    0        3     1     1     0     1     0     8    0
sessionpl  112       17    0        9     1     0     1     1     0     8    0
pgrppl      48       17    0        9     1     0     1     1     0     8    0
ucredpl     96      587    0      580     1     0     1     1     0     8    0
zombiepl   144      192    0      192     2     1     1     1     0     8    1
processpl  840      218    0      192     4     0     4     4     0     8    0
procpl     600      328    0      298     3     0     3     3     0     8    0
sockpl     384       64    0       48     2     0     2     2     0     8    0
mcl4k      4096       2    0        0     1     0     1     1     0     8    0
mcl2k      2048      67    0        0     9     0     9     9     0     8    0
mtagpl      80        1    0        0     1     0     1     1     0     8    0
mbufpl     256       85    0        0     6     0     6     6     0     8    0
bufpl      256     2046    0      261   112     0   112   112     0     8    0
anonpl      16    18529    0    17364     6     1     5     6     0   125    0
amapchunkpl 152     743    0      699     2     0     2     2     0   158    0
amappl16   192      134    0      125     1     0     1     1     0     8    0
amappl15   184        1    0        1     1     1     0     1     0     8    0
amappl14   176        1    0        1     1     1     0     1     0     8    0
amappl13   168       16    0       13     1     0     1     1     0     8    0
amappl12   160        4    0        4     1     1     0     1     0     8    0
amappl11   152      177    0      168     1     0     1     1     0     8    0
amappl10   144       43    0       43     2     1     1     1     0     8    1
amappl9    136      203    0      202     1     0     1     1     0     8    0
amappl8    128      106    0       99     1     0     1     1     0     8    0
amappl7    120       30    0       26     1     0     1     1     0     8    0
amappl6    112       42    0       38     1     0     1     1     0     8    0
amappl5    104      176    0      164     1     0     1     1     0     8    0
amappl4     96      257    0      238     1     0     1     1     0     8    0
amappl3     88      112    0      106     1     0     1     1     0     8    0
amappl2     80      814    0      768     1     0     1     1     0     8    0
amappl1     72    12427    0    12012    15     5    10    15     0     8    0
amappl      72      507    0      483     1     0     1     1     0    75    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
dma64       64      259    0      259     1     1     0     1     0     8    0
dma32       32        7    0        7     1     1     0     1     0     8    0
dma16       16       17    0       17     1     1     0     1     0     8    0
aobjpl      64        1    0        0     1     0     1     1     0     8    0
uaddrrnd    24      204    0      192     1     0     1     1     0     8    0
uaddrbest   32        2    0        0     1     0     1     1     0     8    0
uaddr       24      204    0      192     1     0     1     1     0     8    0
vmmpekpl   168     5377    0     5357     1     0     1     1     0     8    0
vmmpepl    168    25699    0    24920    49    15    34    43     0   357    0
vmsppl     360      203    0      192     2     0     2     2     0     8    0
pdppl      4096     415    0      384     5     0     5     5     0     8    0
pvpl        32    73927    0    71052    30     4    26    26     0   265    2
pmappl     224      203    0      192     1     0     1     1     0     8    0
extentpl    40       39    0       25     1     0     1     1     0     8    0
phpool     112      241    0        3     7     0     7     7     0     8    0
ddb{0}> 

Crashes (315):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci-openbsd-multicore 2019/01/28 22:32 openbsd fabafa7b0c06 aa432daf .config log report syz C
ci-openbsd-setuid 2019/06/22 14:36 openbsd dcaa94fa8333 34bf9440 .config log report syz
ci-openbsd-multicore 2019/01/30 00:58 openbsd 906b732f9d92 aa432daf .config log report syz
ci-openbsd-setuid 2019/01/29 20:31 openbsd 810597764d1f aa432daf .config log report syz
ci-openbsd-setuid 2019/01/29 03:52 openbsd fabafa7b0c06 aa432daf .config log report syz
ci-openbsd-setuid 2019/01/28 22:33 openbsd fabafa7b0c06 aa432daf .config log report syz
ci-openbsd-setuid 2019/01/28 21:54 openbsd fabafa7b0c06 aa432daf .config log report syz
ci-openbsd-multicore 2019/08/27 03:30 openbsd 4350d62ed76b d21c5d9d .config log report
ci-openbsd-setuid 2019/08/27 02:30 openbsd 4350d62ed76b d21c5d9d .config log report
ci-openbsd-multicore 2019/08/26 21:48 openbsd 4350d62ed76b d21c5d9d .config log report
ci-openbsd-multicore 2019/08/26 18:19 openbsd 4350d62ed76b d21c5d9d .config log report
ci-openbsd-setuid 2019/08/26 12:54 openbsd 4350d62ed76b d21c5d9d .config log report
ci-openbsd-multicore 2019/08/26 07:40 openbsd 56a8f046bf24 d21c5d9d .config log report
ci-openbsd-setuid 2019/08/25 09:21 openbsd 1507cfe1d6a4 d21c5d9d .config log report
ci-openbsd-setuid 2019/08/25 04:57 openbsd 1507cfe1d6a4 d21c5d9d .config log report
ci-openbsd-multicore 2019/08/23 08:58 openbsd 9f57e42b5520 ca6f3cfa .config log report
ci-openbsd-setuid 2019/08/23 02:49 openbsd 9f57e42b5520 ca6f3cfa .config log report
ci-openbsd-setuid 2019/08/21 05:05 openbsd 288889b93f60 6b8391d0 .config log report
ci-openbsd-setuid 2019/08/20 13:03 openbsd 55fd3d8764e7 cfc9868f .config log report
ci-openbsd-setuid 2019/08/20 00:27 openbsd 85b8fad3ba84 ae348fb7 .config log report
ci-openbsd-setuid 2019/08/19 14:58 openbsd 85b8fad3ba84 b8ceabfc .config log report
ci-openbsd-setuid 2019/08/19 12:51 openbsd 85b8fad3ba84 b8ceabfc .config log report
ci-openbsd-setuid 2019/08/18 17:07 openbsd 682277b940c4 55bf8926 .config log report
ci-openbsd-setuid 2019/08/18 13:21 openbsd f7a04f0ff9e5 55bf8926 .config log report
ci-openbsd-setuid 2019/08/18 00:34 openbsd 67dad36eec18 55bf8926 .config log report
ci-openbsd-setuid 2019/08/17 12:58 openbsd 8a28f24953c2 8fd428a1 .config log report
ci-openbsd-setuid 2019/08/16 14:35 openbsd bb94865e4f07 8fd428a1 .config log report
ci-openbsd-setuid 2019/08/15 13:25 openbsd f976af443d9f 0d298d6b .config log report
ci-openbsd-multicore 2019/08/14 19:29 openbsd e394331481e8 5576551b .config log report
ci-openbsd-setuid 2019/08/14 17:38 openbsd e394331481e8 5576551b .config log report
ci-openbsd-setuid 2019/08/14 03:40 openbsd 39cbba3c6e68 ef801a3e .config log report
ci-openbsd-multicore 2019/08/13 23:17 openbsd 723403cbe800 74d61399 .config log report
ci-openbsd-setuid 2019/08/13 09:03 openbsd 8c9a8c5f30e0 8620c2c2 .config log report
ci-openbsd-multicore 2019/08/13 00:04 openbsd 8c9a8c5f30e0 8620c2c2 .config log report
ci-openbsd-setuid 2019/08/11 12:34 openbsd 9db55ce60491 acb51638 .config log report
ci-openbsd-setuid 2019/08/09 23:44 openbsd e875c3a0682a aff9e255 .config log report
ci-openbsd-multicore 2019/08/09 20:55 openbsd e875c3a0682a aff9e255 .config log report
ci-openbsd-setuid 2019/08/09 12:48 openbsd 3ac77e71a879 ede31a9b .config log report
ci-openbsd-setuid 2019/08/09 06:13 openbsd 3ac77e71a879 ede31a9b .config log report
ci-openbsd-setuid 2019/08/09 03:17 openbsd 3ac77e71a879 ede31a9b .config log report
ci-openbsd-setuid 2019/08/09 00:27 openbsd 081f0ff5d5ed bcc419e9 .config log report
ci-openbsd-setuid 2019/08/07 10:35 openbsd 3bcea6ef626a cdde7486 .config log report
ci-openbsd-multicore 2019/08/07 01:53 openbsd 3bcea6ef626a cdde7486 .config log report
ci-openbsd-multicore 2019/08/05 22:05 openbsd d8d31ef08b65 6affd8e8 .config log report
ci-openbsd-setuid 2019/08/05 14:07 openbsd fa32c33cb2c9 6affd8e8 .config log report
ci-openbsd-setuid 2019/08/05 07:52 openbsd 864b814f529e 6affd8e8 .config log report
ci-openbsd-multicore 2019/08/05 03:51 openbsd 864b814f529e 6affd8e8 .config log report
ci-openbsd-multicore 2019/08/04 18:02 openbsd e4f599ca6879 6affd8e8 .config log report
ci-openbsd-setuid 2019/08/04 01:24 openbsd d72f70aa5ac4 6affd8e8 .config log report
ci-openbsd-multicore 2019/08/03 14:18 openbsd c935b51f457f 6affd8e8 .config log report
ci-openbsd-setuid 2019/08/03 01:55 openbsd f7c95aac3abf 3faab807 .config log report
ci-openbsd-pf 2019/03/05 00:53 openbsd e86fbd1d81cc 3419571c .config log report
* Struck through repros no longer work on HEAD.