On 08/02/2010 11:35 AM, Arjan Koers wrote:
On 2010-08-02 22:26, Zachary Amsden wrote:
On 08/02/2010 04:43 AM, Glauber Costa wrote:
On Sat, Jul 31, 2010 at 01:55:10PM -1000, Zachary Amsden wrote:
On 07/31/2010 06:36 AM, Arjan Koers wrote:
On 2010-07-31 13:53, Arjan Koers wrote:
The kernel boots successfully when CONFIG_PRINTK_TIME is not set.
The problem occurs when this message is printed:
[ 0.016000] kvm-clock: cpu 1, msr 0:1511c01, secondary cpu clock
When I disable that printk, the kernel boots with
CONFIG_PRINTK_TIME=y
--- a/arch/x86/kernel/kvmclock.c
+++ b/arch/x86/kernel/kvmclock.c
@@ -131,8 +131,8 @@ static int kvm_register_clock(char *txt)
int low, high;
low = (int)__pa(&per_cpu(hv_clock, cpu)) | 1;
high = ((u64)__pa(&per_cpu(hv_clock, cpu))>> 32);
- printk(KERN_INFO "kvm-clock: cpu %d, msr %x:%x, %s\n",
- cpu, high, low, txt);
+ /*printk(KERN_INFO "kvm-clock: cpu %d, msr %x:%x, %s\n",
+ cpu, high, low, txt);*/
return native_write_msr_safe(msr_kvm_system_time, low, high);
}
So the problem appears to be that the clock of the second CPU
is used too soon (or that clock setup should finish earlier).
That's almost hilarious. The printk from setting up the kvm clock
is invoking the kvm clock before it is setup.
There's no reason other printks couldn't do the same thing, however.
I think it's safest to keep an initialized flag and check for it
before attempting to return a meaningful value.
I was on vacations, just got back.
I think it is safe to just patch our own use of it. Before that, all
other
printks will be handled by the main cpu anyway, since it'll be the
only one active
at the moment. The only possible offenders for this are us, and the
cpu initialization
code, which is already fragile in multiple ways anyway.
A flag would only make things more complicated and dirty
Can we just do this?
Sorry, the patch doesn't help. See line 68 in my debug log:
65: ffff880001411c00 1b68905d7 156558001892 6e10a 1b6c0631e 375d47 13c5ce 15655813de60
66: ffff880001411c00 1b68905d7 156558001892 6e10a 1b6c0653b 375f64 13c68f 15655813df21
67: ffff880001411c00 1b68905d7 156558001892 6e10a 1b6c06746 37616f 13c74a 15655813dfdc
68: ffff880001511c00 1967ac192 15654c8d826a 63c6c 3bf58bf0ea18 3bf3f5762886 15695466a1e5 2acea0f4244f
This is a separate bug. See attached patch (it won't apply, it's part
of a series, but shows the bug).
69: ffff880001411c00 1b6f3fbda 156558264b1e 6e10e 1b6f424aa 28d0 e93 1565582659b1
70: ffff880001411c00 1b6f3fbda 156558264b1e 6e10e 1b6f4a1e0 a606 3b4b 156558268669
71: ffff880001411c00 1b6f3fbda 156558264b1e 6e10e 1b6f4ba63 be89 440b 156558268f29
72: ffff880001411c00 1b6f3fbda 156558264b1e 6e10e 1b6f4d8e7 dd0d 4ef1 156558269a0f
73: ffff880001511c00 3bf58bf16356 15655825e74b 40496 3bf58bf4d52c 371d6 13aef 15655827223a
74: ffff880001511c00 3bf58bf16356 15655825e74b 40496 3bf58bf4ebec 38896 1430f 156558272a5a
I don't think that pvclock_clocksource_read is receiving
completely random uninitialized data. The values in shadow
are wrong, but could be interpreted as valid data
(shadow.tsc_to_nsec_mul = b6dc43b6, shadow.tsc_shift = ffffffff,
shadow.flags = 0 and shadow.version is always even).
Copied from the first CPU possibly?
From 3823c018162dc708b543cbdc680a4c7d63533fee Mon Sep 17 00:00:00 2001
From: Zachary Amsden <zamsden@xxxxxxxxxx>
Date: Sat, 29 May 2010 17:52:46 -1000
Subject: [KVM V2 04/25] Fix SVM VMCB reset
Cc: Avi Kivity <avi@xxxxxxxxxx>,
Marcelo Tosatti <mtosatti@xxxxxxxxxx>,
Glauber Costa <glommer@xxxxxxxxxx>,
linux-kernel@xxxxxxxxxxxxxxx
On reset, VMCB TSC should be set to zero. Instead, code was setting
tsc_offset to zero, which passes through the underlying TSC.
Signed-off-by: Zachary Amsden <zamsden@xxxxxxxxxx>
---
arch/x86/kvm/svm.c | 2 +-
1 files changed, 1 insertions(+), 1 deletions(-)
diff --git a/arch/x86/kvm/svm.c b/arch/x86/kvm/svm.c
index 760c86e..46856d2 100644
--- a/arch/x86/kvm/svm.c
+++ b/arch/x86/kvm/svm.c
@@ -781,7 +781,7 @@ static void init_vmcb(struct vcpu_svm *svm)
control->iopm_base_pa = iopm_base;
control->msrpm_base_pa = __pa(svm->msrpm);
- control->tsc_offset = 0;
+ guest_write_tsc(&svm->vcpu, 0);
control->int_ctl = V_INTR_MASKING_MASK;
init_seg(&save->es);
--
1.7.1