INFO: task hung in __kernfs_remove

[syzbot]

Hello,

syzbot found the following crash on:

HEAD commit: 1a059243 Linux 4.19.57
git tree: linux-4.19.y
console output: https://syzkaller.appspot.com/x/log.txt?x=161d538ba00000
kernel config: https://syzkaller.appspot.com/x/.config?x=7e75fed85684bc8a
dashboard link: https://syzkaller.appspot.com/bug?extid=23bd581cc562a92cf74b
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+23bd58...@syzkaller.appspotmail.com

bridge0: port 2(bridge_slave_1) entered forwarding state
bridge0: port 1(bridge_slave_0) entered blocking state
bridge0: port 1(bridge_slave_0) entered forwarding state
device bridge0 entered promiscuous mode
INFO: task syz-executor.4:14854 blocked for more than 140 seconds.
Not tainted 4.19.57 #29
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.4 D26256 14854 7773 0x00000004
Call Trace:
context_switch kernel/sched/core.c:2826 [inline]
__schedule+0x80d/0x1c70 kernel/sched/core.c:3474
schedule+0x92/0x1c0 kernel/sched/core.c:3518
kernfs_drain fs/kernfs/dir.c:474 [inline]
__kernfs_remove fs/kernfs/dir.c:1317 [inline]
__kernfs_remove+0x4a8/0x950 fs/kernfs/dir.c:1276
kernfs_remove+0x24/0x40 fs/kernfs/dir.c:1352
sysfs_remove_dir+0xd2/0x110 fs/sysfs/dir.c:101
kobject_del.part.0+0x3a/0xf0 lib/kobject.c:592
kobject_del+0x20/0x30 lib/kobject.c:588
cleanup_glue_dir.part.0+0x100/0x130 drivers/base/core.c:1657
cleanup_glue_dir drivers/base/core.c:681 [inline]
device_del+0x81c/0xb70 drivers/base/core.c:2100
hci_unregister_dev+0x2c6/0x820 net/bluetooth/hci_core.c:3292
vhci_release+0x76/0xf0 drivers/bluetooth/hci_vhci.c:354
__fput+0x2dd/0x8b0 fs/file_table.c:278
____fput+0x16/0x20 fs/file_table.c:309
task_work_run+0x145/0x1c0 kernel/task_work.c:113
tracehook_notify_resume include/linux/tracehook.h:193 [inline]
exit_to_usermode_loop+0x273/0x2c0 arch/x86/entry/common.c:167
prepare_exit_to_usermode arch/x86/entry/common.c:198 [inline]
syscall_return_slowpath arch/x86/entry/common.c:271 [inline]
do_syscall_64+0x53d/0x620 arch/x86/entry/common.c:296
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x4597c9
Code: Bad RIP value.
RSP: 002b:00007f7e5bbfcc78 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
RAX: 0000000000000002 RBX: 0000000000000003 RCX: 00000000004597c9
RDX: 0000000000000002 RSI: 0000000020000000 RDI: 0000000000000004
RBP: 000000000075bf20 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00007f7e5bbfd6d4
R13: 00000000004c98ed R14: 00000000004e0d30 R15: 00000000ffffffff
INFO: task syz-executor.1:14861 blocked for more than 140 seconds.
Not tainted 4.19.57 #29
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.1 D26304 14861 7763 0x00000004
Call Trace:
context_switch kernel/sched/core.c:2826 [inline]
__schedule+0x80d/0x1c70 kernel/sched/core.c:3474
schedule+0x92/0x1c0 kernel/sched/core.c:3518
schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3576
__mutex_lock_common kernel/locking/mutex.c:1002 [inline]
__mutex_lock+0x726/0x1300 kernel/locking/mutex.c:1072
mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:1087
cleanup_glue_dir.part.0+0x23/0x130 drivers/base/core.c:1655
cleanup_glue_dir drivers/base/core.c:681 [inline]
device_del+0x81c/0xb70 drivers/base/core.c:2100
hci_unregister_dev+0x2c6/0x820 net/bluetooth/hci_core.c:3292
vhci_release+0x76/0xf0 drivers/bluetooth/hci_vhci.c:354
__fput+0x2dd/0x8b0 fs/file_table.c:278
____fput+0x16/0x20 fs/file_table.c:309
task_work_run+0x145/0x1c0 kernel/task_work.c:113
tracehook_notify_resume include/linux/tracehook.h:193 [inline]
exit_to_usermode_loop+0x273/0x2c0 arch/x86/entry/common.c:167
prepare_exit_to_usermode arch/x86/entry/common.c:198 [inline]
syscall_return_slowpath arch/x86/entry/common.c:271 [inline]
do_syscall_64+0x53d/0x620 arch/x86/entry/common.c:296
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x4597c9
Code: Bad RIP value.
RSP: 002b:00007f4105ed7c78 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
RAX: 0000000000000002 RBX: 0000000000000003 RCX: 00000000004597c9
RDX: 0000000000000002 RSI: 0000000020000000 RDI: 0000000000000004
RBP: 000000000075bf20 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00007f4105ed86d4
R13: 00000000004c98ed R14: 00000000004e0d30 R15: 00000000ffffffff

Showing all locks held in the system:
3 locks held by kworker/u4:1/23:
#0: 00000000da230fca (&rq->lock){-.-.}, at: rq_lock
kernel/sched/sched.h:1821 [inline]
#0: 00000000da230fca (&rq->lock){-.-.}, at: __schedule+0x1f8/0x1c70
kernel/sched/core.c:3412
#1: 00000000720311e7 (rcu_read_lock){....}, at:
__update_idle_core+0x45/0x3f0 kernel/sched/fair.c:5995
#2: 00000000720311e7 (rcu_read_lock){....}, at: batadv_nc_purge_orig_hash
net/batman-adv/network-coding.c:417 [inline]
#2: 00000000720311e7 (rcu_read_lock){....}, at:
batadv_nc_worker+0xe3/0x760 net/batman-adv/network-coding.c:730
3 locks held by kworker/1:1/24:
#0: 00000000988bdfaa ((wq_completion)"events"){+.+.}, at:
__write_once_size include/linux/compiler.h:220 [inline]
#0: 00000000988bdfaa ((wq_completion)"events"){+.+.}, at:
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: 00000000988bdfaa ((wq_completion)"events"){+.+.}, at: atomic64_set
include/asm-generic/atomic-instrumented.h:40 [inline]
#0: 00000000988bdfaa ((wq_completion)"events"){+.+.}, at: atomic_long_set
include/asm-generic/atomic-long.h:59 [inline]
#0: 00000000988bdfaa ((wq_completion)"events"){+.+.}, at: set_work_data
kernel/workqueue.c:617 [inline]
#0: 00000000988bdfaa ((wq_completion)"events"){+.+.}, at:
set_work_pool_and_clear_pending kernel/workqueue.c:644 [inline]
#0: 00000000988bdfaa ((wq_completion)"events"){+.+.}, at:
process_one_work+0x87e/0x1750 kernel/workqueue.c:2124
#1: 0000000047df7e71 (deferred_process_work){+.+.}, at:
process_one_work+0x8b4/0x1750 kernel/workqueue.c:2128
#2: 00000000c024117d (rtnl_mutex){+.+.}, at: rtnl_lock+0x17/0x20
net/core/rtnetlink.c:77
1 lock held by khungtaskd/1031:
#0: 00000000720311e7 (rcu_read_lock){....}, at:
debug_show_all_locks+0x5f/0x27e kernel/locking/lockdep.c:4435
1 lock held by rsyslogd/7596:
#0: 0000000000fc65b0 (&f->f_pos_lock){+.+.}, at: __fdget_pos+0xee/0x110
fs/file.c:767
2 locks held by getty/7718:
#0: 000000005e2ed20e (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 000000008136d793 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
2 locks held by getty/7719:
#0: 00000000c530ff85 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 0000000086529387 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
2 locks held by getty/7720:
#0: 00000000c00fa6e8 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 000000007ff11742 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
2 locks held by getty/7721:
#0: 00000000534eb2b5 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 0000000036f29359 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
2 locks held by getty/7722:
#0: 00000000d0f807c6 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 000000006a418bfa (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
2 locks held by getty/7723:
#0: 0000000048e58960 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 00000000b764cf03 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
2 locks held by getty/7724:
#0: 000000006cdbd648 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 00000000e7891152 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
3 locks held by kworker/0:3/7778:
#0: 0000000074306e9f ((wq_completion)"%s"("ipv6_addrconf")){+.+.}, at:
__write_once_size include/linux/compiler.h:220 [inline]
#0: 0000000074306e9f ((wq_completion)"%s"("ipv6_addrconf")){+.+.}, at:
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: 0000000074306e9f ((wq_completion)"%s"("ipv6_addrconf")){+.+.}, at:
atomic64_set include/asm-generic/atomic-instrumented.h:40 [inline]
#0: 0000000074306e9f ((wq_completion)"%s"("ipv6_addrconf")){+.+.}, at:
atomic_long_set include/asm-generic/atomic-long.h:59 [inline]
#0: 0000000074306e9f ((wq_completion)"%s"("ipv6_addrconf")){+.+.}, at:
set_work_data kernel/workqueue.c:617 [inline]
#0: 0000000074306e9f ((wq_completion)"%s"("ipv6_addrconf")){+.+.}, at:
set_work_pool_and_clear_pending kernel/workqueue.c:644 [inline]
#0: 0000000074306e9f ((wq_completion)"%s"("ipv6_addrconf")){+.+.}, at:
process_one_work+0x87e/0x1750 kernel/workqueue.c:2124
#1: 000000009724a1a4 ((addr_chk_work).work){+.+.}, at:
process_one_work+0x8b4/0x1750 kernel/workqueue.c:2128
#2: 00000000c024117d (rtnl_mutex){+.+.}, at: rtnl_lock+0x17/0x20
net/core/rtnetlink.c:77
5 locks held by kworker/u4:5/8391:
#0: 00000000ebc51538 ((wq_completion)"%s""netns"){+.+.}, at:
__write_once_size include/linux/compiler.h:220 [inline]
#0: 00000000ebc51538 ((wq_completion)"%s""netns"){+.+.}, at:
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: 00000000ebc51538 ((wq_completion)"%s""netns"){+.+.}, at: atomic64_set
include/asm-generic/atomic-instrumented.h:40 [inline]
#0: 00000000ebc51538 ((wq_completion)"%s""netns"){+.+.}, at:
atomic_long_set include/asm-generic/atomic-long.h:59 [inline]
#0: 00000000ebc51538 ((wq_completion)"%s""netns"){+.+.}, at: set_work_data
kernel/workqueue.c:617 [inline]
#0: 00000000ebc51538 ((wq_completion)"%s""netns"){+.+.}, at:
set_work_pool_and_clear_pending kernel/workqueue.c:644 [inline]
#0: 00000000ebc51538 ((wq_completion)"%s""netns"){+.+.}, at:
process_one_work+0x87e/0x1750 kernel/workqueue.c:2124
#1: 0000000065b76c01 (net_cleanup_work){+.+.}, at:
process_one_work+0x8b4/0x1750 kernel/workqueue.c:2128
#2: 0000000041d94648 (pernet_ops_rwsem){++++}, at: cleanup_net+0xae/0x960
net/core/net_namespace.c:519
#3: 00000000c024117d (rtnl_mutex){+.+.}, at: rtnl_lock+0x17/0x20
net/core/rtnetlink.c:77
#4: 00000000c927fd7d (gdp_mutex){+.+.}, at:
cleanup_glue_dir.part.0+0x23/0x130 drivers/base/core.c:1655
1 lock held by syz-executor.4/14854:
#0: 00000000c927fd7d (gdp_mutex){+.+.}, at:
cleanup_glue_dir.part.0+0x23/0x130 drivers/base/core.c:1655
1 lock held by syz-executor.1/14861:
#0: 00000000c927fd7d (gdp_mutex){+.+.}, at:
cleanup_glue_dir.part.0+0x23/0x130 drivers/base/core.c:1655

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

NMI backtrace for cpu 1
CPU: 1 PID: 1031 Comm: khungtaskd Not tainted 4.19.57 #29
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
Call Trace:
__dump_stack lib/dump_stack.c:77 [inline]
dump_stack+0x172/0x1f0 lib/dump_stack.c:113
nmi_cpu_backtrace.cold+0x63/0xa4 lib/nmi_backtrace.c:101
nmi_trigger_cpumask_backtrace+0x1b0/0x1f8 lib/nmi_backtrace.c:62
arch_trigger_cpumask_backtrace+0x14/0x20 arch/x86/kernel/apic/hw_nmi.c:38
trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:203 [inline]
watchdog+0x9df/0xee0 kernel/hung_task.c:287
kthread+0x354/0x420 kernel/kthread.c:246
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0 skipped: idling at native_safe_halt+0xe/0x10
arch/x86/include/asm/irqflags.h:60


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