syzbot


assert "timo || _kernel_lock_held()" failed in kern_synch.c

Status: fixed on 2019/08/13 12:07
Reported-by: syzbot+57588681ca9e3e9ba926@syzkaller.appspotmail.com
Fix commit: 93e05fce3bab Revert unlock of lseek(2) since vn_lock() could end up calling tsleep() which is not allowed without holding the kernel lock. Otherwise, wakeups could be lost.
First crash: 1207d, last: 1207d

Sample crash report:
login: panic: kernel diagnostic assertion "timo || _kernel_lock_held()" failed: file "/syzkaller/managers/setuid/kernel/sys/kern/kern_synch.c", line 121
Stopped at      db_enter+0x18:  addq    $0x8,%rsp
    TID    PID    UID     PRFLAGS     PFLAGS  CPU  COMMAND
 388950  39601      0           0  0x4000000    0  syz-executor4793
*445333  85914      0           0  0x4000000    1  syz-executor4793
db_enter() at db_enter+0x18 sys/arch/amd64/amd64/db_interface.c:398
panic() at panic+0x15c sys/kern/subr_prf.c:207
__assert(ffffffff81fb5b5c,ffffffff81fd515d,79,ffffffff81fc5830) at __assert+0x2e sys/kern/subr_prf.c:154
tsleep(fffffd806d2f5b40,8,ffffffff81fb40b2,0) at tsleep+0x3fb sleep_finish_all sys/kern/kern_synch.c:405 [inline]
tsleep(fffffd806d2f5b40,8,ffffffff81fb40b2,0) at tsleep+0x3fb sys/kern/kern_synch.c:152
vn_seek(fffffd807b0024c0,ffff800020bb5808,0,ffff800020aff8b8) at vn_seek+0xa0 vn_lock sys/kern/vfs_vnops.c:556 [inline]
vn_seek(fffffd807b0024c0,ffff800020bb5808,0,ffff800020aff8b8) at vn_seek+0xa0 sys/kern/vfs_vnops.c:611
sys_lseek(ffff800020aff8b8,ffff800020bb5878,ffff800020bb58e0) at sys_lseek+0x6f sys/kern/vfs_syscalls.c:1859
syscall(ffff800020bb5950) at syscall+0x552 mi_syscall sys/sys/syscall_mi.h:92 [inline]
syscall(ffff800020bb5950) at syscall+0x552 sys/arch/amd64/amd64/trap.c:555
Xsyscall(6,0,945385670c8,0,945385670a8,945385670a0) at Xsyscall+0x128
end of kernel
end trace frame: 0x9483259cce0, 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{1}> 
ddb{1}> set $lines = 0
ddb{1}> set $maxwidth = 0
ddb{1}> show panic
kernel diagnostic assertion "timo || _kernel_lock_held()" failed: file "/syzkaller/managers/setuid/kernel/sys/kern/kern_synch.c", line 121
ddb{1}> trace
db_enter() at db_enter+0x18 sys/arch/amd64/amd64/db_interface.c:398
panic() at panic+0x15c sys/kern/subr_prf.c:207
__assert(ffffffff81fb5b5c,ffffffff81fd515d,79,ffffffff81fc5830) at __assert+0x2e sys/kern/subr_prf.c:154
tsleep(fffffd806d2f5b40,8,ffffffff81fb40b2,0) at tsleep+0x3fb sleep_finish_all sys/kern/kern_synch.c:405 [inline]
tsleep(fffffd806d2f5b40,8,ffffffff81fb40b2,0) at tsleep+0x3fb sys/kern/kern_synch.c:152
vn_seek(fffffd807b0024c0,ffff800020bb5808,0,ffff800020aff8b8) at vn_seek+0xa0 vn_lock sys/kern/vfs_vnops.c:556 [inline]
vn_seek(fffffd807b0024c0,ffff800020bb5808,0,ffff800020aff8b8) at vn_seek+0xa0 sys/kern/vfs_vnops.c:611
sys_lseek(ffff800020aff8b8,ffff800020bb5878,ffff800020bb58e0) at sys_lseek+0x6f sys/kern/vfs_syscalls.c:1859
syscall(ffff800020bb5950) at syscall+0x552 mi_syscall sys/sys/syscall_mi.h:92 [inline]
syscall(ffff800020bb5950) at syscall+0x552 sys/arch/amd64/amd64/trap.c:555
Xsyscall(6,0,945385670c8,0,945385670a8,945385670a0) at Xsyscall+0x128
end of kernel
end trace frame: 0x9483259cce0, count: -8
ddb{1}> show registers
rdi                                0
rsi                              0x1
rbp               0xffff800020bb5590
rbx               0xffff800020bb5640
rdx                             0x8b
rcx                              0x2
rax                              0x1
r8                0xffffffff81b1c663    kprintf+0x173
r9                               0x1
r10               0x4da86d535fba2a30
r11               0x821ce3a1a12ad9d8
r12                     0x3000000008
r13               0xffff800020bb55a0
r14                            0x100
r15                              0x1
rip               0xffffffff811a7028    db_enter+0x18
cs                               0x8
rflags                         0x246
rsp               0xffff800020bb5580
ss                              0x10
db_enter+0x18:  addq    $0x8,%rsp
ddb{1}> show proc
PROC (syz-executor4793) pid=445333 stat=onproc
    flags process=0 proc=4000000<THREAD>
    pri=52, usrpri=52, nice=20
    forw=0xffffffffffffffff, list=0xffff800020afe008,0xffff800020afe508
    process=0xffff800020b2a710 user=0xffff800020bb0000, vmspace=0xfffffd806e8f1738
    estcpu=36, cpticks=2, pctcpu=0.0
    user=0, sys=2, intr=0
ddb{1}> ps
   PID     TID   PPID    UID  S       FLAGS  WAIT          COMMAND
 39601  204572  97462      0  2           0                syz-executor4793
 39601  325977  97462      0  3   0x4000080  fsleep        syz-executor4793
 39601  388950  97462      0  7   0x4000000                syz-executor4793
 85914  517016   1651      0  2           0                syz-executor4793
*85914  445333   1651      0  7   0x4000000                syz-executor4793
 97462   32853  94562      0  3        0x80  nanosleep     syz-executor4793
  1651  153458  94562      0  3        0x80  nanosleep     syz-executor4793
 94562  493971  31450      0  3        0x82  nanosleep     syz-executor4793
 31450   33961  13540      0  3    0x10008a  pause         ksh
 13540  372110  19139      0  3        0x92  select        sshd
 58890  442653      1      0  3    0x100083  ttyin         getty
 19139  226125      1      0  3        0x80  select        sshd
 85415  172628  15082     73  3    0x100090  kqread        syslogd
 15082  393815      1      0  3    0x100082  netio         syslogd
 84541  392921      1     77  3    0x100090  poll          dhclient
 14733  272732      1      0  3        0x80  poll          dhclient
 16976  486309      0      0  2     0x14200                zerothread
 79982  446158      0      0  3     0x14200  aiodoned      aiodoned
  4777  348358      0      0  3     0x14200  syncer        update
 27634  260760      0      0  3     0x14200  cleaner       cleaner
 46161   60181      0      0  3     0x14200  reaper        reaper
 10408  215339      0      0  3     0x14200  pgdaemon      pagedaemon
 65729  320803      0      0  3     0x14200  bored         crynlk
 26764  505248      0      0  3     0x14200  bored         crypto
 55960  272271      0      0  3  0x40014200  acpi0         acpi0
  4652   25522      0      0  3  0x40014200                idle1
 97061  364490      0      0  3     0x14200  bored         softnet
 61173  183324      0      0  3     0x14200  bored         systqmp
  7216  452373      0      0  3     0x14200  bored         systq
 18286  289152      0      0  3  0x40014200  bored         softclock
 35173  355206      0      0  3  0x40014200                idle0
 94142  143501      0      0  3     0x14200  bored         smr
     1  266328      0      0  3        0x82  wait          init
     0       0     -1      0  3     0x10200  scheduler     swapper
ddb{1}> show all locks
Process 39601 (syz-executor4793) thread 0xffff800020afe280 (388950)
exclusive rwlock fdlock r = 0 (0xfffffd807f7c5058)
#0  witness_lock+0x52e sys/kern/subr_witness.c:1163
#1  ptmioctl+0xe7 sys/kern/tty_pty.c:1071
#2  VOP_IOCTL+0x88 sys/kern/vfs_vops.c:290
#3  vn_ioctl+0xb7 sys/kern/vfs_vnops.c:524
#4  sys_ioctl+0x5b8
#5  syscall+0x552 mi_syscall sys/sys/syscall_mi.h:92 [inline]
#5  syscall+0x552 sys/arch/amd64/amd64/trap.c:555
#6  Xsyscall+0x128
ddb{1}> show malloc
           Type InUse  MemUse  HighUse   Limit  Requests Type Lim Kern Lim
         devbuf  9448   6316K    6317K  78643K     10535        0        0
            pcb    13      8K       8K  78643K        13        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  1180     74K      74K  78643K      1618        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  1808    196K     290K  78643K     12765        0        0
      file desc     3      4K       5K  78643K       610        0        0
           proc    40     38K      46K  78643K       257        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    42    185K     185K  78643K        42        0        0
           exec     0      0K       1K  78643K       152        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    64      3K       3K  78643K      1489        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   2731K    2795K  78643K      2120        0        0
      SYN cache     2     16K      16K  78643K         2        0        0
ddb{1}> 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       27    0       19     1     0     1     1     0     8    0
syncache   264        5    0        5     2     1     1     1     0     8    1
tcpcb      544        8    0        5     1     0     1     1     0     8    0
inpcb      280       22    0       16     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
dino1pl    128     2029    0      650    45     0    45    45     0     8    0
ffsino     272     2029    0      650    92     0    92    92     0     8    0
nchpl      144     2419    0      880    58     0    58    58     0     8    0
uvmvnodes   72     2038    0        0    38     0    38    38     0     8    0
vnodes     200     2038    0        0   108     0   108   108     0     8    0
namei      1024    7508    0     7508     2     1     1     1     0     8    1
percpumem   16       30    0        0     1     0     1     1     0     8    0
scxspl     192     5107    0     5105     9     8     1     6     0     8    0
plimitpl   152       13    0        8     1     0     1     1     0     8    0
sigapl     432      381    0      367     2     0     2     2     0     8    0
futexpl     56     1501    0     1500     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      118    0      111     3     2     1     1     0     8    0
fdescpl    488      382    0      367     2     0     2     2     0     8    0
filepl     152     3469    0     3417     3     0     3     3     0     8    1
lockfpl    104        6    0        6     1     1     0     1     0     8    0
lockfspl    48        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     2476    0     2469     1     0     1     1     0     8    0
zombiepl   144      367    0      367     3     2     1     1     0     8    1
processpl  896      397    0      367     4     0     4     4     0     8    0
procpl     632      974    0      941     4     0     4     4     0     8    1
sockpl     384       64    0       48     2     0     2     2     0     8    0
mcl4k      4096       3    0        0     1     0     1     1     0     8    0
mcl2k      2048      64    0        0     8     0     8     8     0     8    0
mtagpl      80        1    0        0     1     0     1     1     0     8    0
mbufpl     256       92    0        0     5     0     5     5     0     8    0
bufpl      256     2288    0      262   127     0   127   127     0     8    0
anonpl      16    30591    0    29323     8     2     6     6     0   125    0
amapchunkpl 152    1835    0     1790     3     0     3     3     0   158    1
amappl16   192      539    0      523     1     0     1     1     0     8    0
amappl14   176       36    0       32     1     0     1     1     0     8    0
amappl12   160        9    0        9     1     1     0     1     0     8    0
amappl11   152       42    0       31     1     0     1     1     0     8    0
amappl10   144       46    0       46     2     1     1     1     0     8    1
amappl9    136      400    0      399     1     0     1     1     0     8    0
amappl8    128       91    0       83     1     0     1     1     0     8    0
amappl7    120       14    0       13     1     0     1     1     0     8    0
amappl6    112       40    0       36     1     0     1     1     0     8    0
amappl5    104      119    0      110     1     0     1     1     0     8    0
amappl4     96      606    0      581     1     0     1     1     0     8    0
amappl3     88      350    0      336     1     0     1     1     0     8    0
amappl2     80     2355    0     2285     4     2     2     2     0     8    0
amappl1     72    18574    0    18147    14     4    10    14     0     8    0
amappl      80     1146    0     1120     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
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      382    0      367     1     0     1     1     0     8    0
uaddrbest   32        2    0        0     1     0     1     1     0     8    0
uaddr       24      382    0      367     1     0     1     1     0     8    0
vmmpekpl   168     6873    0     6855     1     0     1     1     0     8    0
vmmpepl    168    42685    0    41742    56    13    43    44     0   357    2
vmsppl     368      381    0      367     2     0     2     2     0     8    0
pdppl      4096     772    0      734     5     0     5     5     0     8    0
pvpl        32    98033    0    95021    34     8    26    26     0   265    1
pmappl     232      381    0      367     1     0     1     1     0     8    0
extentpl    40       41    0       26     1     0     1     1     0     8    0
phpool     112      255    0        3     8     0     8     8     0     8    0

Crashes (2):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci-openbsd-setuid 2019/08/13 04:41 openbsd 8c9a8c5f30e0 8620c2c2 .config log report syz C
ci-openbsd-setuid 2019/08/13 03:08 openbsd 8c9a8c5f30e0 8620c2c2 .config log report
* Struck through repros no longer work on HEAD.