syzbot


INFO: task hung in vhost_dev_ioctl

Status: closed as invalid on 2022/02/08 09:50
Subsystems: kvm net virtualization
[Documentation on labels]
First crash: 823d, last: 823d

Sample crash report:
INFO: task syz-executor.1:9492 blocked for more than 143 seconds.
      Not tainted 5.16.0-rc6-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.1  state:D stack:27088 pid: 9492 ppid:  3630 flags:0x00004004
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:4972 [inline]
 __schedule+0xb72/0x1460 kernel/sched/core.c:6253
 schedule+0x12b/0x1f0 kernel/sched/core.c:6326
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6385
 __mutex_lock_common+0xd1f/0x2590 kernel/locking/mutex.c:680
 __mutex_lock kernel/locking/mutex.c:740 [inline]
 mutex_lock_nested+0x1a/0x20 kernel/locking/mutex.c:792
 memory_access_ok drivers/vhost/vhost.c:799 [inline]
 vhost_set_memory drivers/vhost/vhost.c:1463 [inline]
 vhost_dev_ioctl+0xdf3/0x12b0 drivers/vhost/vhost.c:1768
 vhost_net_ioctl+0x2a5/0x1d10 drivers/vhost/net.c:1735
 vfs_ioctl fs/ioctl.c:51 [inline]
 __do_sys_ioctl fs/ioctl.c:874 [inline]
 __se_sys_ioctl+0xfb/0x170 fs/ioctl.c:860
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x44/0xd0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f5712c6be99
RSP: 002b:00007f57115c0168 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007f5712d7f030 RCX: 00007f5712c6be99
RDX: 0000000020000300 RSI: 000000004008af03 RDI: 0000000000000005
RBP: 00007f5712cc5ff1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 00007fffd5c9fe2f R14: 00007f57115c0300 R15: 0000000000022000
 </TASK>
INFO: task syz-executor.1:9495 blocked for more than 143 seconds.
      Not tainted 5.16.0-rc6-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.1  state:D stack:27792 pid: 9495 ppid:  3630 flags:0x00004004
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:4972 [inline]
 __schedule+0xb72/0x1460 kernel/sched/core.c:6253
 schedule+0x12b/0x1f0 kernel/sched/core.c:6326
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6385
 __mutex_lock_common+0xd1f/0x2590 kernel/locking/mutex.c:680
 __mutex_lock kernel/locking/mutex.c:740 [inline]
 mutex_lock_nested+0x1a/0x20 kernel/locking/mutex.c:792
 vhost_net_ioctl+0x292/0x1d10 drivers/vhost/net.c:1734
 vfs_ioctl fs/ioctl.c:51 [inline]
 __do_sys_ioctl fs/ioctl.c:874 [inline]
 __se_sys_ioctl+0xfb/0x170 fs/ioctl.c:860
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x44/0xd0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f5712c6be99
RSP: 002b:00007f571159f168 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007f5712d7f100 RCX: 00007f5712c6be99
RDX: 0000000020000280 RSI: 000000004028af11 RDI: 0000000000000005
RBP: 00007f5712cc5ff1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 00007fffd5c9fe2f R14: 00007f571159f300 R15: 0000000000022000
 </TASK>

Showing all locks held in the system:
1 lock held by khungtaskd/27:
 #0: ffffffff8cb1de00 (rcu_read_lock){....}-{1:2}, at: rcu_lock_acquire+0x0/0x30
2 locks held by getty/3279:
 #0: ffff88814abdf098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x21/0x70 drivers/tty/tty_ldisc.c:252
 #1: ffffc90002b962e8 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0x6c5/0x1c60 drivers/tty/n_tty.c:2113
2 locks held by syz-executor.1/9492:
 #0: ffff88807ea90070 (&dev->mutex#5){+.+.}-{3:3}, at: vhost_net_ioctl+0x292/0x1d10 drivers/vhost/net.c:1734
 #1: ffff88807ea90218 (&vq->mutex){+.+.}-{3:3}, at: memory_access_ok drivers/vhost/vhost.c:799 [inline]
 #1: ffff88807ea90218 (&vq->mutex){+.+.}-{3:3}, at: vhost_set_memory drivers/vhost/vhost.c:1463 [inline]
 #1: ffff88807ea90218 (&vq->mutex){+.+.}-{3:3}, at: vhost_dev_ioctl+0xdf3/0x12b0 drivers/vhost/vhost.c:1768
1 lock held by syz-executor.1/9495:
 #0: ffff88807ea90070 (&dev->mutex#5){+.+.}-{3:3}, at: vhost_net_ioctl+0x292/0x1d10 drivers/vhost/net.c:1734
1 lock held by vhost-9491/9493:

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

NMI backtrace for cpu 0
CPU: 0 PID: 27 Comm: khungtaskd Not tainted 5.16.0-rc6-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 <TASK>
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0x1dc/0x2d8 lib/dump_stack.c:106
 nmi_cpu_backtrace+0x45f/0x490 lib/nmi_backtrace.c:111
 nmi_trigger_cpumask_backtrace+0x16a/0x280 lib/nmi_backtrace.c:62
 trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
 check_hung_uninterruptible_tasks kernel/hung_task.c:210 [inline]
 watchdog+0xc82/0xcd0 kernel/hung_task.c:295
 kthread+0x468/0x490 kernel/kthread.c:327
 ret_from_fork+0x1f/0x30
 </TASK>
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 2961 Comm: klogd Not tainted 5.16.0-rc6-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
RIP: 0010:__raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:151 [inline]
RIP: 0010:_raw_spin_unlock_irqrestore+0xc3/0x130 kernel/locking/spinlock.c:194
Code: 4c 89 f7 e8 4f 2b ba f7 48 c7 44 24 20 00 00 00 00 9c 8f 44 24 20 42 80 3c 23 00 74 08 4c 89 f7 e8 b2 2a ba f7 f6 44 24 21 02 <75> 4e 41 f7 c7 00 02 00 00 74 01 fb bf 01 00 00 00 e8 c7 f0 43 f7
RSP: 0018:ffffc90001a6f1e0 EFLAGS: 00000046
RAX: 88a3a70587f2c800 RBX: 1ffff9200034de40 RCX: ffffffff90bb6903
RDX: dffffc0000000000 RSI: 0000000000000001 RDI: 0000000000000000
RBP: ffffc90001a6f268 R08: ffffffff818b2860 R09: fffffbfff21ce174
R10: fffffbfff21ce174 R11: 0000000000000000 R12: dffffc0000000000
R13: 1ffff9200034de3c R14: ffffc90001a6f200 R15: 0000000000000246
FS:  00007fd04f692800(0000) GS:ffff8880b9b00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 000000c01d23a730 CR3: 000000007f13d000 CR4: 00000000003506e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <TASK>
 __debug_check_no_obj_freed lib/debugobjects.c:1002 [inline]
 debug_check_no_obj_freed+0x5a2/0x650 lib/debugobjects.c:1023
 free_pages_prepare mm/page_alloc.c:1343 [inline]
 free_pcp_prepare+0x2a5/0xe00 mm/page_alloc.c:1389
 free_unref_page_prepare mm/page_alloc.c:3309 [inline]
 free_unref_page+0x7d/0x580 mm/page_alloc.c:3388
 free_slab mm/slub.c:2033 [inline]
 discard_slab mm/slub.c:2039 [inline]
 __unfreeze_partials+0x1ab/0x200 mm/slub.c:2527
 put_cpu_partial+0x116/0x180 mm/slub.c:2603
 do_slab_free mm/slub.c:3501 [inline]
 ___cache_free+0xe6/0x120 mm/slub.c:3520
 qlist_free_all mm/kasan/quarantine.c:165 [inline]
 kasan_quarantine_reduce+0x151/0x1c0 mm/kasan/quarantine.c:272
 __kasan_slab_alloc+0x2f/0xf0 mm/kasan/common.c:444
 kasan_slab_alloc include/linux/kasan.h:259 [inline]
 slab_post_alloc_hook mm/slab.h:519 [inline]
 slab_alloc_node mm/slub.c:3234 [inline]
 kmem_cache_alloc_node+0x201/0x370 mm/slub.c:3270
 __alloc_skb+0xd8/0x5a0 net/core/skbuff.c:414
 alloc_skb include/linux/skbuff.h:1127 [inline]
 alloc_skb_with_frags+0xab/0x660 net/core/skbuff.c:6078
 sock_alloc_send_pskb+0x928/0xa60 net/core/sock.c:2575
 unix_dgram_sendmsg+0x816/0x2a50 net/unix/af_unix.c:1811
 sock_sendmsg_nosec net/socket.c:704 [inline]
 sock_sendmsg net/socket.c:724 [inline]
 __sys_sendto+0x42e/0x5b0 net/socket.c:2036
 __do_sys_sendto net/socket.c:2048 [inline]
 __se_sys_sendto net/socket.c:2044 [inline]
 __x64_sys_sendto+0xda/0xf0 net/socket.c:2044
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x44/0xd0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7fd04f82e0ac
Code: 89 02 48 c7 c0 ff ff ff ff eb b8 0f 1f 00 41 89 ca 64 8b 04 25 18 00 00 00 85 c0 75 19 45 31 c9 45 31 c0 b8 2c 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 64 c3 0f 1f 00 55 48 83 ec 20 48 89 54 24 10
RSP: 002b:00007ffee9ed80d8 EFLAGS: 00000246 ORIG_RAX: 000000000000002c
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007fd04f82e0ac
RDX: 0000000000000076 RSI: 000055ff1d6141c0 RDI: 0000000000000003
RBP: 000055ff1d60d910 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000004000 R11: 0000000000000246 R12: 0000000000000014
R13: 0000000000000001 R14: 00007fd04f9a977d R15: 00007ffee9ed81e8
 </TASK>
----------------
Code disassembly (best guess):
   0:	4c 89 f7             	mov    %r14,%rdi
   3:	e8 4f 2b ba f7       	callq  0xf7ba2b57
   8:	48 c7 44 24 20 00 00 	movq   $0x0,0x20(%rsp)
   f:	00 00
  11:	9c                   	pushfq
  12:	8f 44 24 20          	popq   0x20(%rsp)
  16:	42 80 3c 23 00       	cmpb   $0x0,(%rbx,%r12,1)
  1b:	74 08                	je     0x25
  1d:	4c 89 f7             	mov    %r14,%rdi
  20:	e8 b2 2a ba f7       	callq  0xf7ba2ad7
  25:	f6 44 24 21 02       	testb  $0x2,0x21(%rsp)
* 2a:	75 4e                	jne    0x7a <-- trapping instruction
  2c:	41 f7 c7 00 02 00 00 	test   $0x200,%r15d
  33:	74 01                	je     0x36
  35:	fb                   	sti
  36:	bf 01 00 00 00       	mov    $0x1,%edi
  3b:	e8 c7 f0 43 f7       	callq  0xf743f107

Crashes (1):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2021/12/26 13:20 upstream 438645193e59 e4f103c4 .config console log report info ci-upstream-kasan-gce-smack-root INFO: task hung in vhost_dev_ioctl
* Struck through repros no longer work on HEAD.