Re: INFO: task hung in p9_fd_close

From: syzbot
Date: Sat Sep 21 2019 - 12:20:45 EST


syzbot has found a reproducer for the following crash on:

HEAD commit: f97c81dc Merge tag 'armsoc-late' of git://git.kernel.org/p..
git tree: upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=171a1555600000
kernel config: https://syzkaller.appspot.com/x/.config?x=61f948934213449f
dashboard link: https://syzkaller.appspot.com/bug?extid=8b41a1365f1106fd0f33
compiler: clang version 9.0.0 (/home/glider/llvm/clang 80fee25776c2fb61e74c1ecb1a523375c2500b69)
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=1641d429600000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=11eff9ad600000

IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+8b41a1365f1106fd0f33@xxxxxxxxxxxxxxxxxxxxxxxxx

INFO: task syz-executor635:8085 blocked for more than 143 seconds.
Not tainted 5.3.0+ #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor635 D27848 8085 8070 0x00004004
Call Trace:
context_switch kernel/sched/core.c:3384 [inline]
__schedule+0x82e/0xc50 kernel/sched/core.c:4056
schedule+0x131/0x1e0 kernel/sched/core.c:4123
schedule_timeout+0x46/0x240 kernel/time/timer.c:1869
do_wait_for_common+0x2e7/0x4d0 kernel/sched/completion.c:83
__wait_for_common kernel/sched/completion.c:104 [inline]
wait_for_common kernel/sched/completion.c:115 [inline]
wait_for_completion+0x47/0x60 kernel/sched/completion.c:136
__flush_work+0xd4/0x150 kernel/workqueue.c:3040
__cancel_work_timer+0x420/0x570 kernel/workqueue.c:3127
cancel_work_sync+0x17/0x20 kernel/workqueue.c:3163
p9_conn_destroy net/9p/trans_fd.c:868 [inline]
p9_fd_close+0x297/0x3c0 net/9p/trans_fd.c:898
p9_client_create+0x974/0xee0 net/9p/client.c:1068
v9fs_session_init+0x192/0x18e0 fs/9p/v9fs.c:406
v9fs_mount+0x82/0x860 fs/9p/vfs_super.c:124
legacy_get_tree+0xf9/0x1a0 fs/fs_context.c:659
vfs_get_tree+0x8f/0x380 fs/super.c:1542
do_new_mount fs/namespace.c:2825 [inline]
do_mount+0x16c7/0x2510 fs/namespace.c:3145
ksys_mount+0xcc/0x100 fs/namespace.c:3354
__do_sys_mount fs/namespace.c:3368 [inline]
__se_sys_mount fs/namespace.c:3365 [inline]
__x64_sys_mount+0xbf/0xd0 fs/namespace.c:3365
do_syscall_64+0xf7/0x1c0 arch/x86/entry/common.c:290
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x447909
Code: e8 5c 14 03 00 48 83 c4 18 c3 0f 1f 80 00 00 00 00 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 0f 83 9b 0c fc ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007eff1aea0db8 EFLAGS: 00000246 ORIG_RAX: 00000000000000a5
RAX: ffffffffffffffda RBX: 00000000006ddc78 RCX: 0000000000447909
RDX: 00000000200005c0 RSI: 0000000020000540 RDI: 0000000000000000
RBP: 00000000006ddc70 R08: 0000000020000680 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000006ddc7c
R13: 00007ffc4e6377ef R14: 00007eff1aea19c0 R15: 000000000000002d

Showing all locks held in the system:
2 locks held by kworker/1:1/22:
#0: ffff8880aa4278e8 ((wq_completion)events){+.+.}, at: spin_unlock_irq include/linux/spinlock.h:388 [inline]
#0: ffff8880aa4278e8 ((wq_completion)events){+.+.}, at: process_one_work+0x75d/0x10e0 kernel/workqueue.c:2242
#1: ffff8880a9a3fd78 ((work_completion)(&m->wq)){+.+.}, at: process_one_work+0x79f/0x10e0 kernel/workqueue.c:2244
1 lock held by khungtaskd/1053:
#0: ffffffff888d3900 (rcu_read_lock){....}, at: rcu_lock_acquire+0x4/0x30 include/linux/rcupdate.h:207
1 lock held by rsyslogd/7959:
#0: ffff8880a99f1e20 (&f->f_pos_lock){+.+.}, at: __fdget_pos+0x243/0x2e0 fs/file.c:801
2 locks held by getty/8049:
#0: ffff8880a602d450 (&tty->ldisc_sem){++++}, at: tty_ldisc_ref_wait+0x25/0x70 drivers/tty/tty_ldisc.c:272
#1: ffffc90005f212e0 (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x221/0x1b00 drivers/tty/n_tty.c:2156
2 locks held by getty/8050:
#0: ffff8880a902ac50 (&tty->ldisc_sem){++++}, at: tty_ldisc_ref_wait+0x25/0x70 drivers/tty/tty_ldisc.c:272
#1: ffffc90005f092e0 (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x221/0x1b00 drivers/tty/n_tty.c:2156
2 locks held by getty/8051:
#0: ffff88809c0f1750 (&tty->ldisc_sem){++++}, at: tty_ldisc_ref_wait+0x25/0x70 drivers/tty/tty_ldisc.c:272
#1: ffffc90005f312e0 (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x221/0x1b00 drivers/tty/n_tty.c:2156
2 locks held by getty/8052:
#0: ffff88809e344b90 (&tty->ldisc_sem){++++}, at: tty_ldisc_ref_wait+0x25/0x70 drivers/tty/tty_ldisc.c:272
#1: ffffc90005f152e0 (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x221/0x1b00 drivers/tty/n_tty.c:2156
2 locks held by getty/8053:
#0: ffff88809e344310 (&tty->ldisc_sem){++++}, at: tty_ldisc_ref_wait+0x25/0x70 drivers/tty/tty_ldisc.c:272
#1: ffffc90005f1d2e0 (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x221/0x1b00 drivers/tty/n_tty.c:2156
2 locks held by getty/8054:
#0: ffff88809c8aa410 (&tty->ldisc_sem){++++}, at: tty_ldisc_ref_wait+0x25/0x70 drivers/tty/tty_ldisc.c:272
#1: ffffc90005f2d2e0 (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x221/0x1b00 drivers/tty/n_tty.c:2156
2 locks held by getty/8055:
#0: ffff8880a0267310 (&tty->ldisc_sem){++++}, at: tty_ldisc_ref_wait+0x25/0x70 drivers/tty/tty_ldisc.c:272
#1: ffffc90005f012e0 (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x221/0x1b00 drivers/tty/n_tty.c:2156

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

NMI backtrace for cpu 0
CPU: 0 PID: 1053 Comm: khungtaskd Not tainted 5.3.0+ #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+0x1d8/0x2f8 lib/dump_stack.c:113
nmi_cpu_backtrace+0xaf/0x1a0 lib/nmi_backtrace.c:101
nmi_trigger_cpumask_backtrace+0x174/0x290 lib/nmi_backtrace.c:62
arch_trigger_cpumask_backtrace+0x10/0x20 arch/x86/kernel/apic/hw_nmi.c:38
trigger_all_cpu_backtrace+0x17/0x20 include/linux/nmi.h:146
check_hung_uninterruptible_tasks kernel/hung_task.c:205 [inline]
watchdog+0xbb9/0xbd0 kernel/hung_task.c:289
kthread+0x332/0x350 kernel/kthread.c:255
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:352
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 0 Comm: swapper/1 Not tainted 5.3.0+ #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
RIP: 0010:check_preemption_disabled+0x6/0x2a0 lib/smp_processor_id.c:13
Code: 90 90 90 90 55 48 89 e5 e8 a7 b2 2e fe 48 c7 c7 79 91 38 88 48 c7 c6 10 72 4e 88 e8 04 00 00 00 5d c3 66 90 55 48 89 e5 41 57 <41> 56 41 55 41 54 53 48 83 ec 10 49 89 f6 49 89 ff e8 74 b2 2e fe
RSP: 0018:ffff8880aeb09ee0 EFLAGS: 00000093
RAX: ffffffff83448fc9 RBX: 0000000000000004 RCX: ffff8880a98c2340
RDX: 0000000000000000 RSI: ffffffff884e7210 RDI: ffffffff88389179
RBP: ffff8880aeb09ee8 R08: ffffffff816701e0 R09: fffffbfff117c3cd
R10: fffffbfff117c3cd R11: 0000000000000000 R12: 1ffff11015d64eaf
R13: ffff8880aeb00000 R14: dffffc0000000000 R15: ffff8880aeb2757c
FS: 0000000000000000(0000) GS:ffff8880aeb00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: ffffffffff600400 CR3: 00000000a3d38000 CR4: 00000000001406e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
<IRQ>
debug_smp_processor_id+0x1c/0x20 lib/smp_processor_id.c:57
tick_nohz_stop_idle kernel/time/tick-sched.c:535 [inline]
tick_nohz_irq_enter kernel/time/tick-sched.c:1255 [inline]
tick_irq_enter+0xbd/0x3e0 kernel/time/tick-sched.c:1274
irq_enter+0x52/0xc0 kernel/softirq.c:354
scheduler_ipi+0xb3/0x4a0 kernel/sched/core.c:2337
smp_reschedule_interrupt+0x7a/0xa0 arch/x86/kernel/smp.c:244
reschedule_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:854
</IRQ>
RIP: 0010:native_safe_halt+0xe/0x10 arch/x86/include/asm/irqflags.h:61
Code: 3c fa eb ae 89 d9 80 e1 07 80 c1 03 38 c1 7c ba 48 89 df e8 94 ab 3c fa eb b0 90 90 e9 07 00 00 00 0f 00 2d b6 99 52 00 fb f4 <c3> 90 e9 07 00 00 00 0f 00 2d a6 99 52 00 f4 c3 90 90 55 48 89 e5
RSP: 0018:ffff8880a98cfe10 EFLAGS: 00000286 ORIG_RAX: ffffffffffffff02
RAX: 1ffffffff1115179 RBX: ffff8880a98c2340 RCX: dffffc0000000000
RDX: 0000000000000000 RSI: ffffffff812ba81a RDI: ffff8880a98c2b80
RBP: ffff8880a98cfe18 R08: ffff8880a98c2b98 R09: ffffed1015318469
R10: ffffed1015318469 R11: 0000000000000000 R12: dffffc0000000000
R13: 1ffff11015318468 R14: dffffc0000000000 R15: 1ffffffff1115177
arch_cpu_idle+0xa/0x10 arch/x86/kernel/process.c:571
default_idle_call+0x59/0xa0 kernel/sched/idle.c:94
cpuidle_idle_call kernel/sched/idle.c:154 [inline]
do_idle+0x140/0x670 kernel/sched/idle.c:264
cpu_startup_entry+0x25/0x30 kernel/sched/idle.c:356
start_secondary+0x384/0x410 arch/x86/kernel/smpboot.c:264
secondary_startup_64+0xa4/0xb0 arch/x86/kernel/head_64.S:241