INFO: task hung in _rcu_barrier (2)

7 views
Skip to first unread message

syzbot

unread,
Mar 16, 2021, 11:03:19 PM3/16/21
to syzkaller...@googlegroups.com
Hello,

syzbot found the following issue on:

HEAD commit: c7150cd2 Linux 4.14.225
git tree: linux-4.14.y
console output: https://syzkaller.appspot.com/x/log.txt?x=132d65c6d00000
kernel config: https://syzkaller.appspot.com/x/.config?x=112b229d8a53892f
dashboard link: https://syzkaller.appspot.com/bug?extid=0f5d90ad2f500f45e4a9

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

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

Bluetooth: hci1 command 0x0406 tx timeout
Bluetooth: hci2 command 0x0406 tx timeout
Bluetooth: hci3 command 0x0406 tx timeout
Bluetooth: hci4 command 0x0406 tx timeout
Bluetooth: hci5 command 0x0406 tx timeout
INFO: task syz-executor.5:7985 blocked for more than 140 seconds.
Not tainted 4.14.225-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.5 D25608 7985 1 0x80000006
Call Trace:
context_switch kernel/sched/core.c:2808 [inline]
__schedule+0x88b/0x1de0 kernel/sched/core.c:3384
schedule+0x8d/0x1b0 kernel/sched/core.c:3428
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:3486
__mutex_lock_common kernel/locking/mutex.c:833 [inline]
__mutex_lock+0x669/0x1310 kernel/locking/mutex.c:893
_rcu_barrier+0x56/0x3b0 kernel/rcu/tree.c:3546
netdev_run_todo+0xf9/0xad0 net/core/dev.c:7919
tun_detach drivers/net/tun.c:587 [inline]
tun_chr_close+0x46/0x60 drivers/net/tun.c:2679
__fput+0x25f/0x7a0 fs/file_table.c:210
task_work_run+0x11f/0x190 kernel/task_work.c:113
exit_task_work include/linux/task_work.h:22 [inline]
do_exit+0xa44/0x2850 kernel/exit.c:868
do_group_exit+0x100/0x2e0 kernel/exit.c:965
get_signal+0x38d/0x1ca0 kernel/signal.c:2423
do_signal+0x7c/0x1550 arch/x86/kernel/signal.c:814
exit_to_usermode_loop+0x160/0x200 arch/x86/entry/common.c:160
prepare_exit_to_usermode arch/x86/entry/common.c:199 [inline]
syscall_return_slowpath arch/x86/entry/common.c:270 [inline]
do_syscall_64+0x4a3/0x640 arch/x86/entry/common.c:297
entry_SYSCALL_64_after_hwframe+0x46/0xbb
RIP: 0033:0x419554
RSP: 002b:00007ffe5e27a500 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: 0000000000000003 RBX: 00007ffe5e27a610 RCX: 0000000000419554
RDX: 0000000000000002 RSI: 00007ffe5e27a650 RDI: 00000000ffffff9c
RBP: 00007ffe5e27a650 R08: 0000000000000000 R09: 00007ffe5e27a410
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 000000000002d377 R14: 0000000000000000 R15: 00007ffe5e27a650
INFO: task syz-executor.4:9531 blocked for more than 140 seconds.
Not tainted 4.14.225-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.4 D29344 9531 7983 0x00000004
Call Trace:
context_switch kernel/sched/core.c:2808 [inline]
__schedule+0x88b/0x1de0 kernel/sched/core.c:3384
schedule+0x8d/0x1b0 kernel/sched/core.c:3428
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:3486
__mutex_lock_common kernel/locking/mutex.c:833 [inline]
__mutex_lock+0x669/0x1310 kernel/locking/mutex.c:893
sock_ioctl+0x313/0x4c0 net/socket.c:1047
vfs_ioctl fs/ioctl.c:46 [inline]
file_ioctl fs/ioctl.c:500 [inline]
do_vfs_ioctl+0x75a/0xff0 fs/ioctl.c:684
SYSC_ioctl fs/ioctl.c:701 [inline]
SyS_ioctl+0x7f/0xb0 fs/ioctl.c:692
do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x46/0xbb
RIP: 0033:0x465f69
RSP: 002b:00007f0065463188 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 000000000056c008 RCX: 0000000000465f69
RDX: 0000000020000380 RSI: 0000000000008982 RDI: 0000000000000005
RBP: 00000000004bfa8f R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000056c008
R13: 00007ffe389593df R14: 00007f0065463300 R15: 0000000000022000
INFO: task syz-executor.4:9532 blocked for more than 140 seconds.
Not tainted 4.14.225-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.4 D27488 9532 7983 0x00000004
Call Trace:
context_switch kernel/sched/core.c:2808 [inline]
__schedule+0x88b/0x1de0 kernel/sched/core.c:3384
schedule+0x8d/0x1b0 kernel/sched/core.c:3428
schedule_timeout+0x80a/0xe90 kernel/time/timer.c:1724
do_wait_for_common kernel/sched/completion.c:91 [inline]
__wait_for_common kernel/sched/completion.c:112 [inline]
wait_for_common+0x272/0x430 kernel/sched/completion.c:123
_rcu_barrier+0x24f/0x3b0 kernel/rcu/tree.c:3611
netdev_run_todo+0xf9/0xad0 net/core/dev.c:7919
vlan_ioctl_handler+0x150/0xcb0 net/8021q/vlan.c:618
sock_ioctl+0x32c/0x4c0 net/socket.c:1049
vfs_ioctl fs/ioctl.c:46 [inline]
file_ioctl fs/ioctl.c:500 [inline]
do_vfs_ioctl+0x75a/0xff0 fs/ioctl.c:684
SYSC_ioctl fs/ioctl.c:701 [inline]
SyS_ioctl+0x7f/0xb0 fs/ioctl.c:692
do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x46/0xbb
RIP: 0033:0x465f69
RSP: 002b:00007f0065442188 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 000000000056c0b0 RCX: 0000000000465f69
RDX: 0000000020000380 RSI: 0000000000008982 RDI: 0000000000000005
RBP: 00000000004bfa8f R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000056c0b0
R13: 00007ffe389593df R14: 00007f0065442300 R15: 0000000000022000

Showing all locks held in the system:
4 locks held by kworker/u4:0/5:
#0: ("%s""netns"){+.+.}, at: [<ffffffff81363810>] process_one_work+0x6b0/0x14a0 kernel/workqueue.c:2087
#1: (net_cleanup_work){+.+.}, at: [<ffffffff81363846>] process_one_work+0x6e6/0x14a0 kernel/workqueue.c:2091
#2: (net_mutex){+.+.}, at: [<ffffffff85bf9b70>] cleanup_net+0x110/0x840 net/core/net_namespace.c:450
#3: (rcu_preempt_state.barrier_mutex){+.+.}, at: [<ffffffff81469416>] _rcu_barrier+0x56/0x3b0 kernel/rcu/tree.c:3546
1 lock held by khungtaskd/1526:
#0: (tasklist_lock){.+.+}, at: [<ffffffff86ff2967>] debug_show_all_locks+0x7c/0x21a kernel/locking/lockdep.c:4548
1 lock held by syz-executor.5/7985:
#0: (rcu_preempt_state.barrier_mutex){+.+.}, at: [<ffffffff81469416>] _rcu_barrier+0x56/0x3b0 kernel/rcu/tree.c:3546
1 lock held by syz-executor.4/9531:
#0: (vlan_ioctl_mutex){+.+.}, at: [<ffffffff85baa5e3>] sock_ioctl+0x313/0x4c0 net/socket.c:1047
2 locks held by syz-executor.4/9532:
#0: (vlan_ioctl_mutex){+.+.}, at: [<ffffffff85baa5e3>] sock_ioctl+0x313/0x4c0 net/socket.c:1047
#1: (rcu_preempt_state.barrier_mutex){+.+.}, at: [<ffffffff81469416>] _rcu_barrier+0x56/0x3b0 kernel/rcu/tree.c:3546

=============================================

NMI backtrace for cpu 0
CPU: 0 PID: 1526 Comm: khungtaskd Not tainted 4.14.225-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+0x1b2/0x281 lib/dump_stack.c:58
nmi_cpu_backtrace.cold+0x57/0x93 lib/nmi_backtrace.c:101
nmi_trigger_cpumask_backtrace+0x13a/0x180 lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:140 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:195 [inline]
watchdog+0x5b9/0xb40 kernel/hung_task.c:274
kthread+0x30d/0x420 kernel/kthread.c:232
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 9521 Comm: syz-executor.3 Not tainted 4.14.225-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
task: ffff88809ad04040 task.stack: ffff8880423f8000
RIP: 0010:general_protection+0x0/0x50 arch/x86/entry/entry_64.S:1115
RSP: 0000:fffffe0000033fd0 EFLAGS: 00000002
RAX: 0000000000000002 RBX: 0000000000000000 RCX: 000000000003ffff
RDX: 0000000000000008 RSI: 0000000000000008 RDI: 00007fcb3bb8115c
RBP: 00007fcb3bb81170 R08: 00007fff7bf96000 R09: 00000000004bfa8f
R10: 001af1d216f34c56 R11: 0000000000000001 R12: 00007fff7bf95080
R13: 0000000000014edc R14: 00007fcb3bb81300 R15: 0000000000022000
FS: 00007fcb3bb81700(0000) GS:ffff8880ba500000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007fcb3bb80f80 CR3: 000000009f0f9000 CR4: 00000000001406e4
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
<ENTRY_TRAMPOLINE>
RIP: 0033:0x7fff7bf9893e
RSP: 002b:00007fcb3bb81148 EFLAGS: 00010202
</ENTRY_TRAMPOLINE>
Code: e9 c6 02 00 00 e8 f1 01 00 00 48 89 e7 48 8b 74 24 78 48 c7 44 24 78 ff ff ff ff e8 5b 3b db f9 e9 a6 02 00 00 66 0f 1f 44 00 00 <0f> 1f 00 f6 44 24 10 03 75 20 e8 c1 01 00 00 48 89 e7 48 8b 74


---
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.

syzbot

unread,
Jul 14, 2021, 11:03:16 PM7/14/21
to syzkaller...@googlegroups.com
Auto-closing this bug as obsolete.
Crashes did not happen for a while, no reproducer and no activity.
Reply all
Reply to author
Forward
0 new messages