INFO: task hung in fsnotify_connector_destroy_workfn

[syzbot]

Hello,

syzbot found the following crash on:

HEAD commit: c98875d9 Linux 4.19.36
git tree: linux-4.19.y
console output: https://syzkaller.appspot.com/x/log.txt?x=12c9143d200000
kernel config: https://syzkaller.appspot.com/x/.config?x=5e40ac5fbcc6366d
dashboard link: https://syzkaller.appspot.com/bug?extid=8a3dbdaf0c4744525419
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+8a3dbd...@syzkaller.appspotmail.com

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
INFO: task kworker/u4:2:34 blocked for more than 140 seconds.
Not tainted 4.19.36 #4
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/u4:2 D25432 34 2 0x80000000
Workqueue: events_unbound fsnotify_connector_destroy_workfn
Call Trace:
context_switch kernel/sched/core.c:2826 [inline]
__schedule+0x813/0x1d00 kernel/sched/core.c:3474
schedule+0x92/0x1c0 kernel/sched/core.c:3518
schedule_timeout+0x8ca/0xfd0 kernel/time/timer.c:1780
do_wait_for_common kernel/sched/completion.c:83 [inline]
__wait_for_common kernel/sched/completion.c:104 [inline]
wait_for_common kernel/sched/completion.c:115 [inline]
wait_for_completion+0x29c/0x440 kernel/sched/completion.c:136
__synchronize_srcu+0x12e/0x210 kernel/rcu/srcutree.c:936
synchronize_srcu_expedited kernel/rcu/srcutree.c:961 [inline]
synchronize_srcu+0x239/0x3e8 kernel/rcu/srcutree.c:1012
fsnotify_connector_destroy_workfn+0x4e/0xa0 fs/notify/mark.c:174
process_one_work+0x98e/0x1760 kernel/workqueue.c:2153
worker_thread+0x98/0xe40 kernel/workqueue.c:2296
kthread+0x357/0x430 kernel/kthread.c:246
ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:413
INFO: task kworker/u4:3:124 blocked for more than 140 seconds.
Not tainted 4.19.36 #4
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/u4:3 D25568 124 2 0x80000000
Workqueue: events_unbound fsnotify_mark_destroy_workfn
Call Trace:
context_switch kernel/sched/core.c:2826 [inline]
__schedule+0x813/0x1d00 kernel/sched/core.c:3474
schedule+0x92/0x1c0 kernel/sched/core.c:3518
schedule_timeout+0x8ca/0xfd0 kernel/time/timer.c:1780
do_wait_for_common kernel/sched/completion.c:83 [inline]
__wait_for_common kernel/sched/completion.c:104 [inline]
wait_for_common kernel/sched/completion.c:115 [inline]
wait_for_completion+0x29c/0x440 kernel/sched/completion.c:136
__synchronize_srcu+0x12e/0x210 kernel/rcu/srcutree.c:936
synchronize_srcu+0x2dc/0x3e8 kernel/rcu/srcutree.c:1014
fsnotify_mark_destroy_workfn+0x110/0x3b0 fs/notify/mark.c:795
process_one_work+0x98e/0x1760 kernel/workqueue.c:2153
worker_thread+0x98/0xe40 kernel/workqueue.c:2296
kthread+0x357/0x430 kernel/kthread.c:246
ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:413
INFO: task syz-executor.5:4049 blocked for more than 140 seconds.
Not tainted 4.19.36 #4
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.5 D27392 4049 8038 0x00000004
Call Trace:
context_switch kernel/sched/core.c:2826 [inline]
__schedule+0x813/0x1d00 kernel/sched/core.c:3474
schedule+0x92/0x1c0 kernel/sched/core.c:3518
schedule_timeout+0x8ca/0xfd0 kernel/time/timer.c:1780
do_wait_for_common kernel/sched/completion.c:83 [inline]
__wait_for_common kernel/sched/completion.c:104 [inline]
wait_for_common kernel/sched/completion.c:115 [inline]
wait_for_completion+0x29c/0x440 kernel/sched/completion.c:136
flush_workqueue+0x40f/0x14c0 kernel/workqueue.c:2707
ceph_msgr_flush+0x15/0x20 net/ceph/messenger.c:306
ceph_mdsc_pre_umount+0x389/0x430 fs/ceph/mds_client.c:3726
ceph_kill_sb+0x8e/0x1e0 fs/ceph/super.c:1111
deactivate_locked_super+0x9a/0x100 fs/super.c:329
ceph_mount+0x1302/0x1840 fs/ceph/super.c:1093
mount_fs+0xae/0x331 fs/super.c:1261
vfs_kern_mount.part.0+0x6f/0x410 fs/namespace.c:961
vfs_kern_mount fs/namespace.c:951 [inline]
do_new_mount fs/namespace.c:2469 [inline]
do_mount+0x53e/0x2bc0 fs/namespace.c:2799
ksys_mount+0xdb/0x150 fs/namespace.c:3015
__do_sys_mount fs/namespace.c:3029 [inline]
__se_sys_mount fs/namespace.c:3026 [inline]
__x64_sys_mount+0xbe/0x150 fs/namespace.c:3026
do_syscall_64+0x103/0x610 arch/x86/entry/common.c:290
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x458c29
Code: Bad RIP value.
RSP: 002b:00007f17a6c2dc78 EFLAGS: 00000246 ORIG_RAX: 00000000000000a5
RAX: ffffffffffffffda RBX: 0000000000000005 RCX: 0000000000458c29
RDX: 0000000020000140 RSI: 00000000200000c0 RDI: 0000000020000040
RBP: 000000000073bf00 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00007f17a6c2e6d4
R13: 00000000004c4c0e R14: 00000000004d8888 R15: 00000000ffffffff
INFO: task syz-executor.2:4521 blocked for more than 140 seconds.
Not tainted 4.19.36 #4
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.2 D28216 4521 8029 0x00000004
Call Trace:
context_switch kernel/sched/core.c:2826 [inline]
__schedule+0x813/0x1d00 kernel/sched/core.c:3474
schedule+0x92/0x1c0 kernel/sched/core.c:3518
schedule_timeout+0x8ca/0xfd0 kernel/time/timer.c:1780
do_wait_for_common kernel/sched/completion.c:83 [inline]
__wait_for_common kernel/sched/completion.c:104 [inline]
wait_for_common kernel/sched/completion.c:115 [inline]
wait_for_completion+0x29c/0x440 kernel/sched/completion.c:136
__synchronize_srcu+0x12e/0x210 kernel/rcu/srcutree.c:936
synchronize_srcu_expedited kernel/rcu/srcutree.c:961 [inline]
synchronize_srcu+0x239/0x3e8 kernel/rcu/srcutree.c:1012
tracepoint_synchronize_unregister include/linux/tracepoint.h:84 [inline]
perf_trace_event_unreg.isra.0+0xcb/0x220
kernel/trace/trace_event_perf.c:163
perf_trace_destroy+0xc1/0x100 kernel/trace/trace_event_perf.c:238
tp_perf_event_destroy+0x16/0x20 kernel/events/core.c:8346
_free_event+0x356/0x1220 kernel/events/core.c:4446
put_event+0x47/0x60 kernel/events/core.c:4532
perf_event_release_kernel+0x68f/0xbf0 kernel/events/core.c:4638
perf_release+0x37/0x50 kernel/events/core.c:4648
__fput+0x2df/0x8b0 fs/file_table.c:278
____fput+0x16/0x20 fs/file_table.c:309
task_work_run+0x14a/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:166
prepare_exit_to_usermode arch/x86/entry/common.c:197 [inline]
syscall_return_slowpath arch/x86/entry/common.c:268 [inline]
do_syscall_64+0x52d/0x610 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x4129e1
Code: bb c8 00 00 00 ff 15 1e 6e 24 00 85 c0 89 c5 0f 85 7e fc ff ff e9 32
ff ff ff 66 66 66 66 66 66 2e 0f 1f 84 00 00 00 00 00 48 <89> 5c 24 d0 4c
89 6c 24 e8 48 89 d3 48 89 6c 24 d8 4c 89 64 24 e0
RSP: 002b:00007ffd14ef73e0 EFLAGS: 00000293 ORIG_RAX: 0000000000000003
RAX: 0000000000000000 RBX: 0000000000000004 RCX: 00000000004129e1
RDX: 0000001b31720000 RSI: 0000000000000000 RDI: 0000000000000003
RBP: 000000000073c900 R08: 000000000981a610 R09: 000000000981a614
R10: 00007ffd14ef74b0 R11: 0000000000000293 R12: 0000000000000001
R13: 000000000073c900 R14: 000000000013e48c R15: 000000000073bf0c

Showing all locks held in the system:
3 locks held by kworker/1:1/24:
2 locks held by kworker/u4:2/34:
#0: 00000000328ab1b7 ((wq_completion)"events_unbound"){+.+.}, at:
__write_once_size include/linux/compiler.h:220 [inline]
#0: 00000000328ab1b7 ((wq_completion)"events_unbound"){+.+.}, at:
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: 00000000328ab1b7 ((wq_completion)"events_unbound"){+.+.}, at:
atomic64_set include/asm-generic/atomic-instrumented.h:40 [inline]
#0: 00000000328ab1b7 ((wq_completion)"events_unbound"){+.+.}, at:
atomic_long_set include/asm-generic/atomic-long.h:59 [inline]
#0: 00000000328ab1b7 ((wq_completion)"events_unbound"){+.+.}, at:
set_work_data kernel/workqueue.c:617 [inline]
#0: 00000000328ab1b7 ((wq_completion)"events_unbound"){+.+.}, at:
set_work_pool_and_clear_pending kernel/workqueue.c:644 [inline]
#0: 00000000328ab1b7 ((wq_completion)"events_unbound"){+.+.}, at:
process_one_work+0x87e/0x1760 kernel/workqueue.c:2124
#1: 00000000afe8a0d9 (connector_reaper_work){+.+.}, at:
process_one_work+0x8b4/0x1760 kernel/workqueue.c:2128
2 locks held by kworker/u4:3/124:
#0: 00000000328ab1b7 ((wq_completion)"events_unbound"){+.+.}, at:
__write_once_size include/linux/compiler.h:220 [inline]
#0: 00000000328ab1b7 ((wq_completion)"events_unbound"){+.+.}, at:
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: 00000000328ab1b7 ((wq_completion)"events_unbound"){+.+.}, at:
atomic64_set include/asm-generic/atomic-instrumented.h:40 [inline]
#0: 00000000328ab1b7 ((wq_completion)"events_unbound"){+.+.}, at:
atomic_long_set include/asm-generic/atomic-long.h:59 [inline]
#0: 00000000328ab1b7 ((wq_completion)"events_unbound"){+.+.}, at:
set_work_data kernel/workqueue.c:617 [inline]
#0: 00000000328ab1b7 ((wq_completion)"events_unbound"){+.+.}, at:
set_work_pool_and_clear_pending kernel/workqueue.c:644 [inline]
#0: 00000000328ab1b7 ((wq_completion)"events_unbound"){+.+.}, at:
process_one_work+0x87e/0x1760 kernel/workqueue.c:2124
#1: 000000001f7ab05a ((reaper_work).work){+.+.}, at:
process_one_work+0x8b4/0x1760 kernel/workqueue.c:2128
1 lock held by khungtaskd/1031:
#0: 000000006215a7d8 (rcu_read_lock){....}, at:
debug_show_all_locks+0x5f/0x27e kernel/locking/lockdep.c:4438
1 lock held by rsyslogd/7861:
#0: 00000000a5984de6 (&f->f_pos_lock){+.+.}, at: __fdget_pos+0xee/0x110
fs/file.c:767
2 locks held by getty/7983:
#0: 00000000d2622dc7 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 000000006eefaf1b (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
2 locks held by getty/7984:
#0: 0000000091eb74ac (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 00000000faad76d6 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
2 locks held by getty/7985:
#0: 000000001fe53dc0 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 00000000af3c258c (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
2 locks held by getty/7986:
#0: 00000000cebf2ace (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 0000000023128b49 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
2 locks held by getty/7987:
#0: 0000000002fa9839 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 000000007c524762 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
2 locks held by getty/7988:
#0: 0000000090887c69 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 00000000a7caa594 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
2 locks held by getty/7989:
#0: 00000000e56e9ab6 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 00000000846ab277 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
1 lock held by syz-executor.5/19092:
#0: 000000009f594b71 (event_mutex){+.+.}, at:
perf_trace_destroy+0x28/0x100 kernel/trace/trace_event_perf.c:236
1 lock held by syz-executor.2/27272:
#0: 000000009f594b71 (event_mutex){+.+.}, at:
perf_trace_destroy+0x28/0x100 kernel/trace/trace_event_perf.c:236
1 lock held by syz-executor.5/4049:
#0: 0000000003cc777f (&type->s_umount_key#84/1){+.+.}, at: alloc_super
fs/super.c:226 [inline]
#0: 0000000003cc777f (&type->s_umount_key#84/1){+.+.}, at:
sget_userns+0x208/0xd30 fs/super.c:519
1 lock held by syz-executor.2/4521:
#0: 000000009f594b71 (event_mutex){+.+.}, at:
perf_trace_destroy+0x28/0x100 kernel/trace/trace_event_perf.c:236

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

NMI backtrace for cpu 0
CPU: 0 PID: 1031 Comm: khungtaskd Not tainted 4.19.36 #4
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+0x357/0x430 kernel/kthread.c:246
ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:413
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 24 Comm: kworker/1:1 Not tainted 4.19.36 #4
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
Workqueue: events rtc_timer_do_work
RIP: 0010:preempt_count_add+0x2c/0x1b0 kernel/sched/core.c:3187
Code: 00 00 00 00 00 fc ff df 55 48 89 e5 41 54 41 89 fc 53 48 c7 c3 20 f6
35 8a 48 89 da 48 c1 ea 03 0f b6 14 02 48 89 d8 83 e0 07 <83> c0 03 38 d0
7c 08 84 d2 0f 85 4f 01 00 00 8b 0d 8f 74 ec 08 85
RSP: 0018:ffff8880aa3e7b20 EFLAGS: 00000246
RAX: 0000000000000000 RBX: ffffffff8a35f620 RCX: ffffffff8159a151
RDX: 0000000000000004 RSI: 0000000000000004 RDI: 0000000000000001
RBP: ffff8880aa3e7b30 R08: 1ffff11015d24732 R09: ffffed1015d24733
R10: ffffed1015d24732 R11: ffff8880ae923993 R12: 0000000000000001
R13: ffff88809f6c2a10 R14: dffffc0000000000 R15: 16862c39ec213600
FS: 0000000000000000(0000) GS:ffff8880ae900000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000000002497db0 CR3: 000000000866d000 CR4: 00000000001426e0
Call Trace:
rcu_lockdep_current_cpu_online kernel/rcu/tree.c:1076 [inline]
rcu_lockdep_current_cpu_online+0x37/0x1c0 kernel/rcu/tree.c:1068
rcu_read_lock_sched_held+0x97/0x130 kernel/rcu/update.c:115
trace_rtc_timer_fired include/trace/events/rtc.h:196 [inline]
rtc_timer_do_work+0x7e5/0xf00 drivers/rtc/interface.c:920
process_one_work+0x98e/0x1760 kernel/workqueue.c:2153
worker_thread+0x98/0xe40 kernel/workqueue.c:2296
kthread+0x357/0x430 kernel/kthread.c:246
ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:413


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