inconsistent lock state in rxrpc_put_client_connection_id
5 views
Skip to first unread message
syzbot
Feb 24, 2020, 6:29:15 AM2/24/20
to syzkaller...@googlegroups.com
Hello,
syzbot found the following crash on:
HEAD commit: 98db2bf2 Linux 4.14.171
git tree: linux-4.14.y
console output: https://syzkaller.appspot.com/x/log.txt?x=171ef74ee00000
kernel config: https://syzkaller.appspot.com/x/.config?x=365f8162d5a0794b
dashboard link: https://syzkaller.appspot.com/bug?extid=9a6b527fea584738d810
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+9a6b52...@syzkaller.appspotmail.com
================================
WARNING: inconsistent lock state
4.14.171-syzkaller #0 Not tainted
--------------------------------
inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage.
syz-executor.1/7299 [HC0[0]:SC1[1]:HE1:SE0] takes:
(rxrpc_conn_id_lock){+.?.}, at: [<ffffffff85ddc229>] spin_lock include/linux/spinlock.h:317 [inline]
(rxrpc_conn_id_lock){+.?.}, at: [<ffffffff85ddc229>] rxrpc_put_client_connection_id.part.0+0x19/0x70 net/rxrpc/conn_client.c:143
{SOFTIRQ-ON-W} state was registered at:
mark_irqflags kernel/locking/lockdep.c:3086 [inline]
__lock_acquire+0xc33/0x4620 kernel/locking/lockdep.c:3444
lock_acquire+0x16f/0x430 kernel/locking/lockdep.c:3994
__raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
_raw_spin_lock+0x2f/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+0x8a5/0x41a0 net/rxrpc/conn_client.c:692
rxrpc_new_client_call+0x8f7/0x1420 net/rxrpc/call_object.c:276
rxrpc_new_client_call_for_sendmsg net/rxrpc/sendmsg.c:525 [inline]
rxrpc_do_sendmsg+0x92a/0x1109 net/rxrpc/sendmsg.c:577
rxrpc_sendmsg+0x4d1/0x610 net/rxrpc/af_rxrpc.c:543
sock_sendmsg_nosec net/socket.c:646 [inline]
sock_sendmsg+0xce/0x110 net/socket.c:656
___sys_sendmsg+0x349/0x840 net/socket.c:2062
__sys_sendmmsg+0x152/0x3a0 net/socket.c:2152
SYSC_sendmmsg net/socket.c:2183 [inline]
SyS_sendmmsg+0x35/0x60 net/socket.c:2178
do_syscall_64+0x1e8/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x42/0xb7
irq event stamp: 7963152
hardirqs last enabled at (7963152): [<ffffffff8668e5cb>] __raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:160 [inline]
hardirqs last enabled at (7963152): [<ffffffff8668e5cb>] _raw_spin_unlock_irqrestore+0x6b/0xe0 kernel/locking/spinlock.c:192
hardirqs last disabled at (7963151): [<ffffffff8668e85f>] __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:108 [inline]
hardirqs last disabled at (7963151): [<ffffffff8668e85f>] _raw_spin_lock_irqsave+0x6f/0xcd kernel/locking/spinlock.c:160
softirqs last enabled at (7962950): [<ffffffff8517d56a>] spin_unlock_bh include/linux/spinlock.h:362 [inline]
softirqs last enabled at (7962950): [<ffffffff8517d56a>] release_sock+0x14a/0x1b0 net/core/sock.c:2790
softirqs last disabled at (7963121): [<ffffffff8138aa10>] invoke_softirq kernel/softirq.c:368 [inline]
softirqs last disabled at (7963121): [<ffffffff8138aa10>] irq_exit+0x160/0x1b0 kernel/softirq.c:409
other info that might help us debug this:
Possible unsafe locking scenario:
CPU0
----
lock(rxrpc_conn_id_lock);
<Interrupt>
lock(rxrpc_conn_id_lock);
*** DEADLOCK ***
3 locks held by syz-executor.1/7299:
#0: (&xt[i].mutex){+.+.}, at: [<ffffffff854c922c>] xt_find_table_lock+0x3c/0x3d0 net/netfilter/x_tables.c:1092
#1: (pgd_lock){+.+.}, at: [<ffffffff812983e3>] spin_lock include/linux/spinlock.h:317 [inline]
#1: (pgd_lock){+.+.}, at: [<ffffffff812983e3>] sync_global_pgds+0xe3/0x400 arch/x86/mm/init_64.c:152
#2: (rcu_callback){....}, at: [<ffffffff814dfa53>] __rcu_reclaim kernel/rcu/rcu.h:185 [inline]
#2: (rcu_callback){....}, at: [<ffffffff814dfa53>] rcu_do_batch kernel/rcu/tree.c:2699 [inline]
#2: (rcu_callback){....}, at: [<ffffffff814dfa53>] invoke_rcu_callbacks kernel/rcu/tree.c:2962 [inline]
#2: (rcu_callback){....}, at: [<ffffffff814dfa53>] __rcu_process_callbacks kernel/rcu/tree.c:2929 [inline]
#2: (rcu_callback){....}, at: [<ffffffff814dfa53>] rcu_process_callbacks+0x893/0x12b0 kernel/rcu/tree.c:2946
stack backtrace:
CPU: 1 PID: 7299 Comm: syz-executor.1 Not tainted 4.14.171-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
<IRQ>
__dump_stack lib/dump_stack.c:17 [inline]
dump_stack+0x142/0x197 lib/dump_stack.c:58
print_usage_bug.cold+0x330/0x42a kernel/locking/lockdep.c:2585
valid_state kernel/locking/lockdep.c:2598 [inline]
mark_lock_irq kernel/locking/lockdep.c:2792 [inline]
mark_lock+0xdbd/0x1240 kernel/locking/lockdep.c:3190
mark_irqflags kernel/locking/lockdep.c:3068 [inline]
__lock_acquire+0xb57/0x4620 kernel/locking/lockdep.c:3444
lock_acquire+0x16f/0x430 kernel/locking/lockdep.c:3994
__raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
_raw_spin_lock+0x2f/0x40 kernel/locking/spinlock.c:152
spin_lock include/linux/spinlock.h:317 [inline]
rxrpc_put_client_connection_id.part.0+0x19/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+0x564/0xaa0 net/rxrpc/conn_client.c:957
rxrpc_put_connection net/rxrpc/ar-internal.h:862 [inline]
rxrpc_rcu_destroy_call+0x88/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+0x7b8/0x12b0 kernel/rcu/tree.c:2946
__do_softirq+0x244/0x9a0 kernel/softirq.c:288
invoke_softirq kernel/softirq.c:368 [inline]
irq_exit+0x160/0x1b0 kernel/softirq.c:409
exiting_irq arch/x86/include/asm/apic.h:648 [inline]
smp_apic_timer_interrupt+0x146/0x5e0 arch/x86/kernel/apic/apic.c:1102
apic_timer_interrupt+0x96/0xa0 arch/x86/entry/entry_64.S:792
</IRQ>
RIP: 0010:debug_spin_unlock kernel/locking/spinlock_debug.c:97 [inline]
RIP: 0010:do_raw_spin_unlock+0x1e/0x260 kernel/locking/spinlock_debug.c:134
RSP: 0018:ffff88805b14fa10 EFLAGS: 00000286 ORIG_RAX: ffffffffffffff10
RAX: dffffc0000000000 RBX: ffffea000229c7c0 RCX: 1ffff1100b628d0e
RDX: ffff888089aa60fc RSI: 0000000000000003 RDI: ffff888089aa60fc
RBP: ffff88805b14fa28 R08: ffff88805b146000 R09: 0000000000000002
R10: 0000000000000000 R11: ffff88805b146000 R12: ffff888089aa60f8
R13: ffff888089aa60f8 R14: 00003ffffffff000 R15: dffffc0000000000
__raw_spin_unlock include/linux/spinlock_api_smp.h:151 [inline]
_raw_spin_unlock+0x23/0x50 kernel/locking/spinlock.c:184
spin_unlock include/linux/spinlock.h:357 [inline]
sync_global_pgds+0x194/0x400 arch/x86/mm/init_64.c:171
vmalloc_sync_all+0x22/0x30 arch/x86/mm/fault.c:406
__vmalloc_node_range+0x383/0x6a0 mm/vmalloc.c:1772
__vmalloc_node mm/vmalloc.c:1815 [inline]
__vmalloc_node_flags mm/vmalloc.c:1829 [inline]
vzalloc+0x46/0x50 mm/vmalloc.c:1868
alloc_counters.isra.0+0x48/0x90 net/ipv6/netfilter/ip6_tables.c:818
copy_entries_to_user net/ipv6/netfilter/ip6_tables.c:840 [inline]
get_entries net/ipv6/netfilter/ip6_tables.c:1044 [inline]
do_ip6t_get_ctl+0x439/0x820 net/ipv6/netfilter/ip6_tables.c:1713
nf_sockopt net/netfilter/nf_sockopt.c:104 [inline]
nf_getsockopt+0x6a/0xc0 net/netfilter/nf_sockopt.c:122
ipv6_getsockopt net/ipv6/ipv6_sockglue.c:1369 [inline]
ipv6_getsockopt+0x182/0x1f0 net/ipv6/ipv6_sockglue.c:1349
tcp_getsockopt net/ipv4/tcp.c:3255 [inline]
tcp_getsockopt+0x84/0xd0 net/ipv4/tcp.c:3249
sock_common_getsockopt+0x94/0xd0 net/core/sock.c:2927
SYSC_getsockopt net/socket.c:1896 [inline]
SyS_getsockopt+0x126/0x1e0 net/socket.c:1878
do_syscall_64+0x1e8/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x45ef3a
RSP: 002b:00007fff26977028 EFLAGS: 00000212 ORIG_RAX: 0000000000000037
RAX: ffffffffffffffda RBX: 00007fff26977050 RCX: 000000000045ef3a
RDX: 0000000000000041 RSI: 0000000000000029 RDI: 0000000000000003
RBP: 000000000071dcc0 R08: 00007fff2697704c R09: 0000000000004000
R10: 00007fff26977150 R11: 0000000000000212 R12: 0000000000000003
R13: 0000000000000000 R14: 0000000000000029 R15: 000000000071c880
---
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 found the following crash on:
HEAD commit: 98db2bf2 Linux 4.14.171
git tree: linux-4.14.y
console output: https://syzkaller.appspot.com/x/log.txt?x=171ef74ee00000
kernel config: https://syzkaller.appspot.com/x/.config?x=365f8162d5a0794b
dashboard link: https://syzkaller.appspot.com/bug?extid=9a6b527fea584738d810
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+9a6b52...@syzkaller.appspotmail.com
================================
WARNING: inconsistent lock state
4.14.171-syzkaller #0 Not tainted
--------------------------------
inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage.
syz-executor.1/7299 [HC0[0]:SC1[1]:HE1:SE0] takes:
(rxrpc_conn_id_lock){+.?.}, at: [<ffffffff85ddc229>] spin_lock include/linux/spinlock.h:317 [inline]
(rxrpc_conn_id_lock){+.?.}, at: [<ffffffff85ddc229>] rxrpc_put_client_connection_id.part.0+0x19/0x70 net/rxrpc/conn_client.c:143
{SOFTIRQ-ON-W} state was registered at:
mark_irqflags kernel/locking/lockdep.c:3086 [inline]
__lock_acquire+0xc33/0x4620 kernel/locking/lockdep.c:3444
lock_acquire+0x16f/0x430 kernel/locking/lockdep.c:3994
__raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
_raw_spin_lock+0x2f/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+0x8a5/0x41a0 net/rxrpc/conn_client.c:692
rxrpc_new_client_call+0x8f7/0x1420 net/rxrpc/call_object.c:276
rxrpc_new_client_call_for_sendmsg net/rxrpc/sendmsg.c:525 [inline]
rxrpc_do_sendmsg+0x92a/0x1109 net/rxrpc/sendmsg.c:577
rxrpc_sendmsg+0x4d1/0x610 net/rxrpc/af_rxrpc.c:543
sock_sendmsg_nosec net/socket.c:646 [inline]
sock_sendmsg+0xce/0x110 net/socket.c:656
___sys_sendmsg+0x349/0x840 net/socket.c:2062
__sys_sendmmsg+0x152/0x3a0 net/socket.c:2152
SYSC_sendmmsg net/socket.c:2183 [inline]
SyS_sendmmsg+0x35/0x60 net/socket.c:2178
do_syscall_64+0x1e8/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x42/0xb7
irq event stamp: 7963152
hardirqs last enabled at (7963152): [<ffffffff8668e5cb>] __raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:160 [inline]
hardirqs last enabled at (7963152): [<ffffffff8668e5cb>] _raw_spin_unlock_irqrestore+0x6b/0xe0 kernel/locking/spinlock.c:192
hardirqs last disabled at (7963151): [<ffffffff8668e85f>] __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:108 [inline]
hardirqs last disabled at (7963151): [<ffffffff8668e85f>] _raw_spin_lock_irqsave+0x6f/0xcd kernel/locking/spinlock.c:160
softirqs last enabled at (7962950): [<ffffffff8517d56a>] spin_unlock_bh include/linux/spinlock.h:362 [inline]
softirqs last enabled at (7962950): [<ffffffff8517d56a>] release_sock+0x14a/0x1b0 net/core/sock.c:2790
softirqs last disabled at (7963121): [<ffffffff8138aa10>] invoke_softirq kernel/softirq.c:368 [inline]
softirqs last disabled at (7963121): [<ffffffff8138aa10>] irq_exit+0x160/0x1b0 kernel/softirq.c:409
other info that might help us debug this:
Possible unsafe locking scenario:
CPU0
----
lock(rxrpc_conn_id_lock);
<Interrupt>
lock(rxrpc_conn_id_lock);
*** DEADLOCK ***
3 locks held by syz-executor.1/7299:
#0: (&xt[i].mutex){+.+.}, at: [<ffffffff854c922c>] xt_find_table_lock+0x3c/0x3d0 net/netfilter/x_tables.c:1092
#1: (pgd_lock){+.+.}, at: [<ffffffff812983e3>] spin_lock include/linux/spinlock.h:317 [inline]
#1: (pgd_lock){+.+.}, at: [<ffffffff812983e3>] sync_global_pgds+0xe3/0x400 arch/x86/mm/init_64.c:152
#2: (rcu_callback){....}, at: [<ffffffff814dfa53>] __rcu_reclaim kernel/rcu/rcu.h:185 [inline]
#2: (rcu_callback){....}, at: [<ffffffff814dfa53>] rcu_do_batch kernel/rcu/tree.c:2699 [inline]
#2: (rcu_callback){....}, at: [<ffffffff814dfa53>] invoke_rcu_callbacks kernel/rcu/tree.c:2962 [inline]
#2: (rcu_callback){....}, at: [<ffffffff814dfa53>] __rcu_process_callbacks kernel/rcu/tree.c:2929 [inline]
#2: (rcu_callback){....}, at: [<ffffffff814dfa53>] rcu_process_callbacks+0x893/0x12b0 kernel/rcu/tree.c:2946
stack backtrace:
CPU: 1 PID: 7299 Comm: syz-executor.1 Not tainted 4.14.171-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
<IRQ>
__dump_stack lib/dump_stack.c:17 [inline]
dump_stack+0x142/0x197 lib/dump_stack.c:58
print_usage_bug.cold+0x330/0x42a kernel/locking/lockdep.c:2585
valid_state kernel/locking/lockdep.c:2598 [inline]
mark_lock_irq kernel/locking/lockdep.c:2792 [inline]
mark_lock+0xdbd/0x1240 kernel/locking/lockdep.c:3190
mark_irqflags kernel/locking/lockdep.c:3068 [inline]
__lock_acquire+0xb57/0x4620 kernel/locking/lockdep.c:3444
lock_acquire+0x16f/0x430 kernel/locking/lockdep.c:3994
__raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
_raw_spin_lock+0x2f/0x40 kernel/locking/spinlock.c:152
spin_lock include/linux/spinlock.h:317 [inline]
rxrpc_put_client_connection_id.part.0+0x19/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+0x564/0xaa0 net/rxrpc/conn_client.c:957
rxrpc_put_connection net/rxrpc/ar-internal.h:862 [inline]
rxrpc_rcu_destroy_call+0x88/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+0x7b8/0x12b0 kernel/rcu/tree.c:2946
__do_softirq+0x244/0x9a0 kernel/softirq.c:288
invoke_softirq kernel/softirq.c:368 [inline]
irq_exit+0x160/0x1b0 kernel/softirq.c:409
exiting_irq arch/x86/include/asm/apic.h:648 [inline]
smp_apic_timer_interrupt+0x146/0x5e0 arch/x86/kernel/apic/apic.c:1102
apic_timer_interrupt+0x96/0xa0 arch/x86/entry/entry_64.S:792
</IRQ>
RIP: 0010:debug_spin_unlock kernel/locking/spinlock_debug.c:97 [inline]
RIP: 0010:do_raw_spin_unlock+0x1e/0x260 kernel/locking/spinlock_debug.c:134
RSP: 0018:ffff88805b14fa10 EFLAGS: 00000286 ORIG_RAX: ffffffffffffff10
RAX: dffffc0000000000 RBX: ffffea000229c7c0 RCX: 1ffff1100b628d0e
RDX: ffff888089aa60fc RSI: 0000000000000003 RDI: ffff888089aa60fc
RBP: ffff88805b14fa28 R08: ffff88805b146000 R09: 0000000000000002
R10: 0000000000000000 R11: ffff88805b146000 R12: ffff888089aa60f8
R13: ffff888089aa60f8 R14: 00003ffffffff000 R15: dffffc0000000000
__raw_spin_unlock include/linux/spinlock_api_smp.h:151 [inline]
_raw_spin_unlock+0x23/0x50 kernel/locking/spinlock.c:184
spin_unlock include/linux/spinlock.h:357 [inline]
sync_global_pgds+0x194/0x400 arch/x86/mm/init_64.c:171
vmalloc_sync_all+0x22/0x30 arch/x86/mm/fault.c:406
__vmalloc_node_range+0x383/0x6a0 mm/vmalloc.c:1772
__vmalloc_node mm/vmalloc.c:1815 [inline]
__vmalloc_node_flags mm/vmalloc.c:1829 [inline]
vzalloc+0x46/0x50 mm/vmalloc.c:1868
alloc_counters.isra.0+0x48/0x90 net/ipv6/netfilter/ip6_tables.c:818
copy_entries_to_user net/ipv6/netfilter/ip6_tables.c:840 [inline]
get_entries net/ipv6/netfilter/ip6_tables.c:1044 [inline]
do_ip6t_get_ctl+0x439/0x820 net/ipv6/netfilter/ip6_tables.c:1713
nf_sockopt net/netfilter/nf_sockopt.c:104 [inline]
nf_getsockopt+0x6a/0xc0 net/netfilter/nf_sockopt.c:122
ipv6_getsockopt net/ipv6/ipv6_sockglue.c:1369 [inline]
ipv6_getsockopt+0x182/0x1f0 net/ipv6/ipv6_sockglue.c:1349
tcp_getsockopt net/ipv4/tcp.c:3255 [inline]
tcp_getsockopt+0x84/0xd0 net/ipv4/tcp.c:3249
sock_common_getsockopt+0x94/0xd0 net/core/sock.c:2927
SYSC_getsockopt net/socket.c:1896 [inline]
SyS_getsockopt+0x126/0x1e0 net/socket.c:1878
do_syscall_64+0x1e8/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x45ef3a
RSP: 002b:00007fff26977028 EFLAGS: 00000212 ORIG_RAX: 0000000000000037
RAX: ffffffffffffffda RBX: 00007fff26977050 RCX: 000000000045ef3a
RDX: 0000000000000041 RSI: 0000000000000029 RDI: 0000000000000003
RBP: 000000000071dcc0 R08: 00007fff2697704c R09: 0000000000004000
R10: 00007fff26977150 R11: 0000000000000212 R12: 0000000000000003
R13: 0000000000000000 R14: 0000000000000029 R15: 000000000071c880
---
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
Sep 29, 2020, 4:26:10 AM9/29/20
to syzkaller...@googlegroups.com
Auto-closing this bug as obsolete.
Crashes did not happen for a while, no reproducer and no activity.
Crashes did not happen for a while, no reproducer and no activity.
Reply all
Reply to author
Forward
0 new messages