syzbot


assert "TAILQ_EMPTY(&lock->lf_blkhd)" failed in vfs_lockf.c (2)

Status: fixed on 2022/06/02 04:10
Reported-by: syzbot+c93afea6c27a3fa3af39@syzkaller.appspotmail.com
Fix commit: ee8a225221fd Fix ambiguity with lock range end
First crash: 189d, last: 189d
similar bugs (1):
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
openbsd assert "TAILQ_EMPTY(&lock->lf_blkhd)" failed in vfs_lockf.c 1 231d 231d 3/3 fixed on 2022/04/28 05:27

Sample crash report:
panic: kernel diagnostic assertion "TAILQ_EMPTY(&lock->lf_blkhd)" failed: file "/syzkaller/managers/multicore/kernel/sys/kern/vfs_lockf.c", line 205
Stopped at      db_enter+0x18:  addq    $0x8,%rsp
    TID    PID    UID     PRFLAGS     PFLAGS  CPU  COMMAND
*248667  45803      0         0x2  0x4000000    1  syz-executor1646560472
 513316  36606      0     0x14000 0x40000200    0  softclock
db_enter() at db_enter+0x18 sys/arch/amd64/amd64/db_interface.c:437
panic(ffffffff8259eac4) at panic+0x177 sys/kern/subr_prf.c:202
__assert(ffffffff82612e18,ffffffff8256ffc8,cd,ffffffff825f2f93) at __assert+0x25 sys/kern/subr_prf.c:161
lf_free(fffffd806f00d820) at lf_free+0xe2 ls_rele sys/kern/vfs_lockf.c:152 [inline]
lf_free(fffffd806f00d820) at lf_free+0xe2 sys/kern/vfs_lockf.c:208
lf_setlock(fffffd806f00d820) at lf_setlock+0xb54
lf_advlock(ffff800000bd5ba0,0,fffffd806f9e35e0,8,ffff8000211d01e0,50) at lf_advlock+0x3a7 sys/kern/vfs_lockf.c:301
VOP_ADVLOCK(fffffd806f2f1168,fffffd806f9e35e0,8,ffff8000211d01e0,50) at VOP_ADVLOCK+0x71 sys/kern/vfs_vops.c:628
sys_fcntl(ffff8000211337a8,ffff8000211d0268,ffff8000211d02c0) at sys_fcntl+0xad9
syscall(ffff8000211d0330) at syscall+0x489 mi_syscall sys/sys/syscall_mi.h:102 [inline]
syscall(ffff8000211d0330) at syscall+0x489 sys/arch/amd64/amd64/trap.c:585
Xsyscall() at Xsyscall+0x128
end of kernel
end trace frame: 0xfe52fd01790, count: 5
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: kernel diagnostic assertion "TAILQ_EMPTY(&lock->lf_blkhd)" failed: file "/syzkaller/managers/multicore/kernel/sys/kern/vfs_lockf.c", line 205
ddb{1}> trace
db_enter() at db_enter+0x18 sys/arch/amd64/amd64/db_interface.c:437
panic(ffffffff8259eac4) at panic+0x177 sys/kern/subr_prf.c:202
__assert(ffffffff82612e18,ffffffff8256ffc8,cd,ffffffff825f2f93) at __assert+0x25 sys/kern/subr_prf.c:161
lf_free(fffffd806f00d820) at lf_free+0xe2 ls_rele sys/kern/vfs_lockf.c:152 [inline]
lf_free(fffffd806f00d820) at lf_free+0xe2 sys/kern/vfs_lockf.c:208
lf_setlock(fffffd806f00d820) at lf_setlock+0xb54
lf_advlock(ffff800000bd5ba0,0,fffffd806f9e35e0,8,ffff8000211d01e0,50) at lf_advlock+0x3a7 sys/kern/vfs_lockf.c:301
VOP_ADVLOCK(fffffd806f2f1168,fffffd806f9e35e0,8,ffff8000211d01e0,50) at VOP_ADVLOCK+0x71 sys/kern/vfs_vops.c:628
sys_fcntl(ffff8000211337a8,ffff8000211d0268,ffff8000211d02c0) at sys_fcntl+0xad9
syscall(ffff8000211d0330) at syscall+0x489 mi_syscall sys/sys/syscall_mi.h:102 [inline]
syscall(ffff8000211d0330) at syscall+0x489 sys/arch/amd64/amd64/trap.c:585
Xsyscall() at Xsyscall+0x128
end of kernel
end trace frame: 0xfe52fd01790, count: -10
ddb{1}> show registers
rdi                                0
rsi                              0x1
rbp               0xffff8000211cfed0
rbx               0xffff800020cd9c5f
rdx                            0x3fd
rcx                                0
rax                             0x95
r8                 0x101010101010101
r9                0x8080808080808080
r10               0x8f59cff0ae48494c
r11               0x4b323472889c2c58
r12               0xffff800020cd9a60
r13                                0
r14                                0
r15                              0x1
rip               0xffffffff8232f328    db_enter+0x18
cs                               0x8
rflags                         0x246
rsp               0xffff8000211cfec0
ss                              0x10
db_enter+0x18:  addq    $0x8,%rsp
ddb{1}> show proc
PROC (syz-executor1646560472) pid=248667 stat=onproc
    flags process=2<EXEC> proc=4000000<THREAD>
    pri=51, usrpri=51, nice=20
    forw=0xffffffffffffffff, list=0xffff800021133508,0xffffffff82a71a88
    process=0xffff8000ffff2150 user=0xffff8000211cb000, vmspace=0xfffffd806ee28cf8
    estcpu=1, cpticks=1, pctcpu=0.0
    user=0, sys=1, intr=0
ddb{1}> ps
   PID     TID   PPID    UID  S       FLAGS  WAIT          COMMAND
 45803  181252   8746      0  2         0x2                syz-executor1646560472
 45803  412490   8746      0  3   0x4000082  lockf         syz-executor1646560472
*45803  248667   8746      0  7   0x4000002                syz-executor1646560472
  8746  428688  85654      0  3    0x10008a  sigsusp       ksh
 85654  361334   6831      0  3        0x9a  kqread        sshd
 82937  443237      1      0  3    0x100083  ttyin         getty
  6831  465766      1      0  3        0x88  kqread        sshd
 38156  297837  94233     74  3   0x1100092  bpf           pflogd
 94233  108865      1      0  3        0x80  netio         pflogd
 25665   46763  48807     73  3   0x1100090  kqread        syslogd
 48807  264616      1      0  3    0x100082  netio         syslogd
 28566    9258      1      0  3    0x100080  kqread        resolvd
 43316  269921  46340     77  3    0x100092  kqread        dhcpleased
 67919  126187  46340     77  3    0x100092  kqread        dhcpleased
 46340   11628      1      0  3        0x80  kqread        dhcpleased
 89739  517763      0      0  3     0x14200  bored         smr
 78840  499733      0      0  3     0x14200  pgzero        zerothread
 76184  108284      0      0  3     0x14200  aiodoned      aiodoned
 82654  166304      0      0  3     0x14200  syncer        update
 60371  207094      0      0  3     0x14200  cleaner       cleaner
  1336  348496      0      0  3     0x14200  reaper        reaper
 33450  131860      0      0  3     0x14200  pgdaemon      pagedaemon
 53770  402640      0      0  3     0x14200  bored         viomb
   484  482512      0      0  3  0x40014200  acpi0         acpi0
 94375  390900      0      0  3  0x40014200                idle1
  8613  461462      0      0  3     0x14200  bored         softnet
 92139  109372      0      0  3     0x14200  bored         softnet
 89291   80560      0      0  3     0x14200  bored         softnet
 21318  245210      0      0  3     0x14200  bored         softnet
 32096  485507      0      0  3     0x14200  bored         systqmp
 87250  282009      0      0  3     0x14200  bored         systq
 36606  513316      0      0  7  0x40014200                softclock
 18575   14753      0      0  3  0x40014200                idle0
     1  353896      0      0  3        0x82  wait          init
     0       0     -1      0  3     0x10200  scheduler     swapper
ddb{1}> show all locks
Process 45803 (syz-executor1646560472) thread 0xffff8000211337a8 (248667)
exclusive rwlock lockflk r = 0 (0xffffffff829ae930)
#0  witness_lock+0x44d
#1  lf_advlock+0x189 sys/kern/vfs_lockf.c:263
#2  VOP_ADVLOCK+0x71 sys/kern/vfs_vops.c:628
#3  sys_fcntl+0xad9
#4  syscall+0x489 mi_syscall sys/sys/syscall_mi.h:102 [inline]
#4  syscall+0x489 sys/arch/amd64/amd64/trap.c:585
#5  Xsyscall+0x128
ddb{1}> show malloc
           Type InUse  MemUse  HighUse   Limit  Requests Type Lim
         devbuf 10153   6455K    6456K  78643K     11243        0
            pcb    13      8K       8K  78643K        13        0
         rtable    58      1K       2K  78643K       108        0
         ifaddr    29      8K       8K  78643K        32        0
       counters    40     33K      33K  78643K        40        0
       ioctlops     0      0K       4K  78643K      1479        0
          mount     1      1K       1K  78643K         1        0
            log     0      0K       0K  78643K         5        0
         vnodes  1167     73K      73K  78643K      1180        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     2      2K       3K  78643K         4        0
           proc    67     91K      91K  78643K       282        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    31    148K     148K  78643K        31        0
           exec     0      0K       2K  78643K       432        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    62      3K       5K  78643K      1559        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   4713K    4777K  78643K      2516        0
         kqueue    11     16K      18K  78643K        24        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      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      312       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    336        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       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     1425    0       39    87     0    87    87     0     8    0
ffsino     272     1425    0       39    93     0    93    93     0     8    0
nchpl      144     1614    0       49    58     0    58    58     0     8    0
uvmvnodes   80     1435    0        0    30     0    30    30     0     8    0
vnodes     224     1435    0        0    85     0    85    85     0     8    0
namei      1024    4476    0     4476     2     1     1     1     0     8    1
percpumem   16       32    0        0     1     0     1     1     0     8    0
kstatmem   264        8    0        0     1     0     1     1     0     8    0
scxspl     216     4067    0     4067    10     4     6     8     0     8    6
plimitpl   152       16    0        9     1     0     1     1     0     8    0
sigapl     424      323    0      291     5     1     4     5     0     8    0
knotepl    120       50    0        0     2     0     2     2     0     8    0
kqueuepl   216       20    0       13     1     0     1     1     0     8    0
pipepl     336       86    0       83     2     1     1     1     0     8    0
fdescpl    496      306    0      291     3     0     3     3     0     8    0
filepl     152     1185    0     1125     3     0     3     3     0     8    0
lockfpl    104       11    0        6     1     0     1     1     0     8    0
lockfspl    48        5    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       72    0       60     1     0     1     1     0     8    0
zombiepl   144      291    0      291     2     1     1     1     0     8    1
processpl  1064     323    0      291     3     0     3     3     0     8    0
procpl     672      325    0      291     4     1     3     4     0     8    0
sockpl     480       84    0       60     5     1     4     4     0     8    0
mcl8k      8192       4    0        0     1     0     1     1     0     8    0
mcl4k      4096       5    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      115    0        0     7     0     7     7     0     8    0
bufpl      288     2021    0       90   138     0   138   138     0     8    0
anonpl      24    39056    0    36911    18     4    14    15     0   186    1
amapchunkpl 152    2868    0     2761     7     2     5     6     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
amappl14   184        1    0        1     1     1     0     1     0     8    0
amappl13   176       34    0       33     2     1     1     1     0     8    0
amappl12   168        3    0        3     2     1     1     1     0     8    1
amappl11   160       66    0       49     1     0     1     1     0     8    0
amappl10   152        3    0        1     1     0     1     1     0     8    0
amappl9    144      497    0      495     1     0     1     1     0     8    0
amappl8    136      365    0      363     2     1     1     1     0     8    0
amappl7    128       52    0       49     1     0     1     1     0     8    0
amappl6    120      106    0       96     1     0     1     1     0     8    0
amappl5    112       91    0       79     1     0     1     1     0     8    0
amappl4    104      629    0      608     1     0     1     1     0     8    0
amappl3     96      398    0      373     1     0     1     1     0     8    0
amappl2     88      454    0      416     1     0     1     1     0     8    0
amappl1     80     9451    0     9025    12     2    10    10     0     8    0
amappl      88     1278    0     1235     2     1     1     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      306    0      291     1     0     1     1     0     8    0
uaddrbest   32        2    0        0     1     0     1     1     0     8    0
uaddr       24      306    0      291     1     0     1     1     0     8    0
vmmpekpl   168     6217    0     6206     1     0     1     1     0     8    0
vmmpepl    168    27089    0    26176    45     3    42    42     0   357    2
vmsppl     368      305    0      291     2     0     2     2     0     8    0
rwobjpl     56     9732    0     7700    30     0    30    30     0     8    0
pdppl      4096     619    0      582    57    20    37    45     0     8    0
pvpl        32   131573    0   127433    43     7    36    36     0   265    2
pmappl     248      305    0      291     2     0     2     2     0     8    0
extentpl    40       58    0       38     1     0     1     1     0     8    0
phpool     112      416    0       25    12     0    12    12     0     8    0
ddb{1}> machine ddbcpu 0
Stopped at      x86_ipi_db+0x1a:        addq    $0x8,%rsp
x86_ipi_db(ffffffff8297aff0) 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(ffffffff82a369e0) at __mp_lock+0x122 __mp_lock_spin sys/kern/kern_lock.c:116 [inline]
__mp_lock(ffffffff82a369e0) at __mp_lock+0x122 sys/kern/kern_lock.c:147
__mp_acquire_count(ffffffff82a369e0,1) at __mp_acquire_count+0x48 sys/kern/kern_lock.c:227
mi_switch() at mi_switch+0x3d3 sys/kern/sched_bsd.c:416
sleep_finish(ffff8000210f5158,1) at sleep_finish+0x180 sys/kern/kern_synch.c:420
softclock_thread(ffff8000210e9500) at softclock_thread+0xd9 sys/kern/kern_timeout.c:797
end trace frame: 0x0, count: 7
ddb{0}> trace
x86_ipi_db(ffffffff8297aff0) 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(ffffffff82a369e0) at __mp_lock+0x122 __mp_lock_spin sys/kern/kern_lock.c:116 [inline]
__mp_lock(ffffffff82a369e0) at __mp_lock+0x122 sys/kern/kern_lock.c:147
__mp_acquire_count(ffffffff82a369e0,1) at __mp_acquire_count+0x48 sys/kern/kern_lock.c:227
mi_switch() at mi_switch+0x3d3 sys/kern/sched_bsd.c:416
sleep_finish(ffff8000210f5158,1) at sleep_finish+0x180 sys/kern/kern_synch.c:420
softclock_thread(ffff8000210e9500) at softclock_thread+0xd9 sys/kern/kern_timeout.c:797
end trace frame: 0x0, count: -8
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:437
panic(ffffffff8259eac4) at panic+0x177 sys/kern/subr_prf.c:202
__assert(ffffffff82612e18,ffffffff8256ffc8,cd,ffffffff825f2f93) at __assert+0x25 sys/kern/subr_prf.c:161
lf_free(fffffd806f00d820) at lf_free+0xe2 ls_rele sys/kern/vfs_lockf.c:152 [inline]
lf_free(fffffd806f00d820) at lf_free+0xe2 sys/kern/vfs_lockf.c:208
lf_setlock(fffffd806f00d820) at lf_setlock+0xb54
lf_advlock(ffff800000bd5ba0,0,fffffd806f9e35e0,8,ffff8000211d01e0,50) at lf_advlock+0x3a7 sys/kern/vfs_lockf.c:301
VOP_ADVLOCK(fffffd806f2f1168,fffffd806f9e35e0,8,ffff8000211d01e0,50) at VOP_ADVLOCK+0x71 sys/kern/vfs_vops.c:628
sys_fcntl(ffff8000211337a8,ffff8000211d0268,ffff8000211d02c0) at sys_fcntl+0xad9
syscall(ffff8000211d0330) at syscall+0x489 mi_syscall sys/sys/syscall_mi.h:102 [inline]
syscall(ffff8000211d0330) at syscall+0x489 sys/arch/amd64/amd64/trap.c:585
Xsyscall() at Xsyscall+0x128
end of kernel
end trace frame: 0xfe52fd01790, count: 5
ddb{1}> trace
db_enter() at db_enter+0x18 sys/arch/amd64/amd64/db_interface.c:437
panic(ffffffff8259eac4) at panic+0x177 sys/kern/subr_prf.c:202
__assert(ffffffff82612e18,ffffffff8256ffc8,cd,ffffffff825f2f93) at __assert+0x25 sys/kern/subr_prf.c:161
lf_free(fffffd806f00d820) at lf_free+0xe2 ls_rele sys/kern/vfs_lockf.c:152 [inline]
lf_free(fffffd806f00d820) at lf_free+0xe2 sys/kern/vfs_lockf.c:208
lf_setlock(fffffd806f00d820) at lf_setlock+0xb54
lf_advlock(ffff800000bd5ba0,0,fffffd806f9e35e0,8,ffff8000211d01e0,50) at lf_advlock+0x3a7 sys/kern/vfs_lockf.c:301
VOP_ADVLOCK(fffffd806f2f1168,fffffd806f9e35e0,8,ffff8000211d01e0,50) at VOP_ADVLOCK+0x71 sys/kern/vfs_vops.c:628
sys_fcntl(ffff8000211337a8,ffff8000211d0268,ffff8000211d02c0) at sys_fcntl+0xad9
syscall(ffff8000211d0330) at syscall+0x489 mi_syscall sys/sys/syscall_mi.h:102 [inline]
syscall(ffff8000211d0330) at syscall+0x489 sys/arch/amd64/amd64/trap.c:585
Xsyscall() at Xsyscall+0x128
end of kernel
end trace frame: 0xfe52fd01790, count: -10
ddb{1}> 

Crashes (2):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci-openbsd-multicore 2022/05/27 06:58 openbsd 12999fd17334 3037caa9 .config log report syz C assert "TAILQ_EMPTY(&lock->lf_blkhd)" failed in vfs_lockf.c
ci-openbsd-multicore 2022/05/27 06:39 openbsd 12999fd17334 3037caa9 .config log report assert "TAILQ_EMPTY(&lock->lf_blkhd)" failed in vfs_lockf.c
* Struck through repros no longer work on HEAD.