================================ WARNING: inconsistent lock state 4.14.180-syzkaller #0 Not tainted -------------------------------- inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage. syz-executor.1/6370 [HC0[0]:SC1[1]:HE1:SE0] takes: (rxrpc_conn_id_lock){+.?.}, at: [] spin_lock include/linux/spinlock.h:317 [inline] (rxrpc_conn_id_lock){+.?.}, at: [] rxrpc_put_client_connection_id.part.0+0x15/0x70 net/rxrpc/conn_client.c:143 {SOFTIRQ-ON-W} state was registered at: lock_acquire+0x170/0x3f0 kernel/locking/lockdep.c:3998 __raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline] _raw_spin_lock+0x2a/0x40 kernel/locking/spinlock.c:152 spin_lock include/linux/spinlock.h:317 [inline] rxrpc_get_client_connection_id net/rxrpc/conn_client.c:114 [inline] rxrpc_alloc_client_connection net/rxrpc/conn_client.c:198 [inline] rxrpc_get_client_conn net/rxrpc/conn_client.c:342 [inline] rxrpc_connect_call+0x7eb/0x3e50 net/rxrpc/conn_client.c:692 rxrpc_new_client_call+0x8d2/0x1410 net/rxrpc/call_object.c:276 rxrpc_new_client_call_for_sendmsg net/rxrpc/sendmsg.c:525 [inline] rxrpc_do_sendmsg+0x8a1/0x1019 net/rxrpc/sendmsg.c:577 rxrpc_sendmsg+0x47d/0x5a0 net/rxrpc/af_rxrpc.c:543 sock_sendmsg_nosec net/socket.c:646 [inline] sock_sendmsg+0xc5/0x100 net/socket.c:656 ___sys_sendmsg+0x349/0x840 net/socket.c:2062 __sys_sendmmsg+0x129/0x330 net/socket.c:2152 SYSC_sendmmsg net/socket.c:2183 [inline] SyS_sendmmsg+0x2f/0x50 net/socket.c:2178 do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292 entry_SYSCALL_64_after_hwframe+0x42/0xb7 irq event stamp: 23928300 hardirqs last enabled at (23928300): [] __raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:160 [inline] hardirqs last enabled at (23928300): [] _raw_spin_unlock_irqrestore+0x67/0xe0 kernel/locking/spinlock.c:192 hardirqs last disabled at (23928299): [] __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:108 [inline] hardirqs last disabled at (23928299): [] _raw_spin_lock_irqsave+0x66/0xbf kernel/locking/spinlock.c:160 softirqs last enabled at (23928018): [] __do_softirq+0x664/0x9bf kernel/softirq.c:314 softirqs last disabled at (23928275): [] invoke_softirq kernel/softirq.c:368 [inline] softirqs last disabled at (23928275): [] irq_exit+0x15b/0x1a0 kernel/softirq.c:409 other info that might help us debug this: Possible unsafe locking scenario: CPU0 ---- lock(rxrpc_conn_id_lock); lock(rxrpc_conn_id_lock); *** DEADLOCK *** 1 lock held by syz-executor.1/6370: #0: (rcu_callback){....}, at: [] __rcu_reclaim kernel/rcu/rcu.h:185 [inline] #0: (rcu_callback){....}, at: [] rcu_do_batch kernel/rcu/tree.c:2699 [inline] #0: (rcu_callback){....}, at: [] invoke_rcu_callbacks kernel/rcu/tree.c:2962 [inline] #0: (rcu_callback){....}, at: [] __rcu_process_callbacks kernel/rcu/tree.c:2929 [inline] #0: (rcu_callback){....}, at: [] rcu_process_callbacks+0x866/0x1190 kernel/rcu/tree.c:2946 stack backtrace: CPU: 0 PID: 6370 Comm: syz-executor.1 Not tainted 4.14.180-syzkaller #0 Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 Call Trace: __dump_stack lib/dump_stack.c:17 [inline] dump_stack+0x13e/0x194 lib/dump_stack.c:58 print_usage_bug.cold+0x327/0x425 kernel/locking/lockdep.c:2589 valid_state kernel/locking/lockdep.c:2602 [inline] mark_lock_irq kernel/locking/lockdep.c:2796 [inline] mark_lock+0xd21/0x10b0 kernel/locking/lockdep.c:3194 mark_irqflags kernel/locking/lockdep.c:3072 [inline] __lock_acquire+0xb57/0x4620 kernel/locking/lockdep.c:3448 lock_acquire+0x170/0x3f0 kernel/locking/lockdep.c:3998 __raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline] _raw_spin_lock+0x2a/0x40 kernel/locking/spinlock.c:152 spin_lock include/linux/spinlock.h:317 [inline] rxrpc_put_client_connection_id.part.0+0x15/0x70 net/rxrpc/conn_client.c:143 rxrpc_put_client_connection_id include/linux/spinlock.h:358 [inline] rxrpc_put_one_client_conn net/rxrpc/conn_client.c:912 [inline] rxrpc_put_client_conn+0x550/0xa80 net/rxrpc/conn_client.c:957 rxrpc_put_connection net/rxrpc/ar-internal.h:862 [inline] rxrpc_rcu_destroy_call+0x83/0x190 net/rxrpc/call_object.c:642 __rcu_reclaim kernel/rcu/rcu.h:195 [inline] rcu_do_batch kernel/rcu/tree.c:2699 [inline] invoke_rcu_callbacks kernel/rcu/tree.c:2962 [inline] __rcu_process_callbacks kernel/rcu/tree.c:2929 [inline] rcu_process_callbacks+0x792/0x1190 kernel/rcu/tree.c:2946 __do_softirq+0x254/0x9bf kernel/softirq.c:288 invoke_softirq kernel/softirq.c:368 [inline] irq_exit+0x15b/0x1a0 kernel/softirq.c:409 exiting_irq arch/x86/include/asm/apic.h:648 [inline] smp_apic_timer_interrupt+0x141/0x5e0 arch/x86/kernel/apic/apic.c:1102 apic_timer_interrupt+0x8f/0xa0 arch/x86/entry/entry_64.S:792 RIP: 0010:__raw_spin_unlock_irq include/linux/spinlock_api_smp.h:169 [inline] RIP: 0010:_raw_spin_unlock_irq+0x50/0x80 kernel/locking/spinlock.c:200 RSP: 0018:ffff8880591d7bb0 EFLAGS: 00000282 ORIG_RAX: ffffffffffffff10 RAX: 1ffffffff0fa2cd3 RBX: ffff8880591ca440 RCX: 0000000000000000 RDX: dffffc0000000000 RSI: 0000000000000001 RDI: ffff8880591cacc4 RBP: ffff8880aea2b540 R08: 0000000000000001 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000000 R12: ffff8880aea2b540 R13: ffff88800095c500 R14: 0000000000000000 R15: ffff8880591ca8dc finish_lock_switch kernel/sched/sched.h:1352 [inline] finish_task_switch+0x178/0x620 kernel/sched/core.c:2675 context_switch kernel/sched/core.c:2811 [inline] __schedule+0x7c0/0x1ca0 kernel/sched/core.c:3384 schedule+0x8d/0x1b0 kernel/sched/core.c:3428 freezable_schedule include/linux/freezer.h:172 [inline] do_nanosleep+0x1d7/0x5e0 kernel/time/hrtimer.c:1483 hrtimer_nanosleep+0x1e8/0x460 kernel/time/hrtimer.c:1537 SYSC_nanosleep kernel/time/hrtimer.c:1569 [inline] SyS_nanosleep+0x116/0x170 kernel/time/hrtimer.c:1556 do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292 entry_SYSCALL_64_after_hwframe+0x42/0xb7 RIP: 0033:0x45af30 RSP: 002b:00007ffecdb21e28 EFLAGS: 00000246 ORIG_RAX: 0000000000000023 RAX: ffffffffffffffda RBX: 00000000001b212a RCX: 000000000045af30 RDX: 0000000000000000 RSI: 0000000000000000 RDI: 00007ffecdb21e30 RBP: 0000000000001eb4 R08: 0000000000000001 R09: 0000000001716940 R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000 R13: 00007ffecdb21e80 R14: 00000000001b212a R15: 00007ffecdb21e90 overlayfs: fs on 'file0' does not support file handles, falling back to index=off. audit: type=1804 audit(1589626488.838:14127): pid=19493 uid=0 auid=0 ses=4 subj=system_u:system_r:kernel_t:s0 op="invalid_pcr" cause="open_writers" comm="syz-executor.3" name="/root/syzkaller-testdir017989036/syzkaller.i2GbW0/2223/file0" dev="sda1" ino=16804 res=1 nla_parse: 3 callbacks suppressed netlink: 8 bytes leftover after parsing attributes in process `syz-executor.1'. IPv6: ADDRCONF(NETDEV_CHANGE): vcan0: link becomes ready IPv6: ADDRCONF(NETDEV_CHANGE): vxcan0: link becomes ready IPv6: ADDRCONF(NETDEV_CHANGE): vxcan1: link becomes ready netlink: 8 bytes leftover after parsing attributes in process `syz-executor.1'. IPv6: ADDRCONF(NETDEV_CHANGE): vcan0: link becomes ready IPv6: ADDRCONF(NETDEV_CHANGE): vxcan0: link becomes ready IPv6: ADDRCONF(NETDEV_CHANGE): vxcan1: link becomes ready audit: type=1804 audit(1589626491.828:14128): pid=19524 uid=0 auid=0 ses=4 subj=system_u:system_r:kernel_t:s0 op="invalid_pcr" cause="open_writers" comm="syz-executor.3" name="/root/syzkaller-testdir017989036/syzkaller.i2GbW0/2224/file0" dev="sda1" ino=17393 res=1 audit: type=1804 audit(1589626492.648:14129): pid=19564 uid=0 auid=0 ses=4 subj=system_u:system_r:kernel_t:s0 op="invalid_pcr" cause="open_writers" comm="syz-executor.3" name="/root/syzkaller-testdir017989036/syzkaller.i2GbW0/2225/file0" dev="sda1" ino=17391 res=1 netlink: 12 bytes leftover after parsing attributes in process `syz-executor.0'. audit: type=1804 audit(1589626492.938:14130): pid=19601 uid=0 auid=0 ses=4 subj=system_u:system_r:kernel_t:s0 op="invalid_pcr" cause="open_writers" comm="syz-executor.3" name="/root/syzkaller-testdir017989036/syzkaller.i2GbW0/2226/file0" dev="sda1" ino=16417 res=1