INFO: task hung in vhost_net_stop_vq

From: syzbot
Date: Fri Nov 30 2018 - 17:32:07 EST


Hello,

syzbot found the following crash on:

HEAD commit: ef78e5ec9214 ia64: export node_distance function
git tree: upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=175c2415400000
kernel config: https://syzkaller.appspot.com/x/.config?x=c94f9f0c0363db4b
dashboard link: https://syzkaller.appspot.com/bug?extid=d21e6e297322a900c128
compiler: gcc (GCC) 8.0.1 20180413 (experimental)
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=141db34d400000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=108ef293400000

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

IPv6: ADDRCONF(NETDEV_UP): veth0: link is not ready
IPv6: ADDRCONF(NETDEV_UP): veth1: link is not ready
IPv6: ADDRCONF(NETDEV_CHANGE): veth1: link becomes ready
IPv6: ADDRCONF(NETDEV_CHANGE): veth0: link becomes ready
8021q: adding VLAN 0 to HW filter on device team0
INFO: task syz-executor251:6230 blocked for more than 140 seconds.
Not tainted 4.20.0-rc4+ #132
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor251 D21080 6230 6229 0x80000002
Call Trace:
context_switch kernel/sched/core.c:2831 [inline]
__schedule+0x8cf/0x21d0 kernel/sched/core.c:3472
schedule+0xfe/0x460 kernel/sched/core.c:3516
schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3574
__mutex_lock_common kernel/locking/mutex.c:1002 [inline]
__mutex_lock+0xaff/0x16f0 kernel/locking/mutex.c:1072
mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:1087
vhost_net_stop_vq+0x2d/0x120 drivers/vhost/net.c:1306
vhost_net_stop drivers/vhost/net.c:1320 [inline]
vhost_net_release+0x5b/0x1d0 drivers/vhost/net.c:1352
__fput+0x385/0xa30 fs/file_table.c:278
____fput+0x15/0x20 fs/file_table.c:309
task_work_run+0x1e8/0x2a0 kernel/task_work.c:113
exit_task_work include/linux/task_work.h:22 [inline]
do_exit+0xf86/0x26d0 kernel/exit.c:867
do_group_exit+0x177/0x440 kernel/exit.c:970
__do_sys_exit_group kernel/exit.c:981 [inline]
__se_sys_exit_group kernel/exit.c:979 [inline]
__x64_sys_exit_group+0x3e/0x50 kernel/exit.c:979
do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x445338
Code: 72 6e 20 69 73 20 25 64 0a 00 72 65 67 65 78 3a 20 65 6e 64 20 73 65 61 72 63 68 2c 20 66 6f 75 6e 64 20 25 64 0a 00 23 25 33 <2e> 33 64 00 5f 00 5f 2e 00 31 30 30 00 31 30 31 00 31 30 32 00 31
RSP: 002b:00007ffd228e1cb8 EFLAGS: 00000246 ORIG_RAX: 00000000000000e7
RAX: ffffffffffffffda RBX: 0000000000000001 RCX: 0000000000445338
RDX: 0000000000000001 RSI: 000000000000003c RDI: 0000000000000001
RBP: 00000000004cd650 R08: 00000000000000e7 R09: ffffffffffffffd0
R10: 00007ffd228e1d00 R11: 0000000000000246 R12: 0000000000000001
R13: 00000000006e1320 R14: 000000000000000a R15: 0000000000000000

Showing all locks held in the system:
1 lock held by khungtaskd/1019:
#0: 00000000da98dfa9 (rcu_read_lock){....}, at: debug_show_all_locks+0xd0/0x424 kernel/locking/lockdep.c:4379
1 lock held by rsyslogd/6077:
#0: 00000000a7881970 (&f->f_pos_lock){+.+.}, at: __fdget_pos+0x1bb/0x200 fs/file.c:766
2 locks held by getty/6199:
#0: 0000000051a5383e (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
#1: 00000000e292e313 (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x335/0x1e80 drivers/tty/n_tty.c:2154
2 locks held by getty/6200:
#0: 000000000155ff5f (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
#1: 000000001a79dc08 (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x335/0x1e80 drivers/tty/n_tty.c:2154
2 locks held by getty/6201:
#0: 0000000050da3a04 (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
#1: 000000000068a427 (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x335/0x1e80 drivers/tty/n_tty.c:2154
2 locks held by getty/6202:
#0: 000000004bd50c6d (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
#1: 000000007dde2138 (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x335/0x1e80 drivers/tty/n_tty.c:2154
2 locks held by getty/6203:
#0: 0000000054dc4f51 (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
#1: 0000000087e81f0c (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x335/0x1e80 drivers/tty/n_tty.c:2154
2 locks held by getty/6204:
#0: 000000004f97fe78 (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
#1: 000000009af2a5dd (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x335/0x1e80 drivers/tty/n_tty.c:2154
2 locks held by getty/6205:
#0: 00000000cb15d6f6 (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
#1: 00000000392a1db6 (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x335/0x1e80 drivers/tty/n_tty.c:2154
1 lock held by syz-executor251/6230:
#0: 000000009c6ae67f (&vq->mutex){+.+.}, at: vhost_net_stop_vq+0x2d/0x120 drivers/vhost/net.c:1306
1 lock held by vhost-6470/6471:

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

NMI backtrace for cpu 1
CPU: 1 PID: 1019 Comm: khungtaskd Not tainted 4.20.0-rc4+ #132
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+0x244/0x39d lib/dump_stack.c:113
nmi_cpu_backtrace.cold.2+0x5c/0xa1 lib/nmi_backtrace.c:101
nmi_trigger_cpumask_backtrace+0x1e8/0x22a 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:205 [inline]
watchdog+0xb51/0x1060 kernel/hung_task.c:289
kthread+0x35a/0x440 kernel/kthread.c:246
ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 6471 Comm: vhost-6470 Not tainted 4.20.0-rc4+ #132
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
RIP: 0010:vhost_umem_interval_tree_iter_first drivers/vhost/vhost.c:53 [inline]
RIP: 0010:iotlb_access_ok+0x4a3/0x600 drivers/vhost/vhost.c:1207
Code: ac 8d fb 4d 39 ec 0f 82 a1 00 00 00 e8 96 ab 8d fb 48 8b 45 b8 4c 8b 60 08 49 8d 7c 24 28 48 89 f8 48 c1 e8 03 42 80 3c 38 00 <0f> 85 ef 00 00 00 4d 8b 74 24 28 4d 89 ec 48 8b 7d c8 4c 89 f6 e8
RSP: 0018:ffff8881c263f950 EFLAGS: 00000246
RAX: 1ffff1103af365b5 RBX: ffff8881d79b2d80 RCX: ffffffff85f1df5c
RDX: 0000000000000000 RSI: ffffffff85f1df6a RDI: ffff8881d79b2da8
RBP: ffff8881c263f9c0 R08: ffff8881c024c500 R09: ffffed1034e2406d
R10: ffff8881c263f9f8 R11: ffff8881a712036f R12: ffff8881d79b2d80
R13: 0000000000000000 R14: 0000000000000010 R15: dffffc0000000000
FS: 0000000000000000(0000) GS:ffff8881dae00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: ffffffffff600400 CR3: 00000001d753a000 CR4: 00000000001406f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
vq_iotlb_prefetch+0x10e/0x230 drivers/vhost/vhost.c:1240
handle_rx+0x292/0x1df0 drivers/vhost/net.c:1093
handle_rx_net+0x19/0x20 drivers/vhost/net.c:1234
vhost_worker+0x2ac/0x4c0 drivers/vhost/vhost.c:365
kthread+0x35a/0x440 kernel/kthread.c:246
ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352


---
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 syzkaller@xxxxxxxxxxxxxxxxx

syzbot will keep track of this bug report. See:
https://goo.gl/tpsmEJ#bug-status-tracking for how to communicate with syzbot.
syzbot can test patches for this bug, for details see:
https://goo.gl/tpsmEJ#testing-patches