witness: reversal: sbufsnd inode (4)

[syzbot]

Hello,

syzbot found the following issue on:

HEAD commit: 19a8be4fa5c4 Use the real sc address for tsleep identifica..
git tree: openbsd
console output: https://syzkaller.appspot.com/x/log.txt?x=128ec2a6580000
kernel config: https://syzkaller.appspot.com/x/.config?x=7058272de1526588
dashboard link: https://syzkaller.appspot.com/bug?extid=de15d066c25df21a5697

Unfortunately, I don't have any reproducer for this issue yet.

Downloadable assets:
disk image: https://storage.googleapis.com/syzbot-assets/7f78283d303a/disk-19a8be4f.raw.xz
bsd.gdb: https://storage.googleapis.com/syzbot-assets/856b3562db71/bsd-19a8be4f.gdb.xz
kernel image: https://storage.googleapis.com/syzbot-assets/55c6c5e8b346/kernel-19a8be4f.xz

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+de15d0...@syzkaller.appspotmail.com

pf: key search, in on vio0: TCPwitness: wire: (0) lock order reversal:
10.128.15.235 1st 0xffff800010fdf388 sbufsnd (&so->so_snd.sb_lock)
:30002 2nd 0xfffffd80757b3a50 inode (&ip->i_lock)
10.128.0.133lock order [1] sbufsnd (&so->so_snd.sb_lock) -> [2] inode (&ip->i_lock)
:8698lock order data 0xffffffff8351aafa -> 0xffffffff8348b191 is missing

lock order [2] inode (&ip->i_lock) -> [3] sbufrcv (&so->so_rcv.sb_lock)
pf: key search, in on vio0: #0 TCP wire: (0) 10.128.15.235:30002 10.128.0.133:8698
pf: key search, out on vio0: TCP wire: (0) 10.128.15.235:30002 10.128.0.133:8698
rw_do_enter_write+0xba
#1 sblock+0xb6 sys/kern/uipc_socket2.c:536
#2 soreceive+0x27d sys/kern/uipc_socket.c:890
#3 fifo_read+0x117 sys/miscfs/fifofs/fifo_vnops.c:264
#4 VOP_READ+0x101 sys/kern/vfs_vops.c:227
#5 vn_rdwr+0x15b sys/kern/vfs_vnops.c:-1
#6 vndsetcred+0xa1 sys/dev/vnd.c:685
#7 vndioctl+0xdfc sys/dev/vnd.c:486
#8 VOP_IOCTL+0xac sys/kern/vfs_vops.c:264
#9 vn_ioctl+0xf8 sys/kern/vfs_vnops.c:537
#10 sys_ioctl+0x674 sys/kern/sys_generic.c:-1
#11 syscall+0xbd4 mi_syscall sys/sys/syscall_mi.h:176 [inline]
#11 syscall+0xbd4 sys/arch/amd64/amd64/trap.c:783
#12 Xsyscall+0x128
lock order [3] sbufrcv (&so->so_rcv.sb_lock) -> [1] sbufsnd (&so->so_snd.sb_lock)
#0 rw_do_enter_write+0xba sys/kern/kern_rwlock.c:234
#1 sblock+0xb6 sys/kern/uipc_socket2.c:536
#2 sosplice+0x312 sys/kern/uipc_socket.c:1347
#3 sys_setsockopt+0x2ba sys/kern/uipc_syscalls.c:1226
#4 syscall+0xbd4 mi_syscall sys/sys/syscall_mi.h:176 [inline]
#4 syscall+0xbd4 sys/arch/amd64/amd64/trap.c:783
#5 Xsyscall+0x128
Stopped at db_enter+0x25: addq $0x8,%rsp
ddb{0}>
ddb{0}> set $lines = 0
ddb{0}> set $maxwidth = 0
ddb{0}> show panic
the kernel did not panic
ddb{0}> trace
db_enter() at db_enter+0x25 sys/arch/amd64/amd64/db_interface.c:438
witness_checkorder(fffffd80757b3a50,9,0) at witness_checkorder+0x10d1 sys/kern/subr_witness.c:-1
rw_do_enter_write(fffffd80757b3a38,1) at rw_do_enter_write+0xba sys/kern/kern_rwlock.c:234
rrw_enter(fffffd80757b3a38,1) at rrw_enter+0xc6 sys/kern/kern_rwlock.c:621
VOP_LOCK(fffffd806ebf9bd0,2001) at VOP_LOCK+0xbd sys/kern/vfs_vops.c:527
vn_lock(fffffd806ebf9bd0,2001) at vn_lock+0xa4 sys/kern/vfs_vnops.c:576
vfs_lookup(ffff800030f8b330) at vfs_lookup+0x12b sys/kern/vfs_lookup.c:431
namei(ffff800030f8b330) at namei+0x7c5 sys/kern/vfs_lookup.c:250
unp_connect(ffff800010fdf1a0,fffffd806a767900,ffff8000fffef770) at unp_connect+0x29d sys/kern/uipc_usrreq.c:872
uipc_dgram_send(ffff800010fdf1a0,fffffd806c581800,fffffd806a767900,0) at uipc_dgram_send+0x163 sys/kern/uipc_usrreq.c:609
sosend(ffff800010fdf1a0,fffffd806a767900,ffff800030f8b5b8,0,0,0) at sosend+0x804 sys/kern/uipc_socket.c:-1
sendit(ffff8000fffef770,3,ffff800030f8b738,0,ffff800030f8b7f0) at sendit+0x5a5 sys/kern/uipc_syscalls.c:785
sys_sendmsg(ffff8000fffef770,ffff800030f8b8a0,ffff800030f8b7f0) at sys_sendmsg+0x246 sys/kern/uipc_syscalls.c:603
syscall(ffff800030f8b8a0) at syscall+0xbd4 mi_syscall sys/sys/syscall_mi.h:176 [inline]
syscall(ffff800030f8b8a0) at syscall+0xbd4 sys/arch/amd64/amd64/trap.c:783
Xsyscall() at Xsyscall+0x128
end of kernel
end trace frame: 0xbb82d6d62f0, count: -15
ddb{0}> show registers
rdi 0
rsi 0x80000 acpi_pdirpa+0x6be71
rbp 0xffff800030f8afa0
rbx 0
rdx 0xffff8000015d1e40
rcx 0xffff8000fffef770
rax 0x7ffff acpi_pdirpa+0x6be70
r8 0xffff800030f8ae80
r9 0x8080808080808080
r10 0x765d39894906a44
r11 0x9597640393e55757
r12 0xfffffd80040bd8c0
r13 0xfffffd80048a5f00
r14 0x3
r15 0xffffffff835277b3 substchar+0xbde8
rip 0xffffffff82e5bf15 db_enter+0x25
cs 0x8
rflags 0x246
rsp 0xffff800030f8af90
ss 0x10
db_enter+0x25: addq $0x8,%rsp
ddb{0}> show proc
PROC (syz-executor) tid=257671 pid=5839 tcnt=2 stat=onproc
flags process=10<SUGID> proc=4000000<THREAD>
runpri=32, usrpri=50, slppri=32, nice=20
wchan=0x0, wmesg=, ps_single=0x0 scnt=0 ecnt=0
forw=0xffffffffffffffff, list=0xffff8000fffee7e0,0xffffffff83af0ad0
process=0xffff80002a37d358 user=0xffff800030f86000, vmspace=0xfffffd806f33d1f0
estcpu=36, cpticks=1, pctcpu=0.0, user=0, sys=1, intr=0
ddb{0}> ps
PID TID PPID UID S FLAGS WAIT COMMAND
5839 508903 31887 60929 2 0x10 syz-executor
* 5839 257671 31887 60929 7 0x4000010 syz-executor
11370 379394 79994 0 2 0 syz-executor
11370 373044 79994 0 3 0x4000080 fsleep syz-executor
11370 408598 79994 0 3 0x4000080 fsleep syz-executor
15482 452051 49264 0 3 0x80 nanoslp syz-executor
15482 473467 49264 0 3 0x4000000 smrbar syz-executor
15482 42787 49264 0 3 0x4000080 fsleep syz-executor
28153 237327 34044 0 2 0 syz-executor
28153 182754 34044 0 3 0x4000080 fsleep syz-executor
83082 514930 1 0 3 0x82 nanoslp getty
63486 121672 79586 0 2 0xc80 syz-executor
63486 419562 79586 0 3 0x4000080 ttyin syz-executor
40202 22410 82138 0 2 0 syz-executor
40202 384027 82138 0 3 0x4000080 kqread syz-executor
40202 34287 82138 0 3 0x4000080 fsleep syz-executor
34530 61293 0 0 3 0x14280 nfsidl nfsio
87495 61108 0 0 3 0x14280 nfsidl nfsio
54600 170733 0 0 3 0x14280 nfsidl nfsio
11356 386494 0 0 3 0x14280 nfsidl nfsio
47477 159668 0 0 3 0x14280 nfsidl nfsio
44318 160806 0 0 3 0x14280 nfsidl nfsio
35926 345533 0 0 3 0x14280 nfsidl nfsio
15327 311872 0 0 3 0x14280 nfsidl nfsio
83458 156457 0 0 3 0x14280 nfsidl nfsio
51550 248135 0 0 3 0x14280 nfsidl nfsio
7193 481682 0 0 3 0x14280 nfsidl nfsio
83004 51855 0 0 3 0x14280 nfsidl nfsio
39735 471039 0 0 3 0x14280 nfsidl nfsio
99945 260461 0 0 3 0x14280 nfsidl nfsio
63478 76317 0 0 3 0x14280 nfsidl nfsio
34289 380343 0 0 3 0x14280 nfsidl nfsio
43266 124007 0 0 3 0x14280 nfsidl nfsio
61191 303341 0 0 3 0x14280 nfsidl nfsio
41336 368140 0 0 3 0x14280 nfsidl nfsio
20904 405035 0 0 3 0x14280 nfsidl nfsio
42870 297742 0 0 3 0x14200 acct acct
79586 130439 53230 0 3 0x82 nanoslp syz-executor
79994 70097 53230 0 3 0x82 nanoslp syz-executor
34044 522929 53230 0 3 0x82 nanoslp syz-executor
49264 52624 53230 0 3 0x82 nanoslp syz-executor
82138 464299 53230 0 2 0xc82 syz-executor
31887 136289 53230 0 3 0x82 nanoslp syz-executor
92004 483631 53230 0 2 0x2 syz-executor
26117 316094 53230 0 7 0x2 syz-executor
53230 115795 1 0 2 0x82 syz-executor
11822 301756 0 0 3 0x14200 pause smr
11651 185842 0 0 2 0x14200 zerothread
95572 124026 0 0 3 0x14200 aiodoned aiodoned
79810 227231 0 0 3 0x14200 syncer update
81435 168920 0 0 3 0x14200 cleaner cleaner
58267 256118 0 0 3 0x14200 reaper reaper
43797 359160 0 0 3 0x14200 pgdaemon pagedaemon
74369 347062 0 0 3 0x14200 bored viomb
44429 55871 0 0 3 0x40014200 acpi0 acpi0
89079 176647 0 0 3 0x40014200 idle1
49103 371290 0 0 3 0x14200 bored softnet1
4555 302966 0 0 3 0x14200 bored softnet0
40950 364538 0 0 3 0x14200 bored systqmp
3355 376453 0 0 3 0x14200 bored systq
75649 417573 0 0 3 0x14200 tmoslp softclockmp
81529 201906 0 0 3 0x40014200 tmoslp softclock
43302 448844 0 0 3 0x40014200 idle0
1 479061 0 0 3 0x82 wait init
0 0 -1 0 3 0x10200 scheduler swapper
ddb{0}> show all locks
Process 5839 (syz-executor) thread 0xffff8000fffef770 (257671)
exclusive kernel_lock &kernel_lock r = 0 (0xffffffff83aaab00)
#0 witness_lock+0x5f1 stacktrace_save sys/sys/stacktrace.h:37 [inline]
#0 witness_lock+0x5f1 sys/kern/subr_witness.c:1160
#1 unp_connect+0x28c sys/kern/uipc_usrreq.c:872
#2 uipc_dgram_send+0x163 sys/kern/uipc_usrreq.c:609
#3 sosend+0x804 sys/kern/uipc_socket.c:-1
#4 sendit+0x5a5 sys/kern/uipc_syscalls.c:785
#5 sys_sendmsg+0x246 sys/kern/uipc_syscalls.c:603
#6 syscall+0xbd4 mi_syscall sys/sys/syscall_mi.h:176 [inline]
#6 syscall+0xbd4 sys/arch/amd64/amd64/trap.c:783
#7 Xsyscall+0x128
exclusive rwlock sbufsnd r = 0 (0xffff800010fdf388)
#0 witness_lock+0x5f1 stacktrace_save sys/sys/stacktrace.h:37 [inline]
#0 witness_lock+0x5f1 sys/kern/subr_witness.c:1160
#1 rw_do_enter_write+0x419 sys/kern/kern_rwlock.c:320
#2 sblock+0xb6 sys/kern/uipc_socket2.c:536
#3 sosend+0x2e9 sys/kern/uipc_socket.c:639
#4 sendit+0x5a5 sys/kern/uipc_syscalls.c:785
#5 sys_sendmsg+0x246 sys/kern/uipc_syscalls.c:603
#6 syscall+0xbd4 mi_syscall sys/sys/syscall_mi.h:176 [inline]
#6 syscall+0xbd4 sys/arch/amd64/amd64/trap.c:783
#7 Xsyscall+0x128
Process 92004 (syz-executor) thread 0xffff80002a2227d8 (483631)
exclusive rrwlock inode r = 0 (0xfffffd8074e84668)
#0 witness_lock+0x5f1 stacktrace_save sys/sys/stacktrace.h:37 [inline]
#0 witness_lock+0x5f1 sys/kern/subr_witness.c:1160
#1 rw_do_enter_write+0x419 sys/kern/kern_rwlock.c:320
#2 rrw_enter+0xc6 sys/kern/kern_rwlock.c:621
#3 VOP_LOCK+0xbd sys/kern/vfs_vops.c:527
#4 vn_lock+0xa4 sys/kern/vfs_vnops.c:576
#5 vget+0x2a2 sys/kern/vfs_subr.c:686
#6 cache_lookup+0x351 sys/kern/vfs_cache.c:222
#7 ufs_lookup+0x1e3 sys/ufs/ufs/ufs_lookup.c:160
#8 VOP_LOOKUP+0x6e sys/kern/vfs_vops.c:85
#9 vfs_lookup+0x963 sys/kern/vfs_lookup.c:580
#10 namei+0x7c5 sys/kern/vfs_lookup.c:250
#11 dounlinkat+0xc1 sys/kern/vfs_syscalls.c:1893
#12 syscall+0xb17 mi_syscall sys/sys/syscall_mi.h:176 [inline]
#12 syscall+0xb17 sys/arch/amd64/amd64/trap.c:783
#13 Xsyscall+0x128
Process 26117 (syz-executor) thread 0xffff8000ffffd760 (316094)
exclusive rrwlock inode r = 0 (0xfffffd80757b3ef0)
#0 witness_lock+0x5f1 stacktrace_save sys/sys/stacktrace.h:37 [inline]
#0 witness_lock+0x5f1 sys/kern/subr_witness.c:1160
#1 rw_do_enter_write+0x419 sys/kern/kern_rwlock.c:320
#2 rrw_enter+0xc6 sys/kern/kern_rwlock.c:621
#3 VOP_LOCK+0xbd sys/kern/vfs_vops.c:527
#4 ufs_ihashins+0x4f ufs_ihash sys/ufs/ufs/ufs_ihash.c:-1 [inline]
#4 ufs_ihashins+0x4f sys/ufs/ufs/ufs_ihash.c:159
#5 ffs_vget+0x187 sys/ufs/ffs/ffs_vfsops.c:1232
#6 ffs_inode_alloc+0x279 sys/ufs/ffs/ffs_alloc.c:393
#7 ufs_mkdir+0xfc sys/ufs/ufs/ufs_vnops.c:1112
#8 VOP_MKDIR+0x101 sys/kern/vfs_vops.c:394
#9 domkdirat+0x179 sys/kern/vfs_syscalls.c:3149
#10 syscall+0xb17 mi_syscall sys/sys/syscall_mi.h:176 [inline]
#10 syscall+0xb17 sys/arch/amd64/amd64/trap.c:783
#11 Xsyscall+0x128
exclusive rrwlock inode r = 0 (0xfffffd80758a50b0)
#0 witness_lock+0x5f1 stacktrace_save sys/sys/stacktrace.h:37 [inline]
#0 witness_lock+0x5f1 sys/kern/subr_witness.c:1160
#1 rw_do_enter_write+0x419 sys/kern/kern_rwlock.c:320
#2 rrw_enter+0xc6 sys/kern/kern_rwlock.c:621
#3 VOP_LOCK+0xbd sys/kern/vfs_vops.c:527
#4 vn_lock+0xa4 sys/kern/vfs_vnops.c:576
#5 vfs_lookup+0x12b sys/kern/vfs_lookup.c:431
#6 namei+0x7c5 sys/kern/vfs_lookup.c:250
#7 domkdirat+0x8b sys/kern/vfs_syscalls.c:3134
#8 syscall+0xb17 mi_syscall sys/sys/syscall_mi.h:176 [inline]
#8 syscall+0xb17 sys/arch/amd64/amd64/trap.c:783
#9 Xsyscall+0x128
ddb{0}>


---
This report is generated by a bot. It may contain errors.
See https://goo.gl/tpsmEJ for more information about syzbot.
syzbot engineers can be reached at syzk...@googlegroups.com.

syzbot will keep track of this issue. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.

If the report is already addressed, let syzbot know by replying with:
#syz fix: exact-commit-title

If you want to overwrite report's subsystems, reply with:
#syz set subsystems: new-subsystem
(See the list of subsystem names on the web dashboard)

If the report is a duplicate of another one, reply with:
#syz dup: exact-subject-of-another-report

If you want to undo deduplication, reply with:
#syz undup