Re: kvm: deadlock between kvm_io_bus_register_dev/kvm_hv_set_msr_common

[Dmitry Vyukov]

[resending an plain test]

Hello,

While running syzkaller fuzzer I am getting tasks deadlocked at the
following stacks. Seems that they are waiting for each other:

# cat /proc/6715/task/*/stack
[<ffffffff815ba488>] __synchronize_srcu+0x2f8/0x4a0 kernel/rcu/srcu.c:448
[<ffffffff815ba693>] synchronize_srcu_expedited+0x13/0x20 kernel/rcu/srcu.c:510
[<ffffffff810884db>] kvm_io_bus_register_dev+0x2ab/0x3e0
arch/x86/kvm/../../../virt/kvm/kvm_main.c:3559
[<ffffffff8117f4a6>] kvm_create_pit+0x5c6/0x8c0 arch/x86/kvm/i8254.c:694
[<ffffffff810df9b3>] kvm_arch_vm_ioctl+0x14d3/0x24b0 arch/x86/kvm/x86.c:3978
[<ffffffff8108270a>] kvm_vm_ioctl+0x1fa/0x1a70
arch/x86/kvm/../../../virt/kvm/kvm_main.c:3099
[<     inline     >] vfs_ioctl fs/ioctl.c:43
[<ffffffff81abdf24>] do_vfs_ioctl+0x1c4/0x1630 fs/ioctl.c:679
[<     inline     >] SYSC_ioctl fs/ioctl.c:694
[<ffffffff81abf424>] SyS_ioctl+0x94/0xc0 fs/ioctl.c:685
[<ffffffff881a5f85>] entry_SYSCALL_64_fastpath+0x23/0xc6
arch/x86/entry/entry_64.S:209
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff81198f33>] kvm_hv_set_msr_common+0x163/0x2a30
arch/x86/kvm/hyperv.c:1145
[<ffffffff810beedb>] kvm_set_msr_common+0xb0b/0x23a0 arch/x86/kvm/x86.c:2278
[<ffffffff811cdb0d>] vmx_set_msr+0x27d/0xcb0 arch/x86/kvm/vmx.c:3149
[<ffffffff81094479>] kvm_set_msr+0xd9/0x170 arch/x86/kvm/x86.c:1093
[<ffffffff81094823>] do_set_msr+0x123/0x1a0 arch/x86/kvm/x86.c:1122
[<     inline     >] __msr_io arch/x86/kvm/x86.c:2540
[<ffffffff810bd060>] msr_io+0x250/0x460 arch/x86/kvm/x86.c:2577
[<ffffffff810d9f00>] kvm_arch_vcpu_ioctl+0x360/0x4580 arch/x86/kvm/x86.c:3420
[<ffffffff8107aab7>] kvm_vcpu_ioctl+0x237/0x11c0
arch/x86/kvm/../../../virt/kvm/kvm_main.c:2710
[<     inline     >] vfs_ioctl fs/ioctl.c:43
[<ffffffff81abdf24>] do_vfs_ioctl+0x1c4/0x1630 fs/ioctl.c:679
[<     inline     >] SYSC_ioctl fs/ioctl.c:694
[<ffffffff81abf424>] SyS_ioctl+0x94/0xc0 fs/ioctl.c:685
[<ffffffff881a5f85>] entry_SYSCALL_64_fastpath+0x23/0xc6
arch/x86/entry/entry_64.S:209
[<ffffffffffffffff>] 0xffffffffffffffff


Later kernel detects the hang and prints:

INFO: task syz-executor:6729 blocked for more than 120 seconds.
      Not tainted 4.9.0-rc8+ #77
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor    D17168  6729      1 0x00000004
 ffff880037510000 ffff88006aaed1c0 ffff880066046080 ffff88006c176400
 ffff88003ed22d18 ffff8800398bef60 ffffffff8818e77c ffffffff894eefa0
 ffff88003ed236a8 ffff88003ed23680 1ffff10007317dd3 ffff88003ed22d18
Call Trace:
 [<ffffffff8818fedd>] schedule+0x10d/0x460 kernel/sched/core.c:3457
 [<ffffffff881a1378>] schedule_timeout+0x498/0x6c0 kernel/time/timer.c:1738
 [<     inline     >] do_wait_for_common kernel/sched/completion.c:75
 [<     inline     >] __wait_for_common kernel/sched/completion.c:93
 [<     inline     >] wait_for_common kernel/sched/completion.c:101
 [<ffffffff88194f2f>] wait_for_completion+0x2df/0x420
kernel/sched/completion.c:122
 [<ffffffff815ba488>] __synchronize_srcu+0x2f8/0x4a0 kernel/rcu/srcu.c:448
 [<ffffffff815ba693>] synchronize_srcu_expedited+0x13/0x20 kernel/rcu/srcu.c:510
 [<ffffffff810884db>] kvm_io_bus_register_dev+0x2ab/0x3e0
arch/x86/kvm/../../../virt/kvm/kvm_main.c:3559
 [<ffffffff8117f4a6>] kvm_create_pit+0x5c6/0x8c0 arch/x86/kvm/i8254.c:694
 [<ffffffff810df9b3>] kvm_arch_vm_ioctl+0x14d3/0x24b0 arch/x86/kvm/x86.c:3978
 [<ffffffff8108270a>] kvm_vm_ioctl+0x1fa/0x1a70
arch/x86/kvm/../../../virt/kvm/kvm_main.c:3099
 [<     inline     >] vfs_ioctl fs/ioctl.c:43
 [<ffffffff81abdf24>] do_vfs_ioctl+0x1c4/0x1630 fs/ioctl.c:679
 [<     inline     >] SYSC_ioctl fs/ioctl.c:694
 [<ffffffff81abf424>] SyS_ioctl+0x94/0xc0 fs/ioctl.c:685
 [<ffffffff881a5f85>] entry_SYSCALL_64_fastpath+0x23/0xc6
arch/x86/entry/entry_64.S:209

Showing all locks held in the system:
2 locks held by khungtaskd/1330:
 #0:  (rcu_read_lock){......}, at: [<     inline     >]
check_hung_uninterruptible_tasks kernel/hung_task.c:168
 #0:  (rcu_read_lock){......}, at: [<ffffffff816f6fdc>]
watchdog+0x1cc/0xd70 kernel/hung_task.c:239
 #1:  (tasklist_lock){.+.+..}, at: [<ffffffff81560472>]
debug_show_all_locks+0xd2/0x420 kernel/locking/lockdep.c:4329
1 lock held by rsyslogd/6191:
 #0:  (&f->f_pos_lock){+.+.+.}, at: [<ffffffff81aeeef0>]
__fdget_pos+0x140/0x1b0 fs/file.c:781
2 locks held by getty/6279:
 #0:  (&tty->ldisc_sem){++++++}, at: [<ffffffff881a32dc>]
ldsem_down_read+0x3c/0x50 drivers/tty/tty_ldsem.c:367
 #1:  (&ldata->atomic_read_lock){+.+...}, at: [<ffffffff839fcb96>]
n_tty_read+0x316/0x14a0 drivers/tty/n_tty.c:2133
2 locks held by getty/6280:
 #0:  (&tty->ldisc_sem){++++++}, at: [<ffffffff881a32dc>]
ldsem_down_read+0x3c/0x50 drivers/tty/tty_ldsem.c:367
 #1:  (&ldata->atomic_read_lock){+.+...}, at: [<ffffffff839fcb96>]
n_tty_read+0x316/0x14a0 drivers/tty/n_tty.c:2133
2 locks held by getty/6281:
 #0:  (&tty->ldisc_sem){++++++}, at: [<ffffffff881a32dc>]
ldsem_down_read+0x3c/0x50 drivers/tty/tty_ldsem.c:367
 #1:  (&ldata->atomic_read_lock){+.+...}, at: [<ffffffff839fcb96>]
n_tty_read+0x316/0x14a0 drivers/tty/n_tty.c:2133
2 locks held by getty/6282:
 #0:  (&tty->ldisc_sem){++++++}, at: [<ffffffff881a32dc>]
ldsem_down_read+0x3c/0x50 drivers/tty/tty_ldsem.c:367
 #1:  (&ldata->atomic_read_lock){+.+...}, at: [<ffffffff839fcb96>]
n_tty_read+0x316/0x14a0 drivers/tty/n_tty.c:2133
2 locks held by getty/6283:
 #0:  (&tty->ldisc_sem){++++++}, at: [<ffffffff881a32dc>]
ldsem_down_read+0x3c/0x50 drivers/tty/tty_ldsem.c:367
 #1:  (&ldata->atomic_read_lock){+.+...}, at: [<ffffffff839fcb96>]
n_tty_read+0x316/0x14a0 drivers/tty/n_tty.c:2133
2 locks held by getty/6284:
 #0:  (&tty->ldisc_sem){++++++}, at: [<ffffffff881a32dc>]
ldsem_down_read+0x3c/0x50 drivers/tty/tty_ldsem.c:367
 #1:  (&ldata->atomic_read_lock){+.+...}, at: [<ffffffff839fcb96>]
n_tty_read+0x316/0x14a0 drivers/tty/n_tty.c:2133
2 locks held by bash/6294:
 #0:  (&tty->ldisc_sem){++++++}, at: [<ffffffff881a32dc>]
ldsem_down_read+0x3c/0x50 drivers/tty/tty_ldsem.c:367
 #1:  (&ldata->atomic_read_lock){+.+...}, at: [<ffffffff839fcb96>]
n_tty_read+0x316/0x14a0 drivers/tty/n_tty.c:2133
2 locks held by syz-executor/6729:
 #0:  (&kvm->lock){+.+.+.}, at: [<ffffffff810df0f4>]
kvm_arch_vm_ioctl+0xc14/0x24b0 arch/x86/kvm/x86.c:3973
 #1:  (&kvm->slots_lock){+.+.+.}, at: [<ffffffff8117f469>]
kvm_create_pit+0x589/0x8c0 arch/x86/kvm/i8254.c:692
3 locks held by syz-executor/6752:
 #0:  (&vcpu->mutex){+.+.+.}, at: [<ffffffff8106c901>]
vcpu_load+0x21/0x70 arch/x86/kvm/../../../virt/kvm/kvm_main.c:143
 #1:  (&kvm->srcu){......}, at: [<     inline     >] __msr_io
arch/x86/kvm/x86.c:2538
 #1:  (&kvm->srcu){......}, at: [<ffffffff810bcf58>]
msr_io+0x148/0x460 arch/x86/kvm/x86.c:2577
 #2:  (&kvm->lock){+.+.+.}, at: [<ffffffff81198f33>]
kvm_hv_set_msr_common+0x163/0x2a30 arch/x86/kvm/hyperv.c:1145
=============================================


I am on commit 318c8932ddec5c1c26a4af0f3c053784841c598e (Dec 7).