possible deadlock in rxrpc_put_peer

[syzbot]

Hello,

syzbot found the following crash on:

HEAD commit: 9a9de33a Linux 4.19.63
git tree: linux-4.19.y
console output: https://syzkaller.appspot.com/x/log.txt?x=149c2ed8600000
kernel config: https://syzkaller.appspot.com/x/.config?x=92b8e10c68c8329
dashboard link: https://syzkaller.appspot.com/bug?extid=f7bec8396c3d1b2b701d
compiler: gcc (GCC) 9.0.0 20181231 (experimental)

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

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

============================================
WARNING: possible recursive locking detected
4.19.63 #37 Not tainted
--------------------------------------------
kworker/0:2/25665 is trying to acquire lock:
0000000098bfadd9 (&(&rxnet->peer_hash_lock)->rlock){+.-.}, at: spin_lock_bh
include/linux/spinlock.h:334 [inline]
0000000098bfadd9 (&(&rxnet->peer_hash_lock)->rlock){+.-.}, at:
__rxrpc_put_peer net/rxrpc/peer_object.c:419 [inline]
0000000098bfadd9 (&(&rxnet->peer_hash_lock)->rlock){+.-.}, at:
rxrpc_put_peer+0x29d/0x660 net/rxrpc/peer_object.c:439

but task is already holding lock:
0000000098bfadd9 (&(&rxnet->peer_hash_lock)->rlock){+.-.}, at: spin_lock_bh
include/linux/spinlock.h:334 [inline]
0000000098bfadd9 (&(&rxnet->peer_hash_lock)->rlock){+.-.}, at:
rxrpc_peer_keepalive_dispatch net/rxrpc/peer_event.c:375 [inline]
0000000098bfadd9 (&(&rxnet->peer_hash_lock)->rlock){+.-.}, at:
rxrpc_peer_keepalive_worker+0x6b3/0xd02 net/rxrpc/peer_event.c:427

other info that might help us debug this:
Possible unsafe locking scenario:

CPU0
----
lock(&(&rxnet->peer_hash_lock)->rlock);
lock(&(&rxnet->peer_hash_lock)->rlock);

*** DEADLOCK ***

May be due to missing lock nesting notation

3 locks held by kworker/0:2/25665:
#0: 0000000089f1f1b1 ((wq_completion)"krxrpcd"){+.+.}, at:
__write_once_size include/linux/compiler.h:220 [inline]
#0: 0000000089f1f1b1 ((wq_completion)"krxrpcd"){+.+.}, at:
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: 0000000089f1f1b1 ((wq_completion)"krxrpcd"){+.+.}, at: atomic64_set
include/asm-generic/atomic-instrumented.h:40 [inline]
#0: 0000000089f1f1b1 ((wq_completion)"krxrpcd"){+.+.}, at: atomic_long_set
include/asm-generic/atomic-long.h:59 [inline]
#0: 0000000089f1f1b1 ((wq_completion)"krxrpcd"){+.+.}, at: set_work_data
kernel/workqueue.c:617 [inline]
#0: 0000000089f1f1b1 ((wq_completion)"krxrpcd"){+.+.}, at:
set_work_pool_and_clear_pending kernel/workqueue.c:644 [inline]
#0: 0000000089f1f1b1 ((wq_completion)"krxrpcd"){+.+.}, at:
process_one_work+0x87e/0x1750 kernel/workqueue.c:2124
#1: 000000006968518a
((work_completion)(&rxnet->peer_keepalive_work)){+.+.}, at:
process_one_work+0x8b4/0x1750 kernel/workqueue.c:2128
#2: 0000000098bfadd9 (&(&rxnet->peer_hash_lock)->rlock){+.-.}, at:
spin_lock_bh include/linux/spinlock.h:334 [inline]
#2: 0000000098bfadd9 (&(&rxnet->peer_hash_lock)->rlock){+.-.}, at:
rxrpc_peer_keepalive_dispatch net/rxrpc/peer_event.c:375 [inline]
#2: 0000000098bfadd9 (&(&rxnet->peer_hash_lock)->rlock){+.-.}, at:
rxrpc_peer_keepalive_worker+0x6b3/0xd02 net/rxrpc/peer_event.c:427

stack backtrace:
CPU: 0 PID: 25665 Comm: kworker/0:2 Not tainted 4.19.63 #37
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
Workqueue: krxrpcd rxrpc_peer_keepalive_worker
Call Trace:
__dump_stack lib/dump_stack.c:77 [inline]
dump_stack+0x172/0x1f0 lib/dump_stack.c:113
print_deadlock_bug kernel/locking/lockdep.c:1759 [inline]
check_deadlock kernel/locking/lockdep.c:1803 [inline]
validate_chain kernel/locking/lockdep.c:2399 [inline]
__lock_acquire.cold+0x20f/0x4a7 kernel/locking/lockdep.c:3411
lock_acquire+0x16f/0x3f0 kernel/locking/lockdep.c:3900
__raw_spin_lock_bh include/linux/spinlock_api_smp.h:135 [inline]
_raw_spin_lock_bh+0x33/0x50 kernel/locking/spinlock.c:168
spin_lock_bh include/linux/spinlock.h:334 [inline]
__rxrpc_put_peer net/rxrpc/peer_object.c:419 [inline]
rxrpc_put_peer+0x29d/0x660 net/rxrpc/peer_object.c:439
rxrpc_peer_keepalive_dispatch net/rxrpc/peer_event.c:378 [inline]
rxrpc_peer_keepalive_worker+0x7a6/0xd02 net/rxrpc/peer_event.c:427
process_one_work+0x989/0x1750 kernel/workqueue.c:2153
worker_thread+0x98/0xe40 kernel/workqueue.c:2296
kthread+0x354/0x420 kernel/kthread.c:246
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415
net_ratelimit: 28 callbacks suppressed
protocol 88fb is buggy, dev hsr_slave_0
protocol 88fb is buggy, dev hsr_slave_1
protocol 88fb is buggy, dev hsr_slave_0
protocol 88fb is buggy, dev hsr_slave_1
kauditd_printk_skb: 60 callbacks suppressed
audit: type=1400 audit(1564662409.995:19423): avc: denied { map } for
pid=31972 comm="blkid" path="/lib/x86_64-linux-gnu/ld-2.13.so" dev="sda1"
ino=2668 scontext=system_u:system_r:kernel_t:s0
tcontext=system_u:object_r:file_t:s0 tclass=file permissive=1
protocol 88fb is buggy, dev hsr_slave_0
protocol 88fb is buggy, dev hsr_slave_1
audit: type=1400 audit(1564662410.044:19424): avc: denied { write } for
pid=31965 comm="syz-executor.1"
scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023
tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023
tclass=netlink_generic_socket permissive=1
kobject: 'loop0' (00000000c6c2bb09): kobject_uevent_env
kobject: 'loop0' (00000000c6c2bb09): fill_kobj_path: path
= '/devices/virtual/block/loop0'
protocol 88fb is buggy, dev hsr_slave_0
protocol 88fb is buggy, dev hsr_slave_1
audit: type=1400 audit(1564662410.054:19425): avc: denied { map } for
pid=31972 comm="blkid" path="/lib/x86_64-linux-gnu/ld-2.13.so" dev="sda1"
ino=2668 scontext=system_u:system_r:kernel_t:s0
tcontext=system_u:object_r:file_t:s0 tclass=file permissive=1
protocol 88fb is buggy, dev hsr_slave_0
protocol 88fb is buggy, dev hsr_slave_1
kobject: 'loop5' (00000000a69ae2b5): kobject_uevent_env
kobject: 'loop5' (00000000a69ae2b5): fill_kobj_path: path
= '/devices/virtual/block/loop5'
audit: type=1400 audit(1564662410.590:19426): avc: denied { create } for
pid=31988 comm="syz-executor.1"
scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023
tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023
tclass=netlink_generic_socket permissive=1
kobject: 'loop4' (000000004dc6a859): kobject_uevent_env
audit: type=1400 audit(1564662410.600:19427): avc: denied { write } for
pid=31988 comm="syz-executor.1"
scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023
tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023
tclass=netlink_generic_socket permissive=1
kobject: 'loop4' (000000004dc6a859): fill_kobj_path: path
= '/devices/virtual/block/loop4'
audit: type=1400 audit(1564662410.719:19428): avc: denied { map } for
pid=31993 comm="blkid" path="/sbin/blkid" dev="sda1" ino=16128
scontext=system_u:system_r:kernel_t:s0 tcontext=system_u:object_r:file_t:s0
tclass=file permissive=1
audit: type=1400 audit(1564662410.788:19429): avc: denied { map } for
pid=31993 comm="blkid" path="/lib/x86_64-linux-gnu/libc-2.13.so" dev="sda1"
ino=2784 scontext=system_u:system_r:kernel_t:s0
tcontext=system_u:object_r:file_t:s0 tclass=file permissive=1
kobject: 'loop5' (00000000a69ae2b5): kobject_uevent_env
kobject: 'loop5' (00000000a69ae2b5): fill_kobj_path: path
= '/devices/virtual/block/loop5'
audit: type=1400 audit(1564662411.363:19430): avc: denied { map } for
pid=32004 comm="blkid" path="/sbin/blkid" dev="sda1" ino=16128
scontext=system_u:system_r:kernel_t:s0 tcontext=system_u:object_r:file_t:s0
tclass=file permissive=1
kobject: 'loop4' (000000004dc6a859): kobject_uevent_env
kobject: 'loop4' (000000004dc6a859): fill_kobj_path: path
= '/devices/virtual/block/loop4'
audit: type=1400 audit(1564662411.383:19431): avc: denied { map } for
pid=32004 comm="blkid" path="/lib/x86_64-linux-gnu/libblkid.so.1.1.0"
dev="sda1" ino=2825 scontext=system_u:system_r:kernel_t:s0
tcontext=system_u:object_r:file_t:s0 tclass=file permissive=1
kobject: 'loop5' (00000000a69ae2b5): kobject_uevent_env
kobject: 'loop5' (00000000a69ae2b5): fill_kobj_path: path
= '/devices/virtual/block/loop5'
audit: type=1400 audit(1564662411.423:19432): avc: denied { map } for
pid=32004 comm="blkid" path="/lib/x86_64-linux-gnu/libc-2.13.so" dev="sda1"
ino=2784 scontext=system_u:system_r:kernel_t:s0
tcontext=system_u:object_r:file_t:s0 tclass=file permissive=1
kobject: 'loop0' (00000000c6c2bb09): kobject_uevent_env
kobject: 'loop0' (00000000c6c2bb09): fill_kobj_path: path
= '/devices/virtual/block/loop0'
kobject: 'loop4' (000000004dc6a859): kobject_uevent_env
kobject: 'loop4' (000000004dc6a859): fill_kobj_path: path
= '/devices/virtual/block/loop4'
kobject: 'loop5' (00000000a69ae2b5): kobject_uevent_env
kobject: 'loop5' (00000000a69ae2b5): fill_kobj_path: path
= '/devices/virtual/block/loop5'
net_ratelimit: 22 callbacks suppressed
protocol 88fb is buggy, dev hsr_slave_0
protocol 88fb is buggy, dev hsr_slave_1
protocol 88fb is buggy, dev hsr_slave_0
protocol 88fb is buggy, dev hsr_slave_1
protocol 88fb is buggy, dev hsr_slave_0
protocol 88fb is buggy, dev hsr_slave_1
protocol 88fb is buggy, dev hsr_slave_0
protocol 88fb is buggy, dev hsr_slave_1
protocol 88fb is buggy, dev hsr_slave_0
protocol 88fb is buggy, dev hsr_slave_1


---
This bug 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 bug report. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.

[syzbot]

Auto-closing this bug as obsolete.
Crashes did not happen for a while, no reproducer and no activity.