Re: [Qemu-discuss] Qemu on Windows (with haxm and whpx), minimal Ubuntu, SLIRP and OpenVPN: very slow

[Michael Fritscher]

Am 14.05.2019 um 09:36:29 schrieb Michael Fritscher:
> Am 13.05.2019 um 23:41:25 schrieb Michael Fritscher:
> > On 13.05.19 23:16, Jakob Bohm wrote:
> > > On 13/05/2019 16:35, Michael Fritscher wrote:
> > > > Am 13.05.2019 um 16:10:33 schrieb Michael Fritscher:
> > > > >    Am Montag, 13. Mai 2019 15:25 CEST, Michael Fritscher
> > > > > <address@hidden> schrieb:
> > > > > > Am 13.05.2019 um 10:32:48 schrieb Michael Fritscher:
> > > > > > > Good day,
> > > > > > >
> > > > > > > Scenario:
> > > > > > > Host: Windows 7 and 10 64 bit, Skylake+ CPUs
> > > > > > > Qemu Version: 3.1 (4.0 isn't available yet on
> > > > > > > https://qemu.weilnetz.de/)
> > > > > > > Accelerators: HAXM and WHPX
> > > > > > > Guest: Ubuntu 18.04.2 64 bit, minimal install
> > > > > > > Guest's tasks: OpenVPN, iptables, tc
> > > > > > >
> > > > > > > Configuration:
> > > > > > > -machine q35,accel=kvm:hvf:whpx:hax:tcg
> > > > > > > -m 512
> > > > > > > -smp 1
> > > > > > > -rtc base=utc
> > > > > > > -drive
> > > > > > > file=layertc_environmentmanager_amsvm.iso,if=virtio,media=cdrom
> > > > > > > -vga std
> > > > > > > -netdev
> > > > > > >        user,id=natted,
> > > > > > >        restrict=n,
> > > > > > >        net=172.31.1.0/255.255.255.0,
> > > > > > >        dhcpstart=172.31.1.1,
> > > > > > >        host=172.31.1.3,
> > > > > > >        dns=172.31.1.4
> > > > > > > -device virtio-net,netdev=natted,mac=00:50:56:00:08:00
> > > > > > > -nodefaults
> > > > > > > -monitor tcp:localhost:4444
> > > > > > > -kernel vmlinuz
> > > > > > > -initrd initrd.img
> > > > > > > -append "boot=casper textonly quiet nosplash nofb fb=false pti=off
> > > > > > > spectre_v2=off l1tf=off nospec_store_bypass_disable noprompt"
> > > > > > >
> > > > > > > (the iso is a casper livecd, but I start the linux kernel directly
> > > > > > > because of boot speed)
> > > > > > >
> > > > > > > Problem:
> > > > > > > It is slow...
> > > > > > > While a openssl speed -elapsed -evp aes-128-cbc is ok (500MB/sec
> > > > > > > and beyond), OpenVPN struggles.
> > > > > > > I get 70% virtual CPU usage , mostly on OpenVPN and system load
> > > > > > > while transfering 1-2 MB/s with a UDP video stream. The measured
> > > > > > > delay is also
> > > > > > > rather spiky and is about 30...40 ms. On the host I get a cpu
> > > > > > > usage of about 10% (=almost a core) I see this both on the server
> > > > > > > and the client
> > > > > > > side.
> > > > > > >
> > > > > > > On the player edition of the big commercial player, the results
> > > > > > > are _much_ better (10% virtual CPU usage, delay of 4-6 ms)
> > > > > > >
> > > > > > > How can I further debug this? Do you know any knobs I can try?
> > > > > > > Slirp, while there are warnings of being slow, doesn't seem to be
> > > > > > > the culprit as
> > > > > > > I can get easily >>10 MB/s through it. And I see the big CPU usage
> > > > > > > of OpenVPN
> > > > > > >
> > > > > > > Best regards,
> > > > > > > Michael Fritscher
> > > > > >
> > > > > > Hi again,
> > > > > >
> > > > > > after a bit of digging, openVPN seems to call read_hpet with about
> > > > > > 1 kHz, which is, regarding to the program perf, the main culprit.
> > > > > > Is a call
> > > > > > rate of this frequency normal and qemu is just very slow to handle
> > > > > > them, or is there another problem?
> > > Compare the boot-up dmesg of the guest OS kernel in the two scenarios.
> > > Assuming read_hpet is a kernel-level function, it may simply be that
> > > on VMware, the kernel or driver chooses to use a different "hardware"
> > > mechanism to implement whichever system call is being called 1000
> > > times per second.
> > >
> > > Also note, that video stream software is more likely than OpenVPN to
> > > be making extremely frequent timer checks (UDP media streams time
> > > packet arrivals to manage buffering and smooth over the content in
> > > lost packets).
> > >
> > > Another frequent user of timing calls is performance checking tools.
> > >
> > >
> > > Enjoy
> > >
> > > Jakob
> > The thing is, on VMWare I see no hpet_read calls, the most called
> > function is reading from the network card - and I have _way_ more called
> > syscalls on VMWare (30k on VMWare vs. 9k on qemu in 5 seconds)... Also,
> > hpet itself isn't the culprit here as if I disable hpet I get the same
> > problem on acpi_pm_read... And I see (with perf) that they are always
> > called from openVPN. Sadly I didn't managed to get a backtrace jet to
> > further analyse why these functions are called so much from OpenVPN yet.
> >
> > The PCs are directly connected via a GBit switch. Also, the VM does only
> > do OpenVPN (+iptables + tc), the creation and reception of the stream is
> > done completely the host.
> >
> > I've uploaded the perf data and the parsed log of perf here:
> > https://mifritscher.de/austausch/openvpn - perhaps I simply missread it.
> >
> > Best regards,
> > Michael Fritscher
>
> Good morning,
>
> I've uploaded the perf file from VMWare for comparison under https://mifritscher.de/austausch/openvpn/vmware/ . Additionally, I've uploaded the 
> dmesg output using VMWare and Qemu.
>
> One interesting thing: It does not always happen, and if it doesn't happen I can provoke it playing with the priority, CPU affinity etc of the 
> qemu process. So it seems to be really a timing problem which can be provoked by scheduling issues on the host?
>
> Best regards,
> Michael Fritscher


Hello again,

I've uploaded a "good" case with qemu. In this good case, I've 2 additional 
lines in dmesg:

[    0.028000] tsc: Fast TSC calibration failed
[    4.544469] tsc: Refined TSC clocksource calibration: 2808.001

And the perf log show no hpet_read call at all!

Somehow it looks like a severe timer problem...

Best regards,
Michael Fritscher


--
ZfT - Zentrum für Telematik e.V.
Michael Fritscher
Magdalene-Schoch-Straße 5
97074 Würzburg
Tel: +49 (931) 615 633 - 57
Fax: +49 (931) 615 633 - 11
Email: address@hidden
Web: http://www.telematik-zentrum.de

Vorstand:
Prof. Dr. Klaus Schilling, Prof. Dr. Andreas Nüchter,  Hans-Joachim Leistner
Sitz: Gerbrunn
USt.-ID Nr.: DE 257 244 580, Steuer-Nr.:  257/111/70203
Amtsgericht Würzburg, Vereinsregister-Nr.: VR 200 167

michael_fritscher.vcf
Description: Vcard