lkml.org 
[lkml]   [2009]   [Apr]   [11]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
Patch in this message
/
Date
From
SubjectRe: Problem with kvm on -tip
Luis Henriques wrote:
> Hi,
>
> Since I am not sure if this problem has already been reported, here it goes.
>
> My log gets the following messages in -tip tree. I don't know for how long this
> issue is around and whether the problem is on lockdep or on kvm. After the
> first lockdep message, I get a huge amount of BUGs from kvm (which stop only
> when I kill kvm). So, I believe issue is on kvm.
>
> I am running on an AMD64. Please let me know if more info is needed (config,
> etc).
>
> [ 3293.134688] BUG: MAX_LOCK_DEPTH too low!
>

Looks like a genuine issue, need to increase MAX_LOCK_DEPTH. Andrea?

> [ 3293.134704] turning off the locking correctness validator.
> [ 3293.134718] Pid: 5117, comm: kvm Not tainted 2.6.30-rc1-tip-01420-g58e70a8
> #18
> [ 3293.134727] Call Trace:
> [ 3293.134749] [<ffffffff802805f6>] __lock_acquire+0x4c6/0xbf0
> [ 3293.134764] [<ffffffff80280e2e>] lock_acquire+0x10e/0x160
> [ 3293.134780] [<ffffffff802f3760>] ? mm_take_all_locks+0x110/0x150
> [ 3293.134798] [<ffffffff80580c3b>] _spin_lock_nest_lock+0x3b/0x50
> [ 3293.134811] [<ffffffff802f3760>] ? mm_take_all_locks+0x110/0x150
> [ 3293.134823] [<ffffffff802f3760>] mm_take_all_locks+0x110/0x150
> [ 3293.134838] [<ffffffff803093af>] do_mmu_notifier_register+0xdf/0x1f0
> [ 3293.134852] [<ffffffff803094f3>] mmu_notifier_register+0x13/0x20
> [ 3293.134899] [<ffffffffa02edede>] kvm_dev_ioctl+0x1ae/0x360 [kvm]
> [ 3293.134914] [<ffffffff80327a16>] vfs_ioctl+0x36/0xb0
> [ 3293.134927] [<ffffffff80327b22>] do_vfs_ioctl+0x92/0x5c0
> [ 3293.134942] [<ffffffff80273d9b>] ? up_read+0x2b/0x40
> [ 3293.134955] [<ffffffff8032809f>] sys_ioctl+0x4f/0x80
> [ 3293.134971] [<ffffffff8020c1f2>] system_call_fastpath+0x16/0x1b request
>


> [ 3297.598606] BUG: using smp_processor_id() in preemptible [00000000] code: kvm/5118
> [ 3297.598630] caller is kvm_arch_vcpu_ioctl_run+0x61c/0xd10 [kvm]
> [ 3297.598635] Pid: 5118, comm: kvm Not tainted 2.6.30-rc1-tip-01420-g58e70a8 #18
> [ 3297.598638] Call Trace:
> [ 3297.598647] [<ffffffff803d9db3>] debug_smp_processor_id+0xe3/0xf0
> [ 3297.598660] [<ffffffffa02f684c>] kvm_arch_vcpu_ioctl_run+0x61c/0xd10 [kvm]
> [ 3297.598667] [<ffffffff8032de67>] ? file_update_time+0xc7/0x130
> [ 3297.598672] [<ffffffff802ed26b>] ? do_wp_page+0x1eb/0x7e0
> [ 3297.598684] [<ffffffffa02ebb23>] kvm_vcpu_ioctl+0x4b3/0x8f0 [kvm]
> [ 3297.598691] [<ffffffff805804d6>] ? trace_hardirqs_on_thunk+0x3a/0x3f
> [ 3297.598696] [<ffffffff80581a35>] ? do_IRQ+0x95/0x100
> [ 3297.598702] [<ffffffff8025c85a>] ? irq_exit+0x8a/0xc0
> [ 3297.598707] [<ffffffff80327a16>] vfs_ioctl+0x36/0xb0
> [ 3297.598712] [<ffffffff80327b22>] do_vfs_ioctl+0x92/0x5c0
> [ 3297.598716] [<ffffffff8032809f>] sys_ioctl+0x4f/0x80
> [ 3297.598723] [<ffffffff8020c1f2>] system_call_fastpath+0x16/0x1b
>

This might be fixed by the attached patch.


--
I have a truly marvellous patch that fixes the bug which this
signature is too narrow to contain.

From 248a107e6d5d96fe276b48cef98daecec03804cf Mon Sep 17 00:00:00 2001
From: Matt T. Yourst <yourst@users.sourceforge.net>
Date: Tue, 24 Feb 2009 15:28:00 -0300
Subject: [PATCH] KVM: x86: silence preempt warning on kvm_write_guest_time

This issue just appeared in kvm-84 when running on 2.6.28.7 (x86-64)
with PREEMPT enabled.

We're getting syslog warnings like this many (but not all) times qemu
tells KVM to run the VCPU:

BUG: using smp_processor_id() in preemptible [00000000] code:
qemu-system-x86/28938
caller is kvm_arch_vcpu_ioctl_run+0x5d1/0xc70 [kvm]
Pid: 28938, comm: qemu-system-x86 2.6.28.7-mtyrel-64bit
Call Trace:
debug_smp_processor_id+0xf7/0x100
kvm_arch_vcpu_ioctl_run+0x5d1/0xc70 [kvm]
? __wake_up+0x4e/0x70
? wake_futex+0x27/0x40
kvm_vcpu_ioctl+0x2e9/0x5a0 [kvm]
enqueue_hrtimer+0x8a/0x110
_spin_unlock_irqrestore+0x27/0x50
vfs_ioctl+0x31/0xa0
do_vfs_ioctl+0x74/0x480
sys_futex+0xb4/0x140
sys_ioctl+0x99/0xa0
system_call_fastpath+0x16/0x1b

As it turns out, the call trace is messed up due to gcc's inlining, but
I isolated the problem anyway: kvm_write_guest_time() is being used in a
non-thread-safe manner on preemptable kernels.

Basically kvm_write_guest_time()'s body needs to be surrounded by
preempt_disable() and preempt_enable(), since the kernel won't let us
query any per-CPU data (indirectly using smp_processor_id()) without
preemption disabled. The attached patch fixes this issue by disabling
preemption inside kvm_write_guest_time().

[marcelo: surround only __get_cpu_var calls since the warning
is harmless]

Signed-off-by: Marcelo Tosatti <mtosatti@redhat.com>
Signed-off-by: Avi Kivity <avi@redhat.com>
---
arch/x86/kvm/x86.c | 2 ++
1 files changed, 2 insertions(+), 0 deletions(-)

diff --git a/arch/x86/kvm/x86.c b/arch/x86/kvm/x86.c
index a1ecec5..b556b6a 100644
--- a/arch/x86/kvm/x86.c
+++ b/arch/x86/kvm/x86.c
@@ -630,10 +630,12 @@ static void kvm_write_guest_time(struct kvm_vcpu *v)
if ((!vcpu->time_page))
return;

+ preempt_disable();
if (unlikely(vcpu->hv_clock_tsc_khz != __get_cpu_var(cpu_tsc_khz))) {
kvm_set_time_scale(__get_cpu_var(cpu_tsc_khz), &vcpu->hv_clock);
vcpu->hv_clock_tsc_khz = __get_cpu_var(cpu_tsc_khz);
}
+ preempt_enable();

/* Keep irq disabled to prevent changes to the clock */
local_irq_save(flags);
--
1.6.1.1
\
 
 \ /
  Last update: 2009-04-11 14:11    [W:2.338 / U:0.072 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site