Bug 922285

Summary: kvmclock unit test fails on F18 with -smp 2
Product: [Fedora] Fedora Reporter: Cole Robinson <crobinso>
Component: qemuAssignee: Marcelo Tosatti <mtosatti>
Status: CLOSED NOTABUG QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 18CC: amit.shah, berrange, cfergeau, crobinso, dwmw2, gleb, itamar, jasowang, mtosatti, pbonzini, rjones, scottt.tw, virt-maint
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2013-06-14 21:32:09 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
My AMD host cpuinfo
none
Host dmesg after a reboot and reproducing the test failure
none
kvmunittest-serialize-rdtsc-inside-kvmclock-read.patch none

Description Cole Robinson 2013-03-16 00:18:48 UTC 
$ uname -a
Linux colepc 3.8.1-201.fc18.x86_64 #1 SMP Thu Feb 28 19:23:08 UTC 2013 x86_64 x86_64 x86_64 GNU/Linux

F18 qemu 1.2 and qemu 1.4 from rawhide seem affected.


$ qemu-kvm -enable-kvm -serial stdio -device testdev,chardev=testlog -chardev file,id=testlog,path=test.out -kernel ./x86/kvmclock_test.flat --append "10000000 `date +%s`" -smp 2
enabling apic
enabling apic
kvm-clock: cpu 0, msr 0x:44bf20 
kvm-clock: cpu 1, msr 0x:44bf40 
Wallclock test, threshold 5
Seconds get from host:     1363393013
Seconds get from kvmclock: 1363393014
Offset:                    1
Check the stability of raw cycle ...
Worst warp -112 
Worst warp -117 
Worst warp -236 
Worst warp -276 
Worst warp -280 
Worst warp -302 
Worst warp -458 
Worst warp -1225 
Worst warp -9719 
Worst warp -9726 
Worst warp -10057 
Total vcpus: 2
Test  loops: 10000000
Total warps:  227220
Total stalls: 0
Worst warp:   -10057
Raw cycle is not stable
Monotonic cycle test:
Worst warp -64 
Worst warp -86 
Worst warp -88 
Worst warp -283 
Worst warp -436 
Worst warp -449 
Worst warp -472 
Worst warp -1207 
Worst warp -1218 
Worst warp -1563 
Worst warp -9983 
Worst warp -10036 
Total vcpus: 2
Test  loops: 10000000
Total warps:  324738
Total stalls: 0
Worst warp:   -10036
Measure the performance of raw cycle ...
Total vcpus: 2
Test  loops: 10000000
TSC cycles:  812278784
Measure the performance of adjusted cycle ...
Total vcpus: 2
Test  loops: 10000000
TSC cycles:  789702310


Without -smp 2:

$ qemu-kvm -enable-kvm -serial stdio -device testdev,chardev=testlog -chardev file,id=testlog,path=test.out -kernel ./x86/kvmclock_test.flat --append "10000000 `date +%s`"
enabling apic
kvm-clock: cpu 0, msr 0x:44bf20 
Wallclock test, threshold 5
Seconds get from host:     1363393041
Seconds get from kvmclock: 1363393042
Offset:                    1
Check the stability of raw cycle ...
Total vcpus: 1
Test  loops: 10000000
Total warps:  0
Total stalls: 0
Worst warp:   0
Raw cycle is stable
Monotonic cycle test:
Total vcpus: 1
Test  loops: 10000000
Total warps:  0
Total stalls: 0
Worst warp:   0
Measure the performance of raw cycle ...
Total vcpus: 1
Test  loops: 10000000
TSC cycles:  799635736
Measure the performance of adjusted cycle ...
Total vcpus: 1
Test  loops: 10000000
TSC cycles:  1436678893


Strangely in our internal autotest jobs, which run with -smp 2, there don't seem to be any problems. I've reproduced on two different machines though.
Comment 1 Marcelo Tosatti 2013-03-17 22:25:42 UTC 
Cole,

Please provide more info on the host machine (cat /proc/cpuinfo).

What is the purpose of 

--append "10000000 `date +%s`"

Again?
Comment 2 Cole Robinson 2013-03-17 23:54:52 UTC 
Created attachment 711635 [details]
My AMD host cpuinfo

(In reply to comment #1)
> 
> What is the purpose of 
> 
> --append "10000000 `date +%s`"
> 
> Again?

Not sure, it's in unittests.cfg in kvm-unit-tests.git:

https://git.kernel.org/cgit/virt/kvm/kvm-unit-tests.git/tree/x86/unittests.cfg

I just assumed it was a required parameter.
Comment 3 Marcelo Tosatti 2013-03-20 01:19:01 UTC 
Cole, please gather the following

1) dmesg of the host
2) $ cat /sys/devices/system/clocksource/clocksource0/current_clocksource
Comment 4 Cole Robinson 2013-03-22 21:19:41 UTC 
Created attachment 714805 [details]
Host dmesg after a reboot and reproducing the test failure

$ cat /sys/devices/system/clocksource/clocksource0/current_clocksource
tsc
Comment 5 Marcelo Tosatti 2013-06-14 01:15:17 UTC 
Created attachment 761027 [details]
kvmunittest-serialize-rdtsc-inside-kvmclock-read.patch
Comment 6 Marcelo Tosatti 2013-06-14 01:16:14 UTC 
Cole,

Can you please test the attach patch to kvm-unit-test on your AMD machine? TIA.
Comment 7 Cole Robinson 2013-06-14 13:19:40 UTC 
Seems to fix things:

$ ./x86-run ./x86/kvmclock_test.flat 
qemu-kvm -enable-kvm -serial stdio -device pc-testdev -device isa-debug-exit,iobase=0xf4,iosize=0x4 -kernel ./x86/kvmclock_test.flat --append "10000000 `date +%s`" -smp 2
enabling apic
enabling apic
kvm-clock: cpu 0, msr 0x:44bee0 
kvm-clock: cpu 1, msr 0x:44bf00 
Wallclock test, threshold 5
Seconds get from host:     1371215837
Seconds get from kvmclock: 1371215837
Offset:                    0
Check the stability of raw cycle ...
Total vcpus: 2
Test  loops: 10000000
Total warps:  0
Total stalls: 0
Worst warp:   0
Raw cycle is stable
Monotonic cycle test:
Total vcpus: 2
Test  loops: 10000000
Total warps:  0
Total stalls: 0
Worst warp:   0
Measure the performance of raw cycle ...
Total vcpus: 2
Test  loops: 10000000
TSC cycles:  2617779666
Measure the performance of adjusted cycle ...
Total vcpus: 2
Test  loops: 10000000
TSC cycles:  2627790624

$ echo $?
0


Thanks Marcelo! So is this just a kvm-unit-test bug? If so I'll close the report.
Comment 8 Marcelo Tosatti 2013-06-14 21:32:09 UTC 
Cole, yes its a kvm-unit-test bug. Patch submitted upstream.

Closing bug as agreed (as NOTABUG since its neither qemu/kernel bug). Thanks.