Re: [PATCH] kvm: x86: move tracepoints outside extended quiescent state

[Paolo Bonzini <pbonzini@redhat.com>]

On 10/12/2015 19:09, Borislav Petkov wrote:
> On Thu, Dec 10, 2015 at 06:38:57PM +0100, Paolo Bonzini wrote:
>> Invoking tracepoints within kvm_guest_enter/kvm_guest_exit causes a
>> lockdep splat.
>>
>> Cc: stable@vger.kernel.org
>> Reported-by: Borislav Petkov <bp@alien8.de>
>> Signed-off-by: Paolo Bonzini <pbonzini@redhat.com>
>> ---
>>  arch/x86/kvm/svm.c | 4 ++--
>>  arch/x86/kvm/vmx.c | 3 ++-
>>  arch/x86/kvm/x86.c | 2 +-
>>  3 files changed, 5 insertions(+), 4 deletions(-)
> 
> Looks like you missed some...

Yeah, wait_lapic_expire also have to be moved before __kvm_guest_enter.

Paolo

> [  144.296364] kvm: zapping shadow pages for mmio generation wraparound
> [  164.699053] kvm: zapping shadow pages for mmio generation wraparound
> [  312.115767] kvm: zapping shadow pages for mmio generation wraparound
> [  432.277585] kvm: zapping shadow pages for mmio generation wraparound
> 
> [  434.547820] ===============================
> [  434.552020] [ INFO: suspicious RCU usage. ]
> [  434.556223] 4.4.0-rc4+ #1 Not tainted
> [  434.559886] -------------------------------
> [  434.564072] arch/x86/kvm/trace.h:971 suspicious rcu_dereference_check() usage!
> [  434.571303] 
>                other info that might help us debug this:
> 
> [  434.579324] 
>                RCU used illegally from idle CPU!
>                rcu_scheduler_active = 1, debug_locks = 0
> [  434.590209] RCU used illegally from extended quiescent state!
> [  434.595971] 1 lock held by qemu-system-x86/2402:
> [  434.600596]  #0:  (&vcpu->mutex){+.+.+.}, at: [<ffffffffa020872c>] vcpu_load+0x1c/0x80 [kvm]
> [  434.609146] 
>                stack backtrace:
> [  434.613526] CPU: 4 PID: 2402 Comm: qemu-system-x86 Not tainted 4.4.0-rc4+ #1
> [  434.620583] Hardware name: Dell Inc. Precision T3600/0PTTT9, BIOS A13 05/11/2014
> [  434.627987]  0000000000000001 ffff88042f79fcf0 ffffffff813c2cfc ffff880435aa0000
> [  434.635443]  ffff88042f79fd20 ffffffff810c5157 ffff88042fd48000 0000000295a85563
> [  434.642886]  0000000295de483f 0000000000000000 ffff88042f79fd58 ffffffffa023ec6e
> [  434.650334] Call Trace:
> [  434.652804]  [<ffffffff813c2cfc>] dump_stack+0x4e/0x82
> [  434.657950]  [<ffffffff810c5157>] lockdep_rcu_suspicious+0xe7/0x120
> [  434.664239]  [<ffffffffa023ec6e>] wait_lapic_expire+0xfe/0x1e0 [kvm]
> [  434.670606]  [<ffffffffa022183e>] kvm_arch_vcpu_ioctl_run+0x76e/0x19c0 [kvm]
> [  434.677674]  [<ffffffffa0221982>] ? kvm_arch_vcpu_ioctl_run+0x8b2/0x19c0 [kvm]
> [  434.684905]  [<ffffffff81858acc>] ? mutex_lock_killable_nested+0x29c/0x4c0
> [  434.691792]  [<ffffffffa0208b32>] kvm_vcpu_ioctl+0x342/0x700 [kvm]
> [  434.697984]  [<ffffffff810c4a7d>] ? __lock_is_held+0x4d/0x70
> [  434.703655]  [<ffffffff812351ae>] ? __fget+0xfe/0x200
> [  434.708719]  [<ffffffff812291f1>] do_vfs_ioctl+0x301/0x550
> [  434.714208]  [<ffffffff8123531a>] ? __fget_light+0x2a/0x90
> [  434.719700]  [<ffffffff81229481>] SyS_ioctl+0x41/0x70
> [  434.724754]  [<ffffffff8185cb36>] entry_SYSCALL_64_fastpath+0x16/0x7a
> [  437.411818] kvm [2400]: vcpu0 unhandled rdmsr: 0x606
> [  437.416898] kvm [2400]: vcpu0 unhandled rdmsr: 0x34
> 
>