Re: kvm-unit-test failures

[Chris J Arges <chris.j.arges@canonical.com>]

On 09/03/2014 09:59 AM, Paolo Bonzini wrote:
> Il 02/09/2014 21:57, Chris J Arges ha scritto:
>> Seconds get from host:     1409687073
>> Seconds get from kvmclock: 1409333034
>> Offset:                    -354039
>> offset too large!
>> Check the stability of raw cycle ...
>> Worst warp -354462672821748
>> Total vcpus: 2
>> Test  loops: 10000000
>> Total warps:  1
>> Total stalls: 0
>> Worst warp:   -354462672821748
>> Raw cycle is not stable
>> Monotonic cycle test:
>> Worst warp -354455286691490
> 
> Looks like one CPU is not being initialized correctly:
> 
> - The "next" correction in the trace is 18445647546048704244,
>   and (next-2^64) / -354039 is about 3.1*10^9.  This is a pretty
>   plausible value of the TSC frequency.  As a comparison, on my machine
>   I have next=18446366988261784997 and an uptime of 29:12 hours, and
>   the two match nicely with the CPU clock:
> 
>   -(18446366988261784997-2^64) / (29.2 * 3600 * 10^9) = 3.587
> 
>   $ grep -m1 model.name /proc/cpuinfo
>   model name	: Intel(R) Xeon(R) CPU E5-1620 0 @ 3.60GHz
> 
> - The offset in seconds * 10^9 is pretty close to the warp in nanoseconds.
> 
> Can you: 1) try this patch 2) gather a new trace 3) include uptime and
> cpuinfo in your report?  All this without clocksource=hpet of course.
> 
> Thanks,
> 
> Paolo
> 
> diff --git a/x86/kvmclock_test.c b/x86/kvmclock_test.c
> index 52a43fb..f68881c 100644
> --- a/x86/kvmclock_test.c
> +++ b/x86/kvmclock_test.c
> @@ -7,6 +7,9 @@
>  #define DEFAULT_TEST_LOOPS 100000000L
>  #define DEFAULT_THRESHOLD  5L
>  
> +long threshold = DEFAULT_THRESHOLD;
> +int nerr = 0;
> +
>  struct test_info {
>          struct spinlock lock;
>          long loops;               /* test loops */
> @@ -20,8 +23,9 @@ struct test_info {
>  
>  struct test_info ti[4];
>  
> -static int wallclock_test(long sec, long threshold)
> +static void wallclock_test(void *p_sec)
>  {
> +	long sec = *(long *)p_sec;
>          long ksec, offset;
>          struct timespec ts;
>  
> @@ -36,10 +40,8 @@ static int wallclock_test(long sec, long threshold)
>  
>          if (offset > threshold || offset < -threshold) {
>                  printf("offset too large!\n");
> -                return 1;
> +                nerr++;
>          }
> -
> -        return 0;
>  }
>  
>  static void kvm_clock_test(void *data)
> @@ -116,10 +118,9 @@ static int cycle_test(int ncpus, long loops, int check, struct test_info *ti)
>  int main(int ac, char **av)
>  {
>          int ncpus;
> -        int nerr = 0, i;
> +        int i;
>          long loops = DEFAULT_TEST_LOOPS;
>          long sec = 0;
> -        long threshold = DEFAULT_THRESHOLD;
>  
>          if (ac > 1)
>                  loops = atol(av[1]);
> @@ -137,7 +138,8 @@ int main(int ac, char **av)
>                  on_cpu(i, kvm_clock_init, (void *)0);
>  
>          if (ac > 2)
> -                nerr += wallclock_test(sec, threshold);
> +	        for (i = 0; i < ncpus; ++i)
> +	                on_cpu(i, wallclock_test, &sec);
>  
>          printf("Check the stability of raw cycle ...\n");
>          pvclock_set_flags(PVCLOCK_TSC_STABLE_BIT
> 

Here are the results of the trace as you requested:
http://people.canonical.com/~arges/kvm/trace-2.dat.xz

$ uptime
 16:18:31 up 53 min,  1 user,  load average: 1.16, 0.39, 0.17

$ grep -m1 model.name /proc/cpuinfo
model name      : Intel(R) Xeon(R) CPU E5-2697 v3 @ 2.60GHz

Here is the output of the command:
qemu-system-x86_64 -enable-kvm -device pc-testdev -device
isa-debug-exit,iobase=0xf4,iosize=0x4 -display none -serial stdio
-device pci-testdev -kernel x86/kvmclock_test.flat -smp 2 --append
10000000 1409761075
enabling apic
enabling apic
kvm-clock: cpu 0, msr 0x:44e520
kvm-clock: cpu 0, msr 0x:44e520
Wallclock test, threshold 5
Seconds get from host:     1409761075
Seconds get from kvmclock: 1409757927
Offset:                    -3148
offset too large!
Wallclock test, threshold 5
Seconds get from host:     1409761075
Seconds get from kvmclock: 1409757927
Offset:                    -3148
offset too large!
Check the stability of raw cycle ...
Worst warp -3147762665310
Total vcpus: 2
Test  loops: 10000000
Total warps:  1
Total stalls: 0
Worst warp:   -3147762665310
Raw cycle is not stable
Monotonic cycle test:
Worst warp -3142929472775
Total vcpus: 2
Test  loops: 10000000
Total warps:  1
Total stalls: 0
Worst warp:   -3142929472775
Measure the performance of raw cycle ...
Total vcpus: 2
Test  loops: 10000000
TSC cycles:  1242044050
Measure the performance of adjusted cycle ...
Total vcpus: 2
Test  loops: 10000000
TSC cycles:  1242665486
Return value from qemu: 3

--chris