INFO: task hung in fsnotify_connector_destroy_workfn (2)

16 views
Skip to first unread message

syzbot

unread,
Apr 17, 2020, 5:30:13 AM4/17/20
to syzkaller...@googlegroups.com
Hello,

syzbot found the following crash on:

HEAD commit: 8488c3f3 Linux 4.19.116
git tree: linux-4.19.y
console output: https://syzkaller.appspot.com/x/log.txt?x=10053c5fe00000
kernel config: https://syzkaller.appspot.com/x/.config?x=f57eb167d8072371
dashboard link: https://syzkaller.appspot.com/bug?extid=6475953811358f45faab
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+647595...@syzkaller.appspotmail.com

NOHZ: local_softirq_pending 08
NOHZ: local_softirq_pending 08
NOHZ: local_softirq_pending 08
INFO: task kworker/u4:1:23 blocked for more than 140 seconds.
Not tainted 4.19.116-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/u4:1 D25664 23 2 0x80000000
Workqueue: events_unbound fsnotify_connector_destroy_workfn
Call Trace:
schedule+0x8d/0x1b0 kernel/sched/core.c:3559
schedule_timeout+0x896/0xf20 kernel/time/timer.c:1782
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+0x26a/0x3c0 kernel/sched/completion.c:136
__synchronize_srcu+0x12e/0x210 kernel/rcu/srcutree.c:936
fsnotify_connector_destroy_workfn+0x49/0xa0 fs/notify/mark.c:174
process_one_work+0x91f/0x1640 kernel/workqueue.c:2155
worker_thread+0x96/0xe20 kernel/workqueue.c:2298
kthread+0x34a/0x420 kernel/kthread.c:246
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415
INFO: task kworker/u4:2:4093 blocked for more than 140 seconds.
Not tainted 4.19.116-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/u4:2 D25792 4093 2 0x80000000
Workqueue: events_unbound fsnotify_mark_destroy_workfn
Call Trace:
schedule+0x8d/0x1b0 kernel/sched/core.c:3559
schedule_timeout+0x896/0xf20 kernel/time/timer.c:1782
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+0x26a/0x3c0 kernel/sched/completion.c:136
__synchronize_srcu+0x12e/0x210 kernel/rcu/srcutree.c:936
fsnotify_mark_destroy_workfn+0xfd/0x330 fs/notify/mark.c:795
process_one_work+0x91f/0x1640 kernel/workqueue.c:2155
worker_thread+0x96/0xe20 kernel/workqueue.c:2298
kthread+0x34a/0x420 kernel/kthread.c:246
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415
INFO: task syz-executor.3:22888 blocked for more than 140 seconds.
Not tainted 4.19.116-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.3 D27072 22888 6774 0x00000004
Call Trace:
schedule+0x8d/0x1b0 kernel/sched/core.c:3559
schedule_timeout+0x896/0xf20 kernel/time/timer.c:1782
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+0x26a/0x3c0 kernel/sched/completion.c:136
__flush_work+0x48b/0x870 kernel/workqueue.c:2928
p9_mux_poll_stop net/9p/trans_fd.c:190 [inline]
p9_conn_destroy net/9p/trans_fd.c:877 [inline]
p9_fd_close+0x290/0x520 net/9p/trans_fd.c:913
p9_client_create+0x98c/0x1400 net/9p/client.c:1084
v9fs_session_init+0x1e7/0x18c0 fs/9p/v9fs.c:421
v9fs_mount+0x79/0x900 fs/9p/vfs_super.c:135
mount_fs+0xa3/0x30c fs/super.c:1261
vfs_kern_mount.part.0+0x68/0x400 fs/namespace.c:961
vfs_kern_mount fs/namespace.c:951 [inline]
do_new_mount fs/namespace.c:2469 [inline]
do_mount+0x4f4/0x2a40 fs/namespace.c:2799
ksys_mount+0xd7/0x150 fs/namespace.c:3015
__do_sys_mount fs/namespace.c:3029 [inline]
__se_sys_mount fs/namespace.c:3026 [inline]
__x64_sys_mount+0xba/0x150 fs/namespace.c:3026
do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x45c889
Code: Bad RIP value.
RSP: 002b:00007ff8da0f7c78 EFLAGS: 00000246 ORIG_RAX: 00000000000000a5
RAX: ffffffffffffffda RBX: 00007ff8da0f86d4 RCX: 000000000045c889
RDX: 0000000020000040 RSI: 0000000020000000 RDI: 0000000000000000
RBP: 000000000076bf00 R08: 0000000020000200 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000ffffffff
R13: 000000000000074c R14: 00000000004ca0ed R15: 000000000076bf0c

Showing all locks held in the system:
2 locks held by kworker/u4:1/23:
#0: 00000000d717fd51 ((wq_completion)"events_unbound"){+.+.}, at: __write_once_size include/linux/compiler.h:220 [inline]
#0: 00000000d717fd51 ((wq_completion)"events_unbound"){+.+.}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: 00000000d717fd51 ((wq_completion)"events_unbound"){+.+.}, at: atomic64_set include/asm-generic/atomic-instrumented.h:40 [inline]
#0: 00000000d717fd51 ((wq_completion)"events_unbound"){+.+.}, at: atomic_long_set include/asm-generic/atomic-long.h:59 [inline]
#0: 00000000d717fd51 ((wq_completion)"events_unbound"){+.+.}, at: set_work_data kernel/workqueue.c:617 [inline]
#0: 00000000d717fd51 ((wq_completion)"events_unbound"){+.+.}, at: set_work_pool_and_clear_pending kernel/workqueue.c:644 [inline]
#0: 00000000d717fd51 ((wq_completion)"events_unbound"){+.+.}, at: process_one_work+0x81a/0x1640 kernel/workqueue.c:2126
#1: 00000000717abfec (connector_reaper_work){+.+.}, at: process_one_work+0x84e/0x1640 kernel/workqueue.c:2130
1 lock held by khungtaskd/1070:
#0: 000000001747feee (rcu_read_lock){....}, at: debug_show_all_locks+0x53/0x265 kernel/locking/lockdep.c:4440
1 lock held by in:imklog/6173:
#0: 00000000b06eaddb (&f->f_pos_lock){+.+.}, at: __fdget_pos+0xe3/0x100 fs/file.c:767
2 locks held by rs:main Q:Reg/6175:
#0: 00000000a8a07ce5 (&f->f_pos_lock){+.+.}, at: __fdget_pos+0xe3/0x100 fs/file.c:767
#1: 00000000aa80543f (sb_writers#3){.+.+}, at: file_start_write include/linux/fs.h:2776 [inline]
#1: 00000000aa80543f (sb_writers#3){.+.+}, at: vfs_write+0x418/0x550 fs/read_write.c:548
3 locks held by kworker/1:4/30279:
2 locks held by kworker/u4:2/4093:
#0: 00000000d717fd51 ((wq_completion)"events_unbound"){+.+.}, at: __write_once_size include/linux/compiler.h:220 [inline]
#0: 00000000d717fd51 ((wq_completion)"events_unbound"){+.+.}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: 00000000d717fd51 ((wq_completion)"events_unbound"){+.+.}, at: atomic64_set include/asm-generic/atomic-instrumented.h:40 [inline]
#0: 00000000d717fd51 ((wq_completion)"events_unbound"){+.+.}, at: atomic_long_set include/asm-generic/atomic-long.h:59 [inline]
#0: 00000000d717fd51 ((wq_completion)"events_unbound"){+.+.}, at: set_work_data kernel/workqueue.c:617 [inline]
#0: 00000000d717fd51 ((wq_completion)"events_unbound"){+.+.}, at: set_work_pool_and_clear_pending kernel/workqueue.c:644 [inline]
#0: 00000000d717fd51 ((wq_completion)"events_unbound"){+.+.}, at: process_one_work+0x81a/0x1640 kernel/workqueue.c:2126
#1: 00000000e4bb1401 ((reaper_work).work){+.+.}, at: process_one_work+0x84e/0x1640 kernel/workqueue.c:2130

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

NMI backtrace for cpu 0
CPU: 0 PID: 1070 Comm: khungtaskd Not tainted 4.19.116-syzkaller #0
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+0x188/0x20d lib/dump_stack.c:118
nmi_cpu_backtrace.cold+0x63/0xa2 lib/nmi_backtrace.c:101
nmi_trigger_cpumask_backtrace+0x1a6/0x1eb lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:203 [inline]
watchdog+0x962/0xe40 kernel/hung_task.c:287
kthread+0x34a/0x420 kernel/kthread.c:246
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 3683 Comm: systemd-journal Not tainted 4.19.116-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
RIP: 0010:memset_erms+0xb/0x10 arch/x86/lib/memset_64.S:67
Code: 03 40 0f b6 f6 48 b8 01 01 01 01 01 01 01 01 48 0f af c6 f3 48 ab 89 d1 f3 aa 4c 89 c8 c3 90 49 89 f9 40 88 f0 48 89 d1 f3 aa <4c> 89 c8 c3 90 49 89 fa 40 0f b6 ce 48 b8 01 01 01 01 01 01 01 01
RSP: 0018:ffff8880946cfd10 EFLAGS: 00000046
RAX: 0000000000000000 RBX: ffff88821bc46800 RCX: 0000000000000000
RDX: 0000000000000010 RSI: 0000000000000000 RDI: ffff888091cffb90
RBP: ffff888091cfeb80 R08: ffff8880946c4700 R09: ffff888091cffb80
R10: ffffed1015ce4732 R11: ffff8880ae723993 R12: ffffea0002473f80
R13: 0000000000000000 R14: 0000000000000000 R15: ffff8880ae736f38
FS: 00007fd3074108c0(0000) GS:ffff8880ae700000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007fd300e75000 CR3: 0000000094054000 CR4: 00000000001406e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
cache_init_objs mm/slab.c:2582 [inline]
cache_grow_begin+0x365/0x8a0 mm/slab.c:2709
cache_alloc_refill mm/slab.c:3049 [inline]
____cache_alloc mm/slab.c:3132 [inline]
____cache_alloc mm/slab.c:3115 [inline]
__do_cache_alloc mm/slab.c:3354 [inline]
slab_alloc mm/slab.c:3389 [inline]
kmem_cache_alloc+0x648/0x710 mm/slab.c:3557
getname_flags fs/namei.c:140 [inline]
getname_flags+0xd2/0x5b0 fs/namei.c:129
user_path_at_empty+0x2a/0x50 fs/namei.c:2609
user_path_at include/linux/namei.h:57 [inline]
do_faccessat+0x248/0x7a0 fs/open.c:397
do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x7fd3066cc9c7
Code: 83 c4 08 48 3d 01 f0 ff ff 73 01 c3 48 8b 0d c8 d4 2b 00 f7 d8 64 89 01 48 83 c8 ff c3 66 0f 1f 44 00 00 b8 15 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d a1 d4 2b 00 f7 d8 64 89 01 48
RSP: 002b:00007fff4df71968 EFLAGS: 00000246 ORIG_RAX: 0000000000000015
RAX: ffffffffffffffda RBX: 00007fff4df74880 RCX: 00007fd3066cc9c7
RDX: 00007fd30713da00 RSI: 0000000000000000 RDI: 00005607f73da9a3
RBP: 00007fff4df719a0 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000069 R11: 0000000000000246 R12: 0000000000000000
R13: 0000000000000000 R14: 00007fff4df74880 R15: 00007fff4df71e90


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

unread,
Sep 2, 2020, 6:35:16 AM9/2/20
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