qemu-devel.nongnu.org archive mirror
 help / color / mirror / Atom feed
* [Qemu-devel] Cross-posted : Odd QXL/KVM performance issue with a Windows 7 Guest
       [not found] ` <dd33a398-3c1f-0c92-2318-00ad144e1e5d@fnarfbargle.com>
@ 2019-09-06  8:49   ` Brad Campbell
  2019-09-06 13:38     ` Brad Campbell
                       ` (2 more replies)
  0 siblings, 3 replies; 9+ messages in thread
From: Brad Campbell @ 2019-09-06  8:49 UTC (permalink / raw)
  To: qemu-discuss, qemu-devel

On 2/9/19 6:23 pm, Brad Campbell wrote:

> 
> Here is the holdup :
> 
> 11725@1567416625.003504:qxl_ring_command_check 0 native
> 11725@1567416625.102653:qxl_io_write 0 native addr=0 (QXL_IO_NOTIFY_CMD) 
> val=0 size=1 async=0
> 
> ~100ms delay prior to each logged QXL_IO_NOTIFY_CMD on the AMD box which 
> explains the performance difference. Now I just need to figure out if 
> that lies in the guest, the guest QXL driver, QEMU or SPICE and why it 
> exhibits on the AMD box and not the i7.
> 
> To get to this point, I recompiled the kernel on the i7 box with both 
> AMD and Intel KVM modules. Once that was running I cloned the drive and 
> put it in the AMD box, so the OS, software stack and all dependencies 
> are identical.

Reacp :

I have a machine with a Windows 7 VM which is running on an i7-3770. 
This works perfectly.

Clone the disk and put it in a new(ish) AMD Ryzen 1500x machine and the 
display output using qxl/spice is now limited to ~5-7fps.

I originally cloned the entire machine to keep the software versions 
identical.

To simplify debugging and reproduction I'm now using :
- An identical SPICE version to that on the i7.
- A fresh 64 bit Windows 7 VM.
- The D2D benchmark from Crystalmark 2004R7.

The machine is booted with :

qemu -enable-kvm \
  -m 8192\
  -rtc base=localtime\
  -vga qxl\
  -device qxl\
  -global qxl-vga.guestdebug=3\
  -global qxl-vga.cmdlog=1\
  -global qxl-vga.vram_size=65536\
  -global qxl.vram_size=65536\
  -global qxl-vga.ram_size=65536\
  -global qxl.ram_size=65536\
  -net nic,model=virtio\
  -net tap,ifname=tap0,script=/etc/qemu-ifup,vhost=on\
  -usbdevice tablet\
  -spice port=5930,disable-ticketing\
  -device virtio-serial\
  -chardev spicevmc,id=vdagent,name=vdagent\
  -device virtserialport,chardev=vdagent,name=com.redhat.spice.0\
  -smp 3,maxcpus=3,cores=3,threads=1,sockets=1\
  -cpu qemu64,hv_relaxed,hv_spinlocks=0x1fff,hv_vapic,hv_time \
  -drive 
file=/server/VM/Cadbox.raw,if=virtio,aio=threads,format=raw,cache=unsafe 
-boot c \
  -drive 
file=/server/VM/Cadbox_swap.raw,if=virtio,aio=threads,format=raw,cache=unsafe 
\


The D2D benchmark runs through a series of Sprites (stars) and it just 
shuffles them around the screen.

With KVM enabled I get :

Sprite    10 - 8.66fps
Sprite   100 - 8.47fps
Sprite   500 - 8.45fps
Sprite  1000 - 8.18fps
Sprite  5000 - 7.64fps
Sprite 10000 - 7.26fps

With the identical system, with KVM disabled I get :

Sprite    10 - 28.97fps
Sprite   100 - 27.24fps
Sprite   500 - 23.85fps
Sprite  1000 - 22.00fps
Sprite  5000 - 11.11fps
Sprite 10000 -  4.50fps

On the i7 with the same software version and kvm enabled  :

Sprite    10 - 88.58fps
Sprite   100 - 88.35fps
Sprite   500 - 85.64fps
Sprite  1000 - 83.33fps
Sprite  5000 - 58.08fps
Sprite 10000 - 45.29fps


cpuinfo from the host :
processor	: 7
vendor_id	: AuthenticAMD
cpu family	: 23
model		: 1
model name	: AMD Ryzen 5 1500X Quad-Core Processor
stepping	: 1
microcode	: 0x8001138
cpu MHz		: 2877.596
cache size	: 512 KB
physical id	: 0
siblings	: 8
core id		: 5
cpu cores	: 4
apicid		: 11
initial apicid	: 11
fpu		: yes
fpu_exception	: yes
cpuid level	: 13
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov 
pat pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fxsr_opt 
pdpe1gb rdtscp lm constant_tsc rep_good nopl nonstop_tsc cpuid 
extd_apicid aperfmperf pni pclmulqdq monitor ssse3 fma cx16 sse4_1 
sse4_2 movbe popcnt aes xsave avx f16c rdrand lahf_lm cmp_legacy svm 
extapic cr8_legacy abm sse4a misalignsse 3dnowprefetch osvw skinit wdt 
tce topoext perfctr_core perfctr_nb bpext perfctr_llc mwaitx cpb 
hw_pstate sme ssbd sev ibpb vmmcall fsgsbase bmi1 avx2 smep bmi2 rdseed 
adx smap clflushopt sha_ni xsaveopt xsavec xgetbv1 xsaves clzero irperf 
xsaveerptr arat npt lbrv svm_lock nrip_save tsc_scale vmcb_clean 
flushbyasid decodeassists pausefilter pfthreshold avic v_vmsave_vmload 
vgif overflow_recov succor smca
bugs		: sysret_ss_attrs null_seg spectre_v1 spectre_v2 spec_store_bypass
bogomips	: 6985.80
TLB size	: 2560 4K pages
clflush size	: 64
cache_alignment	: 64
address sizes	: 43 bits physical, 48 bits virtual
power management: ts ttp tm hwpstate eff_freq_ro [13] [14]

qemu configured with : 
PKG_CONFIG_PATH=/usr/local/libvirt/lib/pkgconfig:/usr/local/libvirt/share/pkgconfig/ 
./configure --target-list=x86_64-softmmu --disable-gtk && make -j6
test:~# uname -a

Linux test 5.2.9 #42 SMP Tue Aug 20 16:41:13 AWST 2019 x86_64 GNU/Linux

test:~# zgrep KVM /proc/config.gz
CONFIG_HAVE_KVM=y
CONFIG_HAVE_KVM_IRQCHIP=y
CONFIG_HAVE_KVM_IRQFD=y
CONFIG_HAVE_KVM_IRQ_ROUTING=y
CONFIG_HAVE_KVM_EVENTFD=y
CONFIG_KVM_MMIO=y
CONFIG_KVM_ASYNC_PF=y
CONFIG_HAVE_KVM_MSI=y
CONFIG_HAVE_KVM_CPU_RELAX_INTERCEPT=y
CONFIG_KVM_VFIO=y
CONFIG_KVM_GENERIC_DIRTYLOG_READ_PROTECT=y
CONFIG_KVM_COMPAT=y
CONFIG_HAVE_KVM_IRQ_BYPASS=y
CONFIG_KVM=m
# CONFIG_KVM_INTEL is not set
CONFIG_KVM_AMD=m
# CONFIG_KVM_MMU_AUDIT is not set

test:~# qemu --version
QEMU emulator version 4.1.50 (v4.1.0-714-g90b1e3a)
Copyright (c) 2003-2019 Fabrice Bellard and the QEMU Project developers

To be clear, I'm not chasing benchmarks. This is a real issue with 
trying to run CAD on a Windows 7 VM on a Ryzen machine.

I've tried it on two machines (a 1500x and an 1800x) with the same 
result. The same configuration on the i7 box works perfectly.

I've tried several versions of SPICE, multiple versions of KVM, kernels 
back as far as 4.0 with KVM enabled, different old and new windows VMs 
and driver versions. The only constant is it is limited on the AMD box 
if KVM is enabled.

I was leaning towards it being something in the qemu/spice software 
stack, but the fact that without kvm enabled it goes as fast as the CPU 
will allow it would indicate perhaps the fault likes in some 
relationship with kvm, so I'm cross-posting to qemu-devel to see if this 
jogs someones memory, or if there are any other things I can try to 
attempt to solve this one.

Regards,
Brad


^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: [Qemu-devel] Cross-posted : Odd QXL/KVM performance issue with a Windows 7 Guest
  2019-09-06  8:49   ` [Qemu-devel] Cross-posted : Odd QXL/KVM performance issue with a Windows 7 Guest Brad Campbell
@ 2019-09-06 13:38     ` Brad Campbell
  2019-09-06 14:41       ` Brad Campbell
  2019-09-06 19:03     ` Dr. David Alan Gilbert
  2019-11-05  2:38     ` Brad Campbell
  2 siblings, 1 reply; 9+ messages in thread
From: Brad Campbell @ 2019-09-06 13:38 UTC (permalink / raw)
  To: qemu-devel, qemu-discuss

On 6/9/19 16:49, Brad Campbell wrote:
> On 2/9/19 6:23 pm, Brad Campbell wrote:
> 
>>
>> Here is the holdup :
>>
>> 11725@1567416625.003504:qxl_ring_command_check 0 native
>> 11725@1567416625.102653:qxl_io_write 0 native addr=0 (QXL_IO_NOTIFY_CMD) val=0 size=1 async=0
>>
>> ~100ms delay prior to each logged QXL_IO_NOTIFY_CMD on the AMD box which explains the performance difference. Now I just need to figure out if that lies in the guest, the guest QXL driver, QEMU or SPICE and why it exhibits on the AMD box and not the i7.
>>
>> To get to this point, I recompiled the kernel on the i7 box with both AMD and Intel KVM modules. Once that was running I cloned the drive and put it in the AMD box, so the OS, software stack and all dependencies are identical.
> 
>
Had a bit more of a poke and traced kvm and qxl on both machines at approximately comparative times of the same benchmark. From what I can ascertain in this context ioctl type 0xc008ae67 is KVM_IRQ_LINE_STATUS.

The i7 trace shows maybe 10ms spent hitting that. The Ryzen trace below shows the majority of the frame spent hitting that ioctl (some ~110ms).

i7 :

qxl/guest-0: 161680464256: qxldd: DrvCopyBits
7022@1567775823.999850:kvm_vcpu_ioctl cpu_index 1, type 0xae80, arg (nil)
7022@1567775824.000106:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c970
7022@1567775824.000115:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c980
7022@1567775824.001106:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c970
7022@1567775824.001117:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c980
7022@1567775824.002106:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c970
7022@1567775824.002115:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c980
7022@1567775824.003122:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c970
7022@1567775824.003145:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c980
7022@1567775824.004122:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c970
7022@1567775824.004144:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c980
7022@1567775824.005122:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c970
7022@1567775824.005144:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c980
7022@1567775824.006122:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c970
7022@1567775824.006144:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c980
7022@1567775824.007122:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c970
7022@1567775824.007144:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c980
7022@1567775824.008128:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c970
7022@1567775824.008150:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c980
7022@1567775824.009122:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c970
7022@1567775824.009144:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c980
7022@1567775824.010118:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c970
7022@1567775824.010139:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c980
7022@1567775824.011118:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c970
7022@1567775824.011139:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c980
7022@1567775824.012117:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c970
7022@1567775824.012138:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c980
7022@1567775824.012200:kvm_run_exit cpu_index 1, reason 2
7022@1567775824.012214:qxl_io_write 0 native addr=4 (QXL_IO_NOTIFY_OOM) val=0 size=1 async=0
7022@1567775824.012226:qxl_spice_oom 0
7022@1567775824.012238:kvm_vcpu_ioctl cpu_index 1, type 0xae80, arg (nil)
7022@1567775824.012280:qxl_ring_command_check 0 native
7022@1567775824.012288:qxl_ring_res_push 0 native s#=0 res#=2 last=0x7faee4c2d458 notify=yes
7022@1567775824.012296:qxl_ring_res_push_rest 0 ring 1/8 [2399,2398]
7022@1567775824.012307:qxl_send_events 0 1
7022@1567775824.012319:qxl_ring_cursor_check 0 native
7022@1567775824.012325:qxl_ring_command_check 0 native
7022@1567775824.012332:qxl_ring_cursor_check 0 native
7022@1567775824.012336:qxl_ring_command_check 0 native
7022@1567775824.012342:qxl_ring_cursor_check 0 native
7022@1567775824.012349:qxl_ring_command_check 0 native
7022@1567775824.012367:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c890
7022@1567775824.012388:kvm_run_exit cpu_index 1, reason 2
7022@1567775824.012399:qxl_io_write 0 native addr=3 (QXL_IO_UPDATE_IRQ) val=0 size=1 async=0
7022@1567775824.012416:kvm_vm_ioctl type 0xc008ae67, arg 0x7fb4f5a296b0
7022@1567775824.012426:kvm_vcpu_ioctl cpu_index 1, type 0xae80, arg (nil)
7022@1567775824.012444:kvm_run_exit cpu_index 1, reason 2
7022@1567775824.012452:qxl_io_write 0 native addr=3 (QXL_IO_UPDATE_IRQ) val=0 size=1 async=0
7022@1567775824.012466:kvm_vcpu_ioctl cpu_index 1, type 0xae80, arg (nil)
7022@1567775824.013106:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c970
7022@1567775824.013124:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c980
7022@1567775824.013642:kvm_run_exit cpu_index 1, reason 2
7022@1567775824.013652:qxl_io_write 0 native addr=0 (QXL_IO_NOTIFY_CMD) val=0 size=1 async=0
7022@1567775824.013667:kvm_vcpu_ioctl cpu_index 1, type 0xae80, arg (nil)
7022@1567775824.013726:qxl_ring_cursor_check 0 native
7022@1567775824.013739:qxl_ring_command_check 0 native
161694369320 qxl-0/cmd: cmd @ 0x10000000102d758 draw: surface_id 0 type copy effect opaque src 1000000018e3cf8 (id 16dbe0870780 type 0 flags 0 width 1920 height 1080, fmt 8 flags 0 x 1920 y 1080 stride 7680 palette 0 data 1000000018e3d28) area 1920x1080+0+0 rop 8
7022@1567775824.013816:qxl_ring_command_get 0 native
7022@1567775824.013858:qxl_ring_res_put 0 #res=1
7022@1567775824.013870:qxl_ring_command_check 0 native
7022@1567775824.013886:qxl_ring_cursor_check 0 native
7022@1567775824.013897:qxl_ring_command_check 0 native
7022@1567775824.013909:qxl_ring_command_req_notification 0
7022@1567775824.013918:qxl_ring_cursor_check 0 native
7022@1567775824.013927:qxl_ring_command_check 0 native
7022@1567775824.014106:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c970
7022@1567775824.014127:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c980
7022@1567775824.015104:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c970
7022@1567775824.015117:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c980
7022@1567775824.016105:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c970
7022@1567775824.016115:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c980
7022@1567775824.017104:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c970
7022@1567775824.017114:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c980
7022@1567775824.018105:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c970
7022@1567775824.018114:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c980
7022@1567775824.019105:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c970
7022@1567775824.019114:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c980
7022@1567775824.019820:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c960
7022@1567775824.019855:kvm_run_exit cpu_index 0, reason 2
7022@1567775824.019866:kvm_vcpu_ioctl cpu_index 0, type 0xae80, arg (nil)
7022@1567775824.019877:kvm_run_exit cpu_index 0, reason 2
7022@1567775824.019883:kvm_vcpu_ioctl cpu_index 0, type 0xae80, arg (nil)
7022@1567775824.019902:kvm_run_exit cpu_index 0, reason 2
7022@1567775824.019907:kvm_vcpu_ioctl cpu_index 0, type 0xae80, arg (nil)
7022@1567775824.019916:kvm_run_exit cpu_index 0, reason 2
7022@1567775824.019925:kvm_vm_ioctl type 0xc008ae67, arg 0x7fb4f622a770
7022@1567775824.019939:kvm_vcpu_ioctl cpu_index 0, type 0xae80, arg (nil)
7022@1567775824.019957:kvm_run_exit cpu_index 0, reason 2
7022@1567775824.019962:kvm_vcpu_ioctl cpu_index 0, type 0xae80, arg (nil)
7022@1567775824.020103:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c970
7022@1567775824.020111:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c980
7022@1567775824.021103:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c970
7022@1567775824.021113:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c980
7022@1567775824.022087:kvm_run_exit cpu_index 1, reason 2
7022@1567775824.022099:qxl_io_write 0 native addr=7 (QXL_IO_LOG) val=0 size=1 async=0
7022@1567775824.022108:qxl_io_log 0 qxldd: DrvCopyBits


Ryzen :

qxl/guest-0: 55011750066: qxldd: DrvCopyBits
6725@1567775954.186011:kvm_vcpu_ioctl cpu_index 2, type 0xae80, arg (nil)
6726@1567775954.186567:qxl_ring_res_put 0 #res=1
6694@1567775954.186779:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.186799:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.187777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.187786:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.188777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.188785:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.189785:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.189794:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.190777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.190785:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.191777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.191785:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.192777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.192785:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.193781:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.193794:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.194781:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.194794:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.195781:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.195794:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.196781:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.196795:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.197777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.197786:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.198780:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.198794:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.199779:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.199789:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6725@1567775954.199821:kvm_run_exit cpu_index 2, reason 2
6725@1567775954.199852:qxl_io_write 0 native addr=4 (QXL_IO_NOTIFY_OOM) val=0 size=1 async=0
6725@1567775954.199885:qxl_spice_oom 0
6725@1567775954.199903:kvm_vcpu_ioctl cpu_index 2, type 0xae80, arg (nil)
6726@1567775954.199926:qxl_ring_command_check 0 native
6726@1567775954.199942:qxl_ring_res_push 0 native s#=0 res#=1 last=0x7f1b16c4b598 notify=yes
6726@1567775954.199973:qxl_ring_res_push_rest 0 ring 1/8 [130,129]
6726@1567775954.199994:qxl_send_events 0 1
6726@1567775954.200014:qxl_ring_cursor_check 0 native
6726@1567775954.200035:qxl_ring_command_check 0 native
6694@1567775954.200027:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631e90
6724@1567775954.200083:kvm_run_exit cpu_index 1, reason 2
6724@1567775954.200099:qxl_io_write 0 native addr=3 (QXL_IO_UPDATE_IRQ) val=0 size=1 async=0
6724@1567775954.200126:kvm_vm_ioctl type 0xc008ae67, arg 0x7f1d266df560
6724@1567775954.200148:kvm_vcpu_ioctl cpu_index 1, type 0xae80, arg (nil)
6724@1567775954.200174:kvm_run_exit cpu_index 1, reason 2
6724@1567775954.200200:qxl_io_write 0 native addr=3 (QXL_IO_UPDATE_IRQ) val=0 size=1 async=0
6724@1567775954.200254:kvm_vcpu_ioctl cpu_index 1, type 0xae80, arg (nil)
6694@1567775954.200777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.200797:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.201773:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.201781:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.202779:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.202793:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.203797:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.203832:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.204797:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.204810:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.205779:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.205788:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.206787:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.206800:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.207796:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.207809:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.208796:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.208809:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.209782:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.209791:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.210778:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.210787:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.211796:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.211809:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.212796:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.212809:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.213797:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.213810:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.214796:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.214809:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.215796:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.215809:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.216796:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.216810:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.217779:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.217788:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.218796:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.218809:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.219804:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.219824:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.220780:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.220788:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.221779:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.221787:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.222777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.222785:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.223778:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.223786:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.224777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.224786:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.225777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.225786:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.226777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.226785:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.227777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.227785:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.228777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.228785:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.229780:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.229789:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.230777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.230785:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.231777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.231786:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.232777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.232785:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.233777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.233785:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.234782:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.234791:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.235777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.235785:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.236777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.236785:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.237777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.237785:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.238777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.238785:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.239780:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.239789:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.240777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.240785:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.241777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.241785:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.242777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.242786:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.243777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.243785:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.244777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.244785:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.245777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.245785:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.246777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.246785:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.247777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.247785:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.248777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.248785:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.249784:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.249794:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.250777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.250785:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.251777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.251785:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.252781:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.252794:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.253777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.253786:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.254777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.254785:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.255780:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.255801:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.256777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.256785:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.257779:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.257792:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.258781:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.258794:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.259783:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.259796:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.260780:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.260794:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.261779:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.261792:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.262780:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.262794:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.263775:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.263784:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.264798:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.264811:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.265796:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.265810:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.266798:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.266811:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.267797:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.267810:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.268796:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.268810:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.269799:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.269820:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.270796:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.270809:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.271796:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.271809:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.272796:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.272810:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.273796:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.273809:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.274796:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.274809:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.275796:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.275809:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.276796:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.276810:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.277779:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.277787:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.278779:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.278789:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.279800:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.279821:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.280778:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.280787:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.281795:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.281807:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.282796:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.282809:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.283796:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.283809:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.284796:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.284809:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.285779:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.285788:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.286779:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.286789:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.287777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.287785:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.288778:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.288788:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.289780:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.289788:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.290777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.290786:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.291778:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.291788:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.292777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.292785:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.293778:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.293788:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.294777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.294785:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.295779:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.295788:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.296777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.296785:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.297778:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.297788:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.298777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.298785:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.299781:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.299791:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.300777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.300785:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.301778:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.301787:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6694@1567775954.302777:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.302785:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6725@1567775954.302875:kvm_run_exit cpu_index 2, reason 2
6725@1567775954.302894:qxl_io_write 0 native addr=0 (QXL_IO_NOTIFY_CMD) val=0 size=1 async=0
6725@1567775954.302924:kvm_vcpu_ioctl cpu_index 2, type 0xae80, arg (nil)
6726@1567775954.302940:qxl_ring_cursor_check 0 native
6726@1567775954.302956:qxl_ring_command_check 0 native
55128722604 qxl-0/cmd: cmd @ 0x10000000104b498 draw: surface_id 0 type copy effect opaque src 100000001ecf950 (id d3e0870780 type 0 flags 0 width 1920 height 1080, fmt 8 flags 0 x 1920 y 1080 stride 7680 palette 0 data 100000001ecf980) area 1920x1080+0+0 rop 8
6726@1567775954.303062:qxl_ring_command_get 0 native
6726@1567775954.303119:qxl_ring_command_check 0 native
6726@1567775954.303143:qxl_ring_cursor_check 0 native
6726@1567775954.303160:qxl_ring_command_check 0 native
6726@1567775954.303174:qxl_ring_command_req_notification 0
6694@1567775954.303778:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f30
6694@1567775954.303799:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffc1b631f40
6725@1567775954.304197:kvm_run_exit cpu_index 2, reason 2
6725@1567775954.304231:qxl_io_write 0 native addr=7 (QXL_IO_LOG) val=0 size=1 async=0
6725@1567775954.304260:qxl_io_log 0 qxldd: DrvCopyBits

Does this look familiar to anyone?

Regards,
Brad
-- 
An expert is a person who has found out by his own painful
experience all the mistakes that one can make in a very
narrow field. - Niels Bohr


^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: [Qemu-devel] Cross-posted : Odd QXL/KVM performance issue with a Windows 7 Guest
  2019-09-06 13:38     ` Brad Campbell
@ 2019-09-06 14:41       ` Brad Campbell
  2019-11-05 11:32         ` Alex Bennée
  0 siblings, 1 reply; 9+ messages in thread
From: Brad Campbell @ 2019-09-06 14:41 UTC (permalink / raw)
  To: qemu-devel

On 6/9/19 21:38, Brad Campbell wrote:
> 7022@1567775824.002106:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c970
> 7022@1567775824.002115:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c980
> 7022@1567775824.003122:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c970

> 
> Does this look familiar to anyone?

Ugh. System timer.

So with the timer interrupt removed and an added trace on IRQ > 0:

qxl/guest-0: 79096403248: qxldd: DrvCopyBits
14955@1567780063.149527:kvm_vcpu_ioctl cpu_index 2, type 0xae80, arg (nil)
14956@1567780063.150291:qxl_ring_res_put 0 #res=1
14955@1567780063.163672:kvm_run_exit cpu_index 2, reason 2
14955@1567780063.163688:qxl_io_write 0 native addr=4 (QXL_IO_NOTIFY_OOM) val=0 size=1 async=0
14955@1567780063.163704:qxl_spice_oom 0
14955@1567780063.163720:kvm_vcpu_ioctl cpu_index 2, type 0xae80, arg (nil)
14956@1567780063.163755:qxl_ring_command_check 0 native
14956@1567780063.163779:qxl_ring_res_push 0 native s#=0 res#=1 last=0x7f3c0d44b6e0 notify=yes
14956@1567780063.163816:qxl_ring_res_push_rest 0 ring 1/8 [326,325]
14956@1567780063.163841:qxl_send_events 0 1
14956@1567780063.163868:qxl_ring_cursor_check 0 native
14956@1567780063.163888:qxl_ring_command_check 0 native
14924@1567780063.163879:kvm_set_irq irq 11, level 1, status 1
14954@1567780063.163895:kvm_run_exit cpu_index 1, reason 2
14954@1567780063.163965:qxl_io_write 0 native addr=3 (QXL_IO_UPDATE_IRQ) val=0 size=1 async=0
14954@1567780063.164006:kvm_set_irq irq 11, level 0, status 1
14954@1567780063.164029:kvm_vcpu_ioctl cpu_index 1, type 0xae80, arg (nil)
14954@1567780063.164065:kvm_run_exit cpu_index 1, reason 2
14954@1567780063.164080:qxl_io_write 0 native addr=3 (QXL_IO_UPDATE_IRQ) val=0 size=1 async=0
14954@1567780063.164104:kvm_vcpu_ioctl cpu_index 1, type 0xae80, arg (nil)
14955@1567780063.266778:kvm_run_exit cpu_index 2, reason 2
14955@1567780063.266790:qxl_io_write 0 native addr=0 (QXL_IO_NOTIFY_CMD) val=0 size=1 async=0
14955@1567780063.266809:kvm_vcpu_ioctl cpu_index 2, type 0xae80, arg (nil)
14956@1567780063.266822:qxl_ring_cursor_check 0 native
14956@1567780063.266842:qxl_ring_command_check 0 native
79213750625 qxl-0/cmd: cmd @ 0x10000000104b598 draw: surface_id 0 type copy effect opaque src 100000001fecbf8 (id 9fe0870780 type 0 flags 0 width 1920 height 1080, fmt 8 flags 0 x 1920 y 1080 stride 7680 palette 0 data 100000001fecc28) area 1920x1080+0+0 rop 8
14956@1567780063.266983:qxl_ring_command_get 0 native
14956@1567780063.267044:qxl_ring_command_check 0 native
14956@1567780063.267070:qxl_ring_cursor_check 0 native
14956@1567780063.267087:qxl_ring_command_check 0 native
14956@1567780063.267109:qxl_ring_command_req_notification 0
14955@1567780063.267967:kvm_run_exit cpu_index 2, reason 2
14955@1567780063.267987:qxl_io_write 0 native addr=7 (QXL_IO_LOG) val=0 size=1 async=0
14955@1567780063.268015:qxl_io_log 0 qxldd: DrvCopyBits

So if I'm not mistaken (for the nth time), we have KVM_RUN on cpu index 2 here:

14955@1567780063.163720:kvm_vcpu_ioctl cpu_index 2, type 0xae80, arg (nil)

And it returns here :

14955@1567780063.266778:kvm_run_exit cpu_index 2, reason 2

Does that imply guest code is running for ~100ms on that vcpu?

Brad
-- 
An expert is a person who has found out by his own painful
experience all the mistakes that one can make in a very
narrow field. - Niels Bohr


^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: [Qemu-devel] Cross-posted : Odd QXL/KVM performance issue with a Windows 7 Guest
  2019-09-06  8:49   ` [Qemu-devel] Cross-posted : Odd QXL/KVM performance issue with a Windows 7 Guest Brad Campbell
  2019-09-06 13:38     ` Brad Campbell
@ 2019-09-06 19:03     ` Dr. David Alan Gilbert
  2019-09-07  0:44       ` Brad Campbell
  2019-11-05  2:38     ` Brad Campbell
  2 siblings, 1 reply; 9+ messages in thread
From: Dr. David Alan Gilbert @ 2019-09-06 19:03 UTC (permalink / raw)
  To: Brad Campbell; +Cc: qemu-devel, qemu-discuss

* Brad Campbell (lists2009@fnarfbargle.com) wrote:
> On 2/9/19 6:23 pm, Brad Campbell wrote:
> 
> > 
> > Here is the holdup :
> > 
> > 11725@1567416625.003504:qxl_ring_command_check 0 native
> > 11725@1567416625.102653:qxl_io_write 0 native addr=0 (QXL_IO_NOTIFY_CMD)
> > val=0 size=1 async=0
> > 
> > ~100ms delay prior to each logged QXL_IO_NOTIFY_CMD on the AMD box which
> > explains the performance difference. Now I just need to figure out if
> > that lies in the guest, the guest QXL driver, QEMU or SPICE and why it
> > exhibits on the AMD box and not the i7.
> > 
> > To get to this point, I recompiled the kernel on the i7 box with both
> > AMD and Intel KVM modules. Once that was running I cloned the drive and
> > put it in the AMD box, so the OS, software stack and all dependencies
> > are identical.
> 
> Reacp :
> 
> I have a machine with a Windows 7 VM which is running on an i7-3770. This
> works perfectly.
> 
> Clone the disk and put it in a new(ish) AMD Ryzen 1500x machine and the
> display output using qxl/spice is now limited to ~5-7fps.
> 
> I originally cloned the entire machine to keep the software versions
> identical.
> 
> To simplify debugging and reproduction I'm now using :
> - An identical SPICE version to that on the i7.
> - A fresh 64 bit Windows 7 VM.
> - The D2D benchmark from Crystalmark 2004R7.
> 
> The machine is booted with :
> 
> qemu -enable-kvm \
>  -m 8192\
>  -rtc base=localtime\
>  -vga qxl\
>  -device qxl\
>  -global qxl-vga.guestdebug=3\
>  -global qxl-vga.cmdlog=1\
>  -global qxl-vga.vram_size=65536\
>  -global qxl.vram_size=65536\
>  -global qxl-vga.ram_size=65536\
>  -global qxl.ram_size=65536\
>  -net nic,model=virtio\
>  -net tap,ifname=tap0,script=/etc/qemu-ifup,vhost=on\
>  -usbdevice tablet\
>  -spice port=5930,disable-ticketing\
>  -device virtio-serial\
>  -chardev spicevmc,id=vdagent,name=vdagent\
>  -device virtserialport,chardev=vdagent,name=com.redhat.spice.0\
>  -smp 3,maxcpus=3,cores=3,threads=1,sockets=1\
>  -cpu qemu64,hv_relaxed,hv_spinlocks=0x1fff,hv_vapic,hv_time \

-cpu qemu64 is almost always a bad idea;  does -cpu host help ?

Dave

>  -drive
> file=/server/VM/Cadbox.raw,if=virtio,aio=threads,format=raw,cache=unsafe
> -boot c \
>  -drive
> file=/server/VM/Cadbox_swap.raw,if=virtio,aio=threads,format=raw,cache=unsafe
> \
> 
> 
> The D2D benchmark runs through a series of Sprites (stars) and it just
> shuffles them around the screen.
> 
> With KVM enabled I get :
> 
> Sprite    10 - 8.66fps
> Sprite   100 - 8.47fps
> Sprite   500 - 8.45fps
> Sprite  1000 - 8.18fps
> Sprite  5000 - 7.64fps
> Sprite 10000 - 7.26fps
> 
> With the identical system, with KVM disabled I get :
> 
> Sprite    10 - 28.97fps
> Sprite   100 - 27.24fps
> Sprite   500 - 23.85fps
> Sprite  1000 - 22.00fps
> Sprite  5000 - 11.11fps
> Sprite 10000 -  4.50fps
> 
> On the i7 with the same software version and kvm enabled  :
> 
> Sprite    10 - 88.58fps
> Sprite   100 - 88.35fps
> Sprite   500 - 85.64fps
> Sprite  1000 - 83.33fps
> Sprite  5000 - 58.08fps
> Sprite 10000 - 45.29fps
> 
> 
> cpuinfo from the host :
> processor	: 7
> vendor_id	: AuthenticAMD
> cpu family	: 23
> model		: 1
> model name	: AMD Ryzen 5 1500X Quad-Core Processor
> stepping	: 1
> microcode	: 0x8001138
> cpu MHz		: 2877.596
> cache size	: 512 KB
> physical id	: 0
> siblings	: 8
> core id		: 5
> cpu cores	: 4
> apicid		: 11
> initial apicid	: 11
> fpu		: yes
> fpu_exception	: yes
> cpuid level	: 13
> wp		: yes
> flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat
> pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fxsr_opt pdpe1gb rdtscp
> lm constant_tsc rep_good nopl nonstop_tsc cpuid extd_apicid aperfmperf pni
> pclmulqdq monitor ssse3 fma cx16 sse4_1 sse4_2 movbe popcnt aes xsave avx
> f16c rdrand lahf_lm cmp_legacy svm extapic cr8_legacy abm sse4a misalignsse
> 3dnowprefetch osvw skinit wdt tce topoext perfctr_core perfctr_nb bpext
> perfctr_llc mwaitx cpb hw_pstate sme ssbd sev ibpb vmmcall fsgsbase bmi1
> avx2 smep bmi2 rdseed adx smap clflushopt sha_ni xsaveopt xsavec xgetbv1
> xsaves clzero irperf xsaveerptr arat npt lbrv svm_lock nrip_save tsc_scale
> vmcb_clean flushbyasid decodeassists pausefilter pfthreshold avic
> v_vmsave_vmload vgif overflow_recov succor smca
> bugs		: sysret_ss_attrs null_seg spectre_v1 spectre_v2 spec_store_bypass
> bogomips	: 6985.80
> TLB size	: 2560 4K pages
> clflush size	: 64
> cache_alignment	: 64
> address sizes	: 43 bits physical, 48 bits virtual
> power management: ts ttp tm hwpstate eff_freq_ro [13] [14]
> 
> qemu configured with : PKG_CONFIG_PATH=/usr/local/libvirt/lib/pkgconfig:/usr/local/libvirt/share/pkgconfig/
> ./configure --target-list=x86_64-softmmu --disable-gtk && make -j6
> test:~# uname -a
> 
> Linux test 5.2.9 #42 SMP Tue Aug 20 16:41:13 AWST 2019 x86_64 GNU/Linux
> 
> test:~# zgrep KVM /proc/config.gz
> CONFIG_HAVE_KVM=y
> CONFIG_HAVE_KVM_IRQCHIP=y
> CONFIG_HAVE_KVM_IRQFD=y
> CONFIG_HAVE_KVM_IRQ_ROUTING=y
> CONFIG_HAVE_KVM_EVENTFD=y
> CONFIG_KVM_MMIO=y
> CONFIG_KVM_ASYNC_PF=y
> CONFIG_HAVE_KVM_MSI=y
> CONFIG_HAVE_KVM_CPU_RELAX_INTERCEPT=y
> CONFIG_KVM_VFIO=y
> CONFIG_KVM_GENERIC_DIRTYLOG_READ_PROTECT=y
> CONFIG_KVM_COMPAT=y
> CONFIG_HAVE_KVM_IRQ_BYPASS=y
> CONFIG_KVM=m
> # CONFIG_KVM_INTEL is not set
> CONFIG_KVM_AMD=m
> # CONFIG_KVM_MMU_AUDIT is not set
> 
> test:~# qemu --version
> QEMU emulator version 4.1.50 (v4.1.0-714-g90b1e3a)
> Copyright (c) 2003-2019 Fabrice Bellard and the QEMU Project developers
> 
> To be clear, I'm not chasing benchmarks. This is a real issue with trying to
> run CAD on a Windows 7 VM on a Ryzen machine.
> 
> I've tried it on two machines (a 1500x and an 1800x) with the same result.
> The same configuration on the i7 box works perfectly.
> 
> I've tried several versions of SPICE, multiple versions of KVM, kernels back
> as far as 4.0 with KVM enabled, different old and new windows VMs and driver
> versions. The only constant is it is limited on the AMD box if KVM is
> enabled.
> 
> I was leaning towards it being something in the qemu/spice software stack,
> but the fact that without kvm enabled it goes as fast as the CPU will allow
> it would indicate perhaps the fault likes in some relationship with kvm, so
> I'm cross-posting to qemu-devel to see if this jogs someones memory, or if
> there are any other things I can try to attempt to solve this one.
> 
> Regards,
> Brad
> 
--
Dr. David Alan Gilbert / dgilbert@redhat.com / Manchester, UK


^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: [Qemu-devel] Cross-posted : Odd QXL/KVM performance issue with a Windows 7 Guest
  2019-09-06 19:03     ` Dr. David Alan Gilbert
@ 2019-09-07  0:44       ` Brad Campbell
  2019-09-09 15:22         ` Dr. David Alan Gilbert
  0 siblings, 1 reply; 9+ messages in thread
From: Brad Campbell @ 2019-09-07  0:44 UTC (permalink / raw)
  To: Dr. David Alan Gilbert; +Cc: qemu-devel, qemu-discuss


On 7/9/19 03:03, Dr. David Alan Gilbert wrote:
> * Brad Campbell (lists2009@fnarfbargle.com) wrote:
>> On 2/9/19 6:23 pm, Brad Campbell wrote:
>>
>>> Here is the holdup :
>>>
>>> 11725@1567416625.003504:qxl_ring_command_check 0 native
>>> 11725@1567416625.102653:qxl_io_write 0 native addr=0 (QXL_IO_NOTIFY_CMD)
>>> val=0 size=1 async=0
>>>
>>> ~100ms delay prior to each logged QXL_IO_NOTIFY_CMD on the AMD box which
>>> explains the performance difference. Now I just need to figure out if
>>> that lies in the guest, the guest QXL driver, QEMU or SPICE and why it
>>> exhibits on the AMD box and not the i7.
>>>
>>> To get to this point, I recompiled the kernel on the i7 box with both
>>> AMD and Intel KVM modules. Once that was running I cloned the drive and
>>> put it in the AMD box, so the OS, software stack and all dependencies
>>> are identical.
>> Reacp :
>>
>> I have a machine with a Windows 7 VM which is running on an i7-3770. This
>> works perfectly.
>>
>> Clone the disk and put it in a new(ish) AMD Ryzen 1500x machine and the
>> display output using qxl/spice is now limited to ~5-7fps.
>>
>> I originally cloned the entire machine to keep the software versions
>> identical.
>>
>> To simplify debugging and reproduction I'm now using :
>> - An identical SPICE version to that on the i7.
>> - A fresh 64 bit Windows 7 VM.
>> - The D2D benchmark from Crystalmark 2004R7.
>>
>> The machine is booted with :
>>
>> qemu -enable-kvm \
>>   -m 8192\
>>   -rtc base=localtime\
>>   -vga qxl\
>>   -device qxl\
>>   -global qxl-vga.guestdebug=3\
>>   -global qxl-vga.cmdlog=1\
>>   -global qxl-vga.vram_size=65536\
>>   -global qxl.vram_size=65536\
>>   -global qxl-vga.ram_size=65536\
>>   -global qxl.ram_size=65536\
>>   -net nic,model=virtio\
>>   -net tap,ifname=tap0,script=/etc/qemu-ifup,vhost=on\
>>   -usbdevice tablet\
>>   -spice port=5930,disable-ticketing\
>>   -device virtio-serial\
>>   -chardev spicevmc,id=vdagent,name=vdagent\
>>   -device virtserialport,chardev=vdagent,name=com.redhat.spice.0\
>>   -smp 3,maxcpus=3,cores=3,threads=1,sockets=1\
>>   -cpu qemu64,hv_relaxed,hv_spinlocks=0x1fff,hv_vapic,hv_time \
> -cpu qemu64 is almost always a bad idea;  does -cpu host help ?
>
> Dave


No. I was using -cpu host. I changed it to qemu64 for testing so I could add & remove -enable-kvm for testing without the machine changing drivers about.

Regards,

Brad

-- 
An expert is a person who has found out by his own painful
experience all the mistakes that one can make in a very
narrow field. - Niels Bohr



^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: [Qemu-devel] Cross-posted : Odd QXL/KVM performance issue with a Windows 7 Guest
  2019-09-07  0:44       ` Brad Campbell
@ 2019-09-09 15:22         ` Dr. David Alan Gilbert
  2019-09-12 14:54           ` [Qemu-devel] [Qemu-discuss] " Brad Campbell
  0 siblings, 1 reply; 9+ messages in thread
From: Dr. David Alan Gilbert @ 2019-09-09 15:22 UTC (permalink / raw)
  To: Brad Campbell; +Cc: qemu-devel, qemu-discuss

* Brad Campbell (lists2009@fnarfbargle.com) wrote:
> 
> On 7/9/19 03:03, Dr. David Alan Gilbert wrote:
> > * Brad Campbell (lists2009@fnarfbargle.com) wrote:
> > > On 2/9/19 6:23 pm, Brad Campbell wrote:
> > > 
> > > > Here is the holdup :
> > > > 
> > > > 11725@1567416625.003504:qxl_ring_command_check 0 native
> > > > 11725@1567416625.102653:qxl_io_write 0 native addr=0 (QXL_IO_NOTIFY_CMD)
> > > > val=0 size=1 async=0
> > > > 
> > > > ~100ms delay prior to each logged QXL_IO_NOTIFY_CMD on the AMD box which
> > > > explains the performance difference. Now I just need to figure out if
> > > > that lies in the guest, the guest QXL driver, QEMU or SPICE and why it
> > > > exhibits on the AMD box and not the i7.
> > > > 
> > > > To get to this point, I recompiled the kernel on the i7 box with both
> > > > AMD and Intel KVM modules. Once that was running I cloned the drive and
> > > > put it in the AMD box, so the OS, software stack and all dependencies
> > > > are identical.
> > > Reacp :
> > > 
> > > I have a machine with a Windows 7 VM which is running on an i7-3770. This
> > > works perfectly.
> > > 
> > > Clone the disk and put it in a new(ish) AMD Ryzen 1500x machine and the
> > > display output using qxl/spice is now limited to ~5-7fps.
> > > 
> > > I originally cloned the entire machine to keep the software versions
> > > identical.
> > > 
> > > To simplify debugging and reproduction I'm now using :
> > > - An identical SPICE version to that on the i7.
> > > - A fresh 64 bit Windows 7 VM.
> > > - The D2D benchmark from Crystalmark 2004R7.
> > > 
> > > The machine is booted with :
> > > 
> > > qemu -enable-kvm \
> > >   -m 8192\
> > >   -rtc base=localtime\
> > >   -vga qxl\
> > >   -device qxl\
> > >   -global qxl-vga.guestdebug=3\
> > >   -global qxl-vga.cmdlog=1\
> > >   -global qxl-vga.vram_size=65536\
> > >   -global qxl.vram_size=65536\
> > >   -global qxl-vga.ram_size=65536\
> > >   -global qxl.ram_size=65536\
> > >   -net nic,model=virtio\
> > >   -net tap,ifname=tap0,script=/etc/qemu-ifup,vhost=on\
> > >   -usbdevice tablet\
> > >   -spice port=5930,disable-ticketing\
> > >   -device virtio-serial\
> > >   -chardev spicevmc,id=vdagent,name=vdagent\
> > >   -device virtserialport,chardev=vdagent,name=com.redhat.spice.0\
> > >   -smp 3,maxcpus=3,cores=3,threads=1,sockets=1\
> > >   -cpu qemu64,hv_relaxed,hv_spinlocks=0x1fff,hv_vapic,hv_time \
> > -cpu qemu64 is almost always a bad idea;  does -cpu host help ?
> > 
> > Dave
> 
> 
> No. I was using -cpu host. I changed it to qemu64 for testing so I could add & remove -enable-kvm for testing without the machine changing drivers about.

Oh, hmm.
Sorry I don't know too much where to look then; you have any of:
  a) Windows
  b) guest graphics drivers
  c) spice server in qemu
 
and probalby some more.

So I think it's going to be a case of profiling on the two different
systems and see if you can spot anything in particular that stands out.

Dave

> Regards,
> 
> Brad
> 
> -- 
> An expert is a person who has found out by his own painful
> experience all the mistakes that one can make in a very
> narrow field. - Niels Bohr
> 
--
Dr. David Alan Gilbert / dgilbert@redhat.com / Manchester, UK


^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: [Qemu-devel] [Qemu-discuss] Cross-posted : Odd QXL/KVM performance issue with a Windows 7 Guest
  2019-09-09 15:22         ` Dr. David Alan Gilbert
@ 2019-09-12 14:54           ` Brad Campbell
  0 siblings, 0 replies; 9+ messages in thread
From: Brad Campbell @ 2019-09-12 14:54 UTC (permalink / raw)
  To: Dr. David Alan Gilbert; +Cc: qemu-devel, qemu-discuss

On 9/9/19 11:22 pm, Dr. David Alan Gilbert wrote:
> 
> Oh, hmm.
> Sorry I don't know too much where to look then; you have any of:
>    a) Windows
>    b) guest graphics drivers
>    c) spice server in qemu
>   
> and probalby some more.
> 
> So I think it's going to be a case of profiling on the two different
> systems and see if you can spot anything in particular that stands out.
> 

G'day Dave,

Thanks for the advice.

I ran qemu through Valgrind/callgrind and nothing excessive popped up. 
It looks like the issue might be in Windows, so I'm now trying to figure 
out how to profile inside the guest.

Suggestions as to how to profile the qxl driver while it's underway 
gratefully accepted. I'm working my way through the profiling tools in 
the Windows SDK & DDK but haven't made much headway.

Regards,
Brad


^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: [Qemu-discuss] Cross-posted : Odd QXL/KVM performance issue with a Windows 7 Guest
  2019-09-06  8:49   ` [Qemu-devel] Cross-posted : Odd QXL/KVM performance issue with a Windows 7 Guest Brad Campbell
  2019-09-06 13:38     ` Brad Campbell
  2019-09-06 19:03     ` Dr. David Alan Gilbert
@ 2019-11-05  2:38     ` Brad Campbell
  2 siblings, 0 replies; 9+ messages in thread
From: Brad Campbell @ 2019-11-05  2:38 UTC (permalink / raw)
  To: qemu-discuss, qemu-devel

On 6/9/19 4:49 pm, Brad Campbell wrote:
> On 2/9/19 6:23 pm, Brad Campbell wrote:
> 
>>
>> Here is the holdup :
>>
>> 11725@1567416625.003504:qxl_ring_command_check 0 native
>> 11725@1567416625.102653:qxl_io_write 0 native addr=0 
>> (QXL_IO_NOTIFY_CMD) val=0 size=1 async=0
>>
>> ~100ms delay prior to each logged QXL_IO_NOTIFY_CMD on the AMD box 
>> which explains the performance difference. Now I just need to figure 
>> out if that lies in the guest, the guest QXL driver, QEMU or SPICE and 
>> why it exhibits on the AMD box and not the i7.
>>
>> To get to this point, I recompiled the kernel on the i7 box with both 
>> AMD and Intel KVM modules. Once that was running I cloned the drive 
>> and put it in the AMD box, so the OS, software stack and all 
>> dependencies are identical.
> 
> Reacp :
> 
> I have a machine with a Windows 7 VM which is running on an i7-3770. 
> This works perfectly.
> 
> Clone the disk and put it in a new(ish) AMD Ryzen 1500x machine and the 
> display output using qxl/spice is now limited to ~5-7fps.
> 
> I originally cloned the entire machine to keep the software versions 
> identical.
> 
> To simplify debugging and reproduction I'm now using :
> - An identical SPICE version to that on the i7.
> - A fresh 64 bit Windows 7 VM.
> - The D2D benchmark from Crystalmark 2004R7.
> 
> The machine is booted with :
> 
> qemu -enable-kvm \
>   -m 8192\
>   -rtc base=localtime\
>   -vga qxl\
>   -device qxl\
>   -global qxl-vga.guestdebug=3\
>   -global qxl-vga.cmdlog=1\
>   -global qxl-vga.vram_size=65536\
>   -global qxl.vram_size=65536\
>   -global qxl-vga.ram_size=65536\
>   -global qxl.ram_size=65536\
>   -net nic,model=virtio\
>   -net tap,ifname=tap0,script=/etc/qemu-ifup,vhost=on\
>   -usbdevice tablet\
>   -spice port=5930,disable-ticketing\
>   -device virtio-serial\
>   -chardev spicevmc,id=vdagent,name=vdagent\
>   -device virtserialport,chardev=vdagent,name=com.redhat.spice.0\
>   -smp 3,maxcpus=3,cores=3,threads=1,sockets=1\
>   -cpu qemu64,hv_relaxed,hv_spinlocks=0x1fff,hv_vapic,hv_time \
>   -drive 
> file=/server/VM/Cadbox.raw,if=virtio,aio=threads,format=raw,cache=unsafe 
> -boot c \
>   -drive 
> file=/server/VM/Cadbox_swap.raw,if=virtio,aio=threads,format=raw,cache=unsafe 
> \
> 
> 
> The D2D benchmark runs through a series of Sprites (stars) and it just 
> shuffles them around the screen.
> 
> With KVM enabled I get :
> 
> Sprite    10 - 8.66fps
> Sprite   100 - 8.47fps
> Sprite   500 - 8.45fps
> Sprite  1000 - 8.18fps
> Sprite  5000 - 7.64fps
> Sprite 10000 - 7.26fps
> 
> With the identical system, with KVM disabled I get :
> 
> Sprite    10 - 28.97fps
> Sprite   100 - 27.24fps
> Sprite   500 - 23.85fps
> Sprite  1000 - 22.00fps
> Sprite  5000 - 11.11fps
> Sprite 10000 -  4.50fps
> 
> On the i7 with the same software version and kvm enabled  :
> 
> Sprite    10 - 88.58fps
> Sprite   100 - 88.35fps
> Sprite   500 - 85.64fps
> Sprite  1000 - 83.33fps
> Sprite  5000 - 58.08fps
> Sprite 10000 - 45.29fps
> 

Just to round this out, I spent quite a bit of time trying to profile 
the guest and qxl driver, and then gave up.

I tried installing Windows 8.1 and the new WDDM driver and it didn't 
exhibit the fault, so I resigned myself to rebuild all the guests.

Regards,
Brad
-- 
An expert is a person who has found out by his own painful
experience all the mistakes that one can make in a very
narrow field. - Niels Bohr


^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: [Qemu-devel] Cross-posted : Odd QXL/KVM performance issue with a Windows 7 Guest
  2019-09-06 14:41       ` Brad Campbell
@ 2019-11-05 11:32         ` Alex Bennée
  0 siblings, 0 replies; 9+ messages in thread
From: Alex Bennée @ 2019-11-05 11:32 UTC (permalink / raw)
  To: qemu-devel


Brad Campbell <lists2009@fnarfbargle.com> writes:

> On 6/9/19 21:38, Brad Campbell wrote:
>> 7022@1567775824.002106:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c970
>> 7022@1567775824.002115:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c980
>> 7022@1567775824.003122:kvm_vm_ioctl type 0xc008ae67, arg 0x7ffe13b0c970
>
>> Does this look familiar to anyone?
>
> Ugh. System timer.
>
> So with the timer interrupt removed and an added trace on IRQ > 0:
>
> qxl/guest-0: 79096403248: qxldd: DrvCopyBits
> 14955@1567780063.149527:kvm_vcpu_ioctl cpu_index 2, type 0xae80, arg (nil)
> 14956@1567780063.150291:qxl_ring_res_put 0 #res=1
> 14955@1567780063.163672:kvm_run_exit cpu_index 2, reason 2
> 14955@1567780063.163688:qxl_io_write 0 native addr=4 (QXL_IO_NOTIFY_OOM) val=0 size=1 async=0
> 14955@1567780063.163704:qxl_spice_oom 0
> 14955@1567780063.163720:kvm_vcpu_ioctl cpu_index 2, type 0xae80, arg (nil)
> 14956@1567780063.163755:qxl_ring_command_check 0 native
> 14956@1567780063.163779:qxl_ring_res_push 0 native s#=0 res#=1 last=0x7f3c0d44b6e0 notify=yes
> 14956@1567780063.163816:qxl_ring_res_push_rest 0 ring 1/8 [326,325]
> 14956@1567780063.163841:qxl_send_events 0 1
> 14956@1567780063.163868:qxl_ring_cursor_check 0 native
> 14956@1567780063.163888:qxl_ring_command_check 0 native
> 14924@1567780063.163879:kvm_set_irq irq 11, level 1, status 1
> 14954@1567780063.163895:kvm_run_exit cpu_index 1, reason 2
> 14954@1567780063.163965:qxl_io_write 0 native addr=3 (QXL_IO_UPDATE_IRQ) val=0 size=1 async=0
> 14954@1567780063.164006:kvm_set_irq irq 11, level 0, status 1
> 14954@1567780063.164029:kvm_vcpu_ioctl cpu_index 1, type 0xae80, arg (nil)
> 14954@1567780063.164065:kvm_run_exit cpu_index 1, reason 2
> 14954@1567780063.164080:qxl_io_write 0 native addr=3 (QXL_IO_UPDATE_IRQ) val=0 size=1 async=0
> 14954@1567780063.164104:kvm_vcpu_ioctl cpu_index 1, type 0xae80, arg (nil)
> 14955@1567780063.266778:kvm_run_exit cpu_index 2, reason 2
> 14955@1567780063.266790:qxl_io_write 0 native addr=0 (QXL_IO_NOTIFY_CMD) val=0 size=1 async=0
> 14955@1567780063.266809:kvm_vcpu_ioctl cpu_index 2, type 0xae80, arg (nil)
> 14956@1567780063.266822:qxl_ring_cursor_check 0 native
> 14956@1567780063.266842:qxl_ring_command_check 0 native
> 79213750625 qxl-0/cmd: cmd @ 0x10000000104b598 draw: surface_id 0 type copy effect opaque src 100000001fecbf8 (id 9fe0870780 type 0 flags 0 width 1920 height 1080, fmt 8 flags 0 x 1920 y 1080 stride 7680 palette 0 data 100000001fecc28) area 1920x1080+0+0 rop 8
> 14956@1567780063.266983:qxl_ring_command_get 0 native
> 14956@1567780063.267044:qxl_ring_command_check 0 native
> 14956@1567780063.267070:qxl_ring_cursor_check 0 native
> 14956@1567780063.267087:qxl_ring_command_check 0 native
> 14956@1567780063.267109:qxl_ring_command_req_notification 0
> 14955@1567780063.267967:kvm_run_exit cpu_index 2, reason 2
> 14955@1567780063.267987:qxl_io_write 0 native addr=7 (QXL_IO_LOG) val=0 size=1 async=0
> 14955@1567780063.268015:qxl_io_log 0 qxldd: DrvCopyBits
>
> So if I'm not mistaken (for the nth time), we have KVM_RUN on cpu index 2 here:
>
> 14955@1567780063.163720:kvm_vcpu_ioctl cpu_index 2, type 0xae80, arg (nil)
>
> And it returns here :
>
> 14955@1567780063.266778:kvm_run_exit cpu_index 2, reason 2
>
> Does that imply guest code is running for ~100ms on that vcpu?

Yes. In the KVM game vmexits is what kills performance. If QEMU is
involved in doing the emulation you have to exit the guest, go through
the kernel, exit the ioctl and then QEMU does it's thing before you
restart.

You can't avoid all exits - indeed VIRTIO is designed to limit the exits
to a single exit per transmission. However if you are emulating a legacy
device in QEMU every access to a memory mapped register will involve an
exit.

If you monitor QEMU with "perf record" and then look at the result
("perf report") see what QEMU is doing all that time. It's likely there
is a legacy device somewhere which the guest kernel is hammering.

--
Alex.


^ permalink raw reply	[flat|nested] 9+ messages in thread

end of thread, other threads:[~2019-11-05 11:33 UTC | newest]

Thread overview: 9+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
     [not found] <ed421291-7178-d7bc-5ed3-9863d28ceba9@fnarfbargle.com>
     [not found] ` <dd33a398-3c1f-0c92-2318-00ad144e1e5d@fnarfbargle.com>
2019-09-06  8:49   ` [Qemu-devel] Cross-posted : Odd QXL/KVM performance issue with a Windows 7 Guest Brad Campbell
2019-09-06 13:38     ` Brad Campbell
2019-09-06 14:41       ` Brad Campbell
2019-11-05 11:32         ` Alex Bennée
2019-09-06 19:03     ` Dr. David Alan Gilbert
2019-09-07  0:44       ` Brad Campbell
2019-09-09 15:22         ` Dr. David Alan Gilbert
2019-09-12 14:54           ` [Qemu-devel] [Qemu-discuss] " Brad Campbell
2019-11-05  2:38     ` Brad Campbell

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).