On 1/9/19 21:28, Brad Campbell wrote:> G'day all,
I have a box which has the sole purpose of running a Windows 7 VM. It's an i7-3770K built in 2013 and happily runs a Windows 7 VM with 2 QXL heads which are displayed remotely over a 1GB ethernet to a client running the spicy spice-gtk client.
....
CPU/FPU/Memory/Storage are all comparable. GDI performance is similar, but when we get to the D2D test the Intel box runs at about ~50 FPS and the AMD box runs ~5FPS. That explains the interactive issues when running CAD in the guest.
....
I've tried enabling simpletrace and run traces on both machines. Aside from the intel machine time deltas for the commands being ~ half those on the AMD box I really can spot anything strange.
Ok, so enabling tracing for the guest, ring and qxl_* tracepoints and I can now see an issue. These traces are snapped out of a benchmark run when it's clearly demonstrating the issue. i7 ~ 60fps, Ryzen ~8fps. This is a trace from the i7 box : qxl/guest-0: 36633582382: qxldd: DrvCopyBits 30794@1567418204.460991:qxl_ring_cursor_check 0 native 30794@1567418204.461016:qxl_ring_command_check 0 native 30794@1567418204.465960:qxl_ring_cursor_check 0 native 30794@1567418204.465979:qxl_ring_command_check 0 native 30794@1567418204.465989:qxl_ring_cursor_check 0 native 30794@1567418204.465997:qxl_ring_command_check 0 native 30794@1567418204.469440:qxl_io_write 0 native addr=4 (QXL_IO_NOTIFY_OOM) val=0 size=1 async=0 30794@1567418204.469466:qxl_spice_oom 0 30794@1567418204.469517:qxl_ring_command_check 0 native 30794@1567418204.469538:qxl_ring_res_push_rest 0 ring 1/8 [125,124] 30794@1567418204.469552:qxl_send_events 0 1 30794@1567418204.469568:qxl_ring_cursor_check 0 native 30794@1567418204.469577:qxl_ring_command_check 0 native 30794@1567418204.469587:qxl_ring_cursor_check 0 native 30794@1567418204.469595:qxl_ring_command_check 0 native 30794@1567418204.469604:qxl_ring_cursor_check 0 native 30794@1567418204.469611:qxl_ring_command_check 0 native 30794@1567418204.469622:qxl_io_write 0 native addr=3 (QXL_IO_UPDATE_IRQ) val=0 size=1 async=0 30794@1567418204.469658:qxl_io_write 0 native addr=3 (QXL_IO_UPDATE_IRQ) val=0 size=1 async=0 30794@1567418204.470821:qxl_io_write 0 native addr=0 (QXL_IO_NOTIFY_CMD) val=0 size=1 async=0 30794@1567418204.470888:qxl_ring_cursor_check 0 native 30794@1567418204.470904:qxl_ring_command_check 0 native 36647479204 qxl-0/cmd: cmd @ 0x10000000104b798 draw: surface_id 0 type copy effect opaque src 10000000348f840 (id 10ae0870780 type 0 flags 0 width 1920 height 1080, fmt 8 flags 0 x 1920 y 1080 stride 7680 palette 0 data 10000000348f870) area 1920x1080+0+0 rop 8 30794@1567418204.470967:qxl_ring_command_get 0 native 30794@1567418204.471014:qxl_ring_command_check 0 native 30794@1567418204.471026:qxl_ring_cursor_check 0 native 30794@1567418204.471034:qxl_ring_command_check 0 native 30794@1567418204.471042:qxl_ring_command_req_notification 0 30794@1567418204.471051:qxl_ring_cursor_check 0 native 30794@1567418204.471059:qxl_ring_command_check 0 native 30794@1567418204.471667:qxl_io_write 0 native addr=7 (QXL_IO_LOG) val=0 size=1 async=0 30794@1567418204.471689:qxl_io_log 0 qxldd: DrvCopyBits qxl/guest-0: 36648262127: qxldd: DrvCopyBits 30794@1567418204.475330:qxl_io_write 0 native addr=0 (QXL_IO_NOTIFY_CMD) val=0 size=1 async=0 30794@1567418204.475417:qxl_ring_cursor_check 0 native 30794@1567418204.475435:qxl_ring_command_check 0 native 36652010610 qxl-0/cmd: cmd @ 0x10000000104b498 draw: surface_id 0 type copy effect opaque src 100000001a0ff78 (id 10be0870780 type 0 flags 0 width 1920 height 1080, fmt 8 flags 0 x 1920 y 1080 stride 7680 palette 0 data 100000001a0ffa8) area 1920x1080+0+0 rop 8 30794@1567418204.475498:qxl_ring_command_get 0 native 30794@1567418204.475548:qxl_ring_command_check 0 native 30794@1567418204.475562:qxl_ring_cursor_check 0 native 30794@1567418204.475571:qxl_ring_command_check 0 native 30794@1567418204.475579:qxl_ring_command_req_notification 0 30794@1567418204.475587:qxl_ring_cursor_check 0 native 30794@1567418204.475596:qxl_ring_command_check 0 native 30794@1567418204.476111:qxl_io_write 0 native addr=7 (QXL_IO_LOG) val=0 size=1 async=0 30794@1567418204.476133:qxl_io_log 0 qxldd: DrvCopyBits qxl/guest-0: 36652705645: qxldd: DrvCopyBits 30794@1567418204.479788:qxl_io_write 0 native addr=0 (QXL_IO_NOTIFY_CMD) val=0 size=1 async=0 30794@1567418204.479863:qxl_ring_cursor_check 0 native 30794@1567418204.479881:qxl_ring_command_check 0 native 36656456294 qxl-0/cmd: cmd @ 0x10000000104b598 draw: surface_id 0 type copy effect opaque src 1000000037ba090 (id 10ce0870780 type 0 flags 0 width 1920 height 1080, fmt 8 flags 0 x 1920 y 1080 stride 7680 palette 0 data 1000000037ba0c0) area 1920x1080+0+0 rop 8 30794@1567418204.479944:qxl_ring_command_get 0 native 30794@1567418204.480000:qxl_ring_command_check 0 native 30794@1567418204.480014:qxl_ring_cursor_check 0 native 30794@1567418204.480022:qxl_ring_command_check 0 native 30794@1567418204.480030:qxl_ring_command_req_notification 0 30794@1567418204.480040:qxl_ring_cursor_check 0 native 30794@1567418204.480048:qxl_ring_command_check 0 native 30794@1567418204.480561:qxl_io_write 0 native addr=7 (QXL_IO_LOG) val=0 size=1 async=0 30794@1567418204.480583:qxl_io_log 0 qxldd: DrvCopyBits This is the equivalent trace from the Ryzen : qxl/guest-0: 78354754028: qxldd: DrvCopyBits 11725@1567416624.988319:qxl_ring_cursor_check 0 native 11725@1567416624.988340:qxl_ring_command_check 0 native 11725@1567416625.003283:qxl_io_write 0 native addr=4 (QXL_IO_NOTIFY_OOM) val=0 size=1 async=0 11725@1567416625.003315:qxl_spice_oom 0 11725@1567416625.003350:qxl_ring_command_check 0 native 11725@1567416625.003365:qxl_ring_res_push_rest 0 ring 1/8 [174,173] 11725@1567416625.003380:qxl_send_events 0 1 11725@1567416625.003396:qxl_ring_cursor_check 0 native 11725@1567416625.003406:qxl_ring_command_check 0 native 11725@1567416625.003414:qxl_io_write 0 native addr=3 (QXL_IO_UPDATE_IRQ) val=0 size=1 async=0 11725@1567416625.003430:qxl_ring_cursor_check 0 native 11725@1567416625.003461:qxl_io_write 0 native addr=3 (QXL_IO_UPDATE_IRQ) val=0 size=1 async=0 11725@1567416625.003462:qxl_ring_command_check 0 native 11725@1567416625.003494:qxl_ring_cursor_check 0 native 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 11725@1567416625.102701:qxl_ring_cursor_check 0 native 11725@1567416625.102717:qxl_ring_command_check 0 native 78472556666 qxl-0/cmd: cmd @ 0x10000000105a5b8 draw: surface_id 0 type copy effect opaque src 1000000026d3f70 (id dfe0870780 type 0 flags 0 width 1920 height 1080, fmt 8 flags 0 x 1920 y 1080 stride 7680 palette 0 data 1000000026d3fa0) a rea 1920x1080+0+0 rop 8 11725@1567416625.102797:qxl_ring_command_get 0 native 11725@1567416625.102850:qxl_ring_command_check 0 native 11725@1567416625.102865:qxl_ring_cursor_check 0 native 11725@1567416625.102876:qxl_ring_command_check 0 native 11725@1567416625.102885:qxl_ring_command_req_notification 0 11725@1567416625.103593:qxl_io_write 0 native addr=7 (QXL_IO_LOG) val=0 size=1 async=0 11725@1567416625.103628:qxl_io_log 0 qxldd: DrvCopyBits qxl/guest-0: 78473464666: qxldd: DrvCopyBits 11725@1567416625.106778:qxl_ring_cursor_check 0 native 11725@1567416625.106801:qxl_ring_command_check 0 native 11725@1567416625.210516:qxl_io_write 0 native addr=0 (QXL_IO_NOTIFY_CMD) val=0 size=1 async=0 11725@1567416625.210591:qxl_ring_cursor_check 0 native 11725@1567416625.210609:qxl_ring_command_check 0 native 78580448134 qxl-0/cmd: cmd @ 0x10000000105a6b8 draw: surface_id 0 type copy effect opaque src 100000002ebe098 (id e0e0870780 type 0 flags 0 width 1920 height 1080, fmt 8 flags 0 x 1920 y 1080 stride 7680 palette 0 data 100000002ebe0c8) a rea 1920x1080+0+0 rop 8 11725@1567416625.210676:qxl_ring_command_get 0 native 11725@1567416625.210729:qxl_ring_command_check 0 native 11725@1567416625.210742:qxl_ring_cursor_check 0 native 11725@1567416625.210750:qxl_ring_command_check 0 native 11725@1567416625.210759:qxl_ring_command_req_notification 0 11725@1567416625.211881:qxl_io_write 0 native addr=7 (QXL_IO_LOG) val=0 size=1 async=0 11725@1567416625.211924:qxl_io_log 0 qxldd: DrvCopyBits qxl/guest-0: 78581760527: qxldd: DrvCopyBits 11725@1567416625.214592:qxl_ring_cursor_check 0 native 11725@1567416625.214614:qxl_ring_command_check 0 native 11725@1567416625.318683:qxl_io_write 0 native addr=0 (QXL_IO_NOTIFY_CMD) val=0 size=1 async=0 11725@1567416625.318748:qxl_ring_cursor_check 0 native 11725@1567416625.318763:qxl_ring_command_check 0 native 78688600327 qxl-0/cmd: cmd @ 0x10000000105a7b8 draw: surface_id 0 type copy effect opaque src 1000000036a81c0 (id e1e0870780 type 0 flags 0 width 1920 height 1080, fmt 8 flags 0 x 1920 y 1080 stride 7680 palette 0 data 1000000036a81f0) area 1920x1080+0+0 rop 8 11725@1567416625.318828:qxl_ring_command_get 0 native 11725@1567416625.318878:qxl_ring_command_check 0 native 11725@1567416625.318890:qxl_ring_cursor_check 0 native 11725@1567416625.318899:qxl_ring_command_check 0 native 11725@1567416625.318907:qxl_ring_command_req_notification 0 11725@1567416625.319633:qxl_io_write 0 native addr=7 (QXL_IO_LOG) val=0 size=1 async=0 11725@1567416625.319669:qxl_io_log 0 qxldd: DrvCopyBits 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. Anyone have any ideas? 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
