INFO: task hung in debugfs_remove

[syzbot]

Hello,

syzbot found the following crash on:

HEAD commit: fab7352c Merge upstream-f2fs-stable-linux-4.14.y into andr..
git tree: android-4.14
console output: https://syzkaller.appspot.com/x/log.txt?x=1496af80c00000
kernel config: https://syzkaller.appspot.com/x/.config?x=9ed317eef2eaa25
dashboard link: https://syzkaller.appspot.com/bug?extid=b2b116b5b8cd771af754
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+b2b116...@syzkaller.appspotmail.com

[30644] 0 30644 17601 8453 25 4 0
0 syz-executor2
[30649] 0 30649 17601 8229 24 3 0
0 syz-executor2
[30660] 0 30660 17601 8229 24 3 0
0 syz-executor2
[30687] 0 30687 17601 8229 24 3 0
0 syz-executor2
[30690] 0 30690 17601 8453 25 4 0
0 syz-executor2
INFO: task kworker/0:0:13059 blocked for more than 140 seconds.
[30702] 0 30702 17601 8229 24 3 0
0 syz-executor2
[30707] 0 30707 17601 8228 23 3 0
0 syz-executor2
Not tainted 4.14.92+ #5
[30716] 0 30716 17601 8229 24 3 0
0 syz-executor2
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[30724] 0 30724 17601 8229 24 3 0
0 syz-executor2
kworker/0:0 D25280 13059 2 0x80000000
[30730] 0 30730 17601 8229 24 3 0
0 syz-executor2
Workqueue: events delayed_fput
[30748] 0 30748 17667 12554 32 4 0
0 syz-executor3
[30756] 0 30756 17601 8229 24 3 0
0 syz-executor2
[30771] 0 30771 17601 8228 23 3 0
0 syz-executor2
[30783] 0 30783 17601 8229 24 3 0
0 syz-executor2
[30796] 0 30796 17601 8229 24 3 0
0 syz-executor2
[30816] 0 30816 17601 8229 24 3 0
0 syz-executor2
[30823] 0 30823 17601 8229 24 3 0
0 syz-executor2
Call Trace:
[30830] 0 30830 17601 8229 24 3 0
0 syz-executor2
[30831] 0 30831 17601 8229 24 3 0
0 syz-executor2
[30839] 0 30839 17601 8229 24 3 0
0 syz-executor2
[30858] 0 30858 17601 8229 24 3 0
0 syz-executor2
[30861] 0 30861 17667 12554 32 4 0
0 syz-executor3
[30865] 0 30865 17601 8229 24 3 0
0 syz-executor2
schedule+0x92/0x1c0 kernel/sched/core.c:3490
[30878] 0 30878 17601 8229 24 3 0
0 syz-executor2
schedule_timeout+0x736/0xe80 kernel/time/timer.c:1721
[30885] 0 30885 17601 8229 24 3 0
0 syz-executor2
[30897] 0 30897 17667 12554 32 4 0
0 syz-executor3
[30901] 0 30901 17601 8229 24 3 0
0 syz-executor2
[30922] 0 30922 17667 12554 32 4 0
0 syz-executor3
[30925] 0 30925 17601 8230 24 3 0
0 syz-executor1
do_wait_for_common kernel/sched/completion.c:91 [inline]
__wait_for_common kernel/sched/completion.c:112 [inline]
wait_for_common+0x29c/0x470 kernel/sched/completion.c:123
[30929] 0 30929 17634 8477 25 4 0
0 syz-executor1
[30941] 0 30941 17601 8230 24 3 0
0 syz-executor1
[30945] 0 30945 17634 8232 24 3 0
0 syz-executor1
[30951] 0 30951 17601 8230 24 3 0
0 syz-executor1
[30954] 0 30954 17634 8232 24 3 0
0 syz-executor1
[30968] 0 30968 17601 8230 24 3 0
0 syz-executor1
[30969] 0 30969 17634 8477 25 4 0
0 syz-executor1
[30972] 0 30972 17634 8232 24 3 0
0 syz-executor1
[30981] 0 30981 17634 8456 25 4 0
1000 /group.stat
[30990] 0 30990 17667 12554 32 4 0
0 syz-executor3
__synchronize_srcu+0x12a/0x210 kernel/rcu/srcutree.c:898
[30993] 0 30993 17601 8230 24 3 0
0 syz-executor1
[30994] 0 30994 17634 8477 25 4 0
0 syz-executor1
[30998] 0 30998 17634 8232 24 3 0
0 syz-executor1
[31009] 0 31009 17601 8230 24 3 0
0 syz-executor1
[31012] 0 31012 17634 8232 24 3 0
0 syz-executor1
debugfs_remove fs/debugfs/inode.c:664 [inline]
debugfs_remove+0xc7/0x110 fs/debugfs/inode.c:649
[31027] 0 31027 17667 12552 32 4 0
0 syz-executor2
[31029] 0 31029 17667 12554 32 4 0
0 syz-executor3
[31030] 0 31030 17601 8230 24 3 0
0 syz-executor1
[31033] 0 31033 17634 8477 25 4 0
0 syz-executor1
[31035] 0 31035 17634 8232 24 3 0
0 syz-executor1
binder_release+0x59/0x80 drivers/android/binder.c:5074
[31043] 0 31043 17601 8230 24 3 0
0 syz-executor1
__fput+0x25e/0x700 fs/file_table.c:210
[31044] 0 31044 17634 8477 25 4 0
0 syz-executor1
[31049] 0 31049 17634 8232 24 3 0
0 syz-executor1
[31057] 0 31057 17634 8477 25 4 0
0 syz-executor1
delayed_fput+0x45/0x60 fs/file_table.c:239
[31067] 0 31067 17667 12552 32 4 0
0 syz-executor2
[31073] 0 31073 17667 12554 32 4 0
0 syz-executor3
process_one_work+0x7c6/0x14e0 kernel/workqueue.c:2114
[31074] 0 31074 17601 8230 24 3 0
0 syz-executor1
[31077] 0 31077 17634 8477 25 4 0
0 syz-executor1
worker_thread+0x5d7/0x1080 kernel/workqueue.c:2248
[31079] 0 31079 17634 8232 24 3 0
0 syz-executor1
[31087] 0 31087 17601 8230 24 3 0
0 syz-executor1
[31089] 0 31089 17634 8477 25 4 0
0 syz-executor1
kthread+0x310/0x420 kernel/kthread.c:232
[31094] 0 31094 17634 8232 24 3 0
0 syz-executor1
[31104] 0 31104 17601 8230 24 3 0
0 syz-executor1
[31111] 0 31111 17667 8234 24 3 0
0 syz-executor1
ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:402
[31119] 0 31119 17634 8232 24 3 0
0 syz-executor1

Showing all locks held in the system:
[31121] 0 31121 17634 8477 25 4 0
0 syz-executor1
1 lock held by khungtaskd/23:
#0: (tasklist_lock){.+.+}, at: [<ffffffffae5ff9cc>]
debug_show_all_locks+0x7c/0x21a kernel/locking/lockdep.c:4541
[31123] 0 31123 17634 8456 25 4 0
1000 /group.stat
2 locks held by rsyslogd/1629:
#0: (&mm->mmap_sem){++++}, at: [<ffffffffae4b43e1>]
__do_page_fault+0x271/0xb80 arch/x86/mm/fault.c:1354
[31141] 0 31141 17667 12554 32 4 0
0 syz-executor3
#1: (&ei->i_mmap_sem){++++}, at: [<ffffffffaeb5e19c>]
ext4_filemap_fault+0x7c/0xb0 fs/ext4/inode.c:6183
[31144] 0 31144 17601 8230 24 3 0
0 syz-executor1
2 locks held by getty/1757:
[31147] 0 31147 17634 8232 24 3 0
0 syz-executor1
#0: (&tty->ldisc_sem){++++}, at: [<ffffffffaf137492>]
tty_ldisc_ref_wait+0x22/0x80 drivers/tty/tty_ldisc.c:275
[31154] 0 31154 17601 8230 24 3 0
0 syz-executor1
#1: (&ldata->atomic_read_lock){+.+.}, at: [<ffffffffaf1328b7>]
n_tty_read+0x1f7/0x1700 drivers/tty/n_tty.c:2156
[31159] 0 31159 17634 8236 25 3 0
0 syz-executor2
2 locks held by syz-fuzzer/1782:
#0: (&mm->mmap_sem){++++}, at: [<ffffffffae4b43e1>]
__do_page_fault+0x271/0xb80 arch/x86/mm/fault.c:1354
#1: (&ei->i_mmap_sem){++++}
[31160] 0 31160 17634 8232 24 3 0
0 syz-executor1
, at: [<ffffffffaeb5e19c>] ext4_filemap_fault+0x7c/0xb0 fs/ext4/inode.c:6183
[31169] 0 31169 17601 8230 24 3 0
0 syz-executor1
2 locks held by syz-fuzzer/1784:
#0: (&mm->mmap_sem){++++}, at: [<ffffffffae4b43e1>]
__do_page_fault+0x271/0xb80 arch/x86/mm/fault.c:1354
#1: (&ei->i_mmap_sem){++++}, at: [<ffffffffaeb5e19c>]
ext4_filemap_fault+0x7c/0xb0 fs/ext4/inode.c:6183
[31175] 0 31175 17667 8234 24 3 0
0 syz-executor1
2 locks held by syz-fuzzer/1792:
#0: (&mm->mmap_sem){++++}, at: [<ffffffffae4b43e1>]
__do_page_fault+0x271/0xb80 arch/x86/mm/fault.c:1354
#1: (&ei->i_mmap_sem){++++}, at: [<ffffffffaeb5e19c>]
ext4_filemap_fault+0x7c/0xb0 fs/ext4/inode.c:6183
1 lock held by syz-executor0/2702:
[31185] 0 31185 17634 8456 25 4 0
1000 /group.stat
#0: (&sig->cred_guard_mutex){+.+.}, at: [<ffffffffae96bee1>]
prepare_bprm_creds+0x51/0x110 fs/exec.c:1389
[31197] 0 31197 17667 12554 32 4 0
0 syz-executor3
2 locks held by kworker/0:0/13059:
#0: ("events"){+.+.}, at: [<ffffffffae527d65>]
process_one_work+0x6e5/0x14e0 kernel/workqueue.c:2085
#1: ((delayed_fput_work).work){+.+.}, at: [<ffffffffae527d9b>]
process_one_work+0x71b/0x14e0 kernel/workqueue.c:2089
[31200] 0 31200 17601 8230 24 3 0
0 syz-executor1

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

NMI backtrace for cpu 0
CPU: 0 PID: 23 Comm: khungtaskd Not tainted 4.14.92+ #5
[31201] 0 31201 17634 8477 25 4 0
0 syz-executor1
Call Trace:
__dump_stack lib/dump_stack.c:17 [inline]
dump_stack+0xb9/0x10e lib/dump_stack.c:53
nmi_cpu_backtrace.cold+0x47/0x86 lib/nmi_backtrace.c:101
[31210] 0 31210 17700 8240 25 3 0
0 syz-executor2
[31212] 0 31212 17601 8454 25 4 0
1000 syz-executor4
Sending NMI from CPU 0 to CPUs 1:
[31223] 0 31223 17601 8230 24 3 0
0 syz-executor1
NMI backtrace for cpu 1
CPU: 1 PID: 2 Comm: kthreadd Not tainted 4.14.92+ #5
task: ffff8881da9d1780 task.stack: ffff8881da9f0000
RIP: 0010:debug_lockdep_rcu_enabled+0x0/0x90 kernel/rcu/update.c:299
RSP: 0000:ffff8881da9f75b8 EFLAGS: 00000083
RAX: 0000000000000001 RBX: 0000000000000046 RCX: ffff8881c95c1eb0
RDX: ffff8881da9d1780 RSI: 0000000000000000 RDI: ffff8881da9d1fac
RBP: ffffffffb08cb1b8 R08: 0000000000000001 R09: 0000000000000000
R10: 0000000000000000 R11: ffffffffb1df3128 R12: 0000000000000000
R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000001
FS: 0000000000000000(0000) GS:ffff8881dbb00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 000000000045043d CR3: 000000011c226004 CR4: 00000000001606a0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000600
Call Trace:
trace_lock_acquire include/trace/events/lock.h:13 [inline]
lock_acquire+0x1e6/0x380 kernel/locking/lockdep.c:3990
__raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
_raw_spin_lock+0x2a/0x40 kernel/locking/spinlock.c:152
console_lock_spinning_enable kernel/printk/printk.c:1577 [inline]
console_unlock+0x2b9/0xc60 kernel/printk/printk.c:2388
vprintk_emit+0x128/0x330 kernel/printk/printk.c:1917
vprintk_func+0x58/0x152 kernel/printk/printk_safe.c:401
printk+0xba/0xed kernel/printk/printk.c:1990
dump_tasks mm/oom_kill.c:396 [inline]
dump_header+0x6d8/0x775 mm/oom_kill.c:428
oom_kill_process.cold+0x10/0xc29 mm/oom_kill.c:861
Code: 02 48 89 f8 83 e0 07 83 c0 03 38 d0 7c 04 84 d2 75 0f 8b 93 2c 08 00
00 31 c0 5b 85 d2 0f 94 c0 c3 e8 05 b0 2e 00 eb ea 0f 1f 00 <48> c7 c0 e4
a3 c3 b0 48 ba 00 00 00 00 00 fc ff df 48 89 c1 83


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