* [Qemu-devel] qom-test on netbsd can be very slow
@ 2018-04-09 17:10 Peter Maydell
2018-04-09 20:51 ` Kamil Rytarowski
2018-04-10 8:19 ` Daniel P. Berrangé
0 siblings, 2 replies; 4+ messages in thread
From: Peter Maydell @ 2018-04-09 17:10 UTC (permalink / raw)
To: QEMU Developers; +Cc: Eric Blake, Daniel P. Berrange, Markus Armbruster
My NetBSD build system recently seems to have taken a nosedive
in how long it takes to finish "make check". This seems to be
because qom-test (and probably other things where the test interacts
with the QEMU process) can run very slowly.
netbsdvm# for i in 1 2 3 4 5 6 7 8 9 10; do
(QTEST_QEMU_BINARY=x86_64-softmmu/qemu-system-x86_64 time
tests/qom-test -p /x86_64/qom/pc-i440fx-2.0); done
/x86_64/qom/pc-i440fx-2.0: OK
8.49 real 1.18 user 7.34 sys
/x86_64/qom/pc-i440fx-2.0: OK
10.41 real 1.32 user 9.09 sys
/x86_64/qom/pc-i440fx-2.0: OK
8.45 real 1.24 user 7.24 sys
/x86_64/qom/pc-i440fx-2.0: OK
9.88 real 1.10 user 8.31 sys
/x86_64/qom/pc-i440fx-2.0: OK
11.60 real 1.47 user 9.90 sys
/x86_64/qom/pc-i440fx-2.0: OK
10.94 real 1.28 user 9.68 sys
/x86_64/qom/pc-i440fx-2.0: OK
10.06 real 1.32 user 8.76 sys
/x86_64/qom/pc-i440fx-2.0: OK
13.38 real 1.37 user 12.04 sys
/x86_64/qom/pc-i440fx-2.0: OK
16.19 real 1.46 user 14.29 sys
/x86_64/qom/pc-i440fx-2.0: OK
9.70 real 1.17 user 8.51 sys
Admittedly this is running in a (KVM) VM, but still, there seems
something wrong with how long each of these is taking. On Linux
each run is less than a second, so there's an order-of-magnitude
slowdown here. Further, I've occasionally seen a run take 100 seconds!
Does anybody else see this, and any ideas why it might be running slow?
I'm not very familiar with debugging on netbsd; I had a look at
ktrace output, and the QEMU process seems to sometimes spend
quite a lot of time in a poll() loop not actually doing anything.
I couldn't figure out how to get the ktrace logs to annotate
which thread was making which syscall though, so they weren't
easy to interpret. If anybody's more experienced at debugging
things in the BSDs that would also be helpful.
On OpenBSD, for comparison, each test run seems to fairly reliably
take 5 seconds give-or-take, there's much less run-to-run
variation, though it's still much slower than Linux is.
The OpenBSD and FreeBSD build VMs seem to complete more
reasonably quickly than the NetBSD one.
One thing I noticed looking at ktrace output is that we do
all our reading of QMP input and output with a read syscall
per character. I don't think that's the cause of this slowness,
though.
thanks
-- PMM
^ permalink raw reply [flat|nested] 4+ messages in thread* Re: [Qemu-devel] qom-test on netbsd can be very slow 2018-04-09 17:10 [Qemu-devel] qom-test on netbsd can be very slow Peter Maydell @ 2018-04-09 20:51 ` Kamil Rytarowski 2018-04-09 23:31 ` Kamil Rytarowski 2018-04-10 8:19 ` Daniel P. Berrangé 1 sibling, 1 reply; 4+ messages in thread From: Kamil Rytarowski @ 2018-04-09 20:51 UTC (permalink / raw) To: Peter Maydell, QEMU Developers; +Cc: Markus Armbruster [-- Attachment #1: Type: text/plain, Size: 3611 bytes --] On 09.04.2018 19:10, Peter Maydell wrote: > My NetBSD build system recently seems to have taken a nosedive > in how long it takes to finish "make check". This seems to be > because qom-test (and probably other things where the test interacts > with the QEMU process) can run very slowly. > > netbsdvm# for i in 1 2 3 4 5 6 7 8 9 10; do > (QTEST_QEMU_BINARY=x86_64-softmmu/qemu-system-x86_64 time > tests/qom-test -p /x86_64/qom/pc-i440fx-2.0); done > /x86_64/qom/pc-i440fx-2.0: OK > 8.49 real 1.18 user 7.34 sys > /x86_64/qom/pc-i440fx-2.0: OK > 10.41 real 1.32 user 9.09 sys > /x86_64/qom/pc-i440fx-2.0: OK > 8.45 real 1.24 user 7.24 sys > /x86_64/qom/pc-i440fx-2.0: OK > 9.88 real 1.10 user 8.31 sys > /x86_64/qom/pc-i440fx-2.0: OK > 11.60 real 1.47 user 9.90 sys > /x86_64/qom/pc-i440fx-2.0: OK > 10.94 real 1.28 user 9.68 sys > /x86_64/qom/pc-i440fx-2.0: OK > 10.06 real 1.32 user 8.76 sys > /x86_64/qom/pc-i440fx-2.0: OK > 13.38 real 1.37 user 12.04 sys > /x86_64/qom/pc-i440fx-2.0: OK > 16.19 real 1.46 user 14.29 sys > /x86_64/qom/pc-i440fx-2.0: OK > 9.70 real 1.17 user 8.51 sys > > Admittedly this is running in a (KVM) VM, but still, there seems > something wrong with how long each of these is taking. On Linux > each run is less than a second, so there's an order-of-magnitude > slowdown here. Further, I've occasionally seen a run take 100 seconds! > > Does anybody else see this, and any ideas why it might be running slow? > I'm not very familiar with debugging on netbsd; I had a look at > ktrace output, and the QEMU process seems to sometimes spend > quite a lot of time in a poll() loop not actually doing anything. > I couldn't figure out how to get the ktrace logs to annotate > which thread was making which syscall though, so they weren't > easy to interpret. If anybody's more experienced at debugging > things in the BSDs that would also be helpful. > > On OpenBSD, for comparison, each test run seems to fairly reliably > take 5 seconds give-or-take, there's much less run-to-run > variation, though it's still much slower than Linux is. > The OpenBSD and FreeBSD build VMs seem to complete more > reasonably quickly than the NetBSD one. > > One thing I noticed looking at ktrace output is that we do > all our reading of QMP input and output with a read syscall > per character. I don't think that's the cause of this slowness, > though. > > thanks > -- PMM > I'm running these tests natively and get apparently expected results: /x86_64/qom/pc-i440fx-2.0: OK 2,05 real 1,36 user 0,71 sys /x86_64/qom/pc-i440fx-2.0: OK 1,92 real 1,17 user 0,79 sys /x86_64/qom/pc-i440fx-2.0: OK 1,84 real 1,14 user 0,77 sys /x86_64/qom/pc-i440fx-2.0: OK 1,85 real 1,16 user 0,76 sys /x86_64/qom/pc-i440fx-2.0: OK 1,79 real 1,04 user 0,82 sys /x86_64/qom/pc-i440fx-2.0: OK 1,84 real 1,00 user 0,91 sys /x86_64/qom/pc-i440fx-2.0: OK 1,86 real 1,18 user 0,75 sys /x86_64/qom/pc-i440fx-2.0: OK 1,85 real 1,27 user 0,64 sys /x86_64/qom/pc-i440fx-2.0: OK 1,84 real 1,27 user 0,64 sys /x86_64/qom/pc-i440fx-2.0: OK 1,82 real 1,18 user 0,71 sys [-- Attachment #2: OpenPGP digital signature --] [-- Type: application/pgp-signature, Size: 850 bytes --] ^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: [Qemu-devel] qom-test on netbsd can be very slow 2018-04-09 20:51 ` Kamil Rytarowski @ 2018-04-09 23:31 ` Kamil Rytarowski 0 siblings, 0 replies; 4+ messages in thread From: Kamil Rytarowski @ 2018-04-09 23:31 UTC (permalink / raw) To: Peter Maydell, QEMU Developers; +Cc: Markus Armbruster [-- Attachment #1: Type: text/plain, Size: 5100 bytes --] On 09.04.2018 22:51, Kamil Rytarowski wrote: > On 09.04.2018 19:10, Peter Maydell wrote: >> My NetBSD build system recently seems to have taken a nosedive >> in how long it takes to finish "make check". This seems to be >> because qom-test (and probably other things where the test interacts >> with the QEMU process) can run very slowly. >> >> netbsdvm# for i in 1 2 3 4 5 6 7 8 9 10; do >> (QTEST_QEMU_BINARY=x86_64-softmmu/qemu-system-x86_64 time >> tests/qom-test -p /x86_64/qom/pc-i440fx-2.0); done >> /x86_64/qom/pc-i440fx-2.0: OK >> 8.49 real 1.18 user 7.34 sys >> /x86_64/qom/pc-i440fx-2.0: OK >> 10.41 real 1.32 user 9.09 sys >> /x86_64/qom/pc-i440fx-2.0: OK >> 8.45 real 1.24 user 7.24 sys >> /x86_64/qom/pc-i440fx-2.0: OK >> 9.88 real 1.10 user 8.31 sys >> /x86_64/qom/pc-i440fx-2.0: OK >> 11.60 real 1.47 user 9.90 sys >> /x86_64/qom/pc-i440fx-2.0: OK >> 10.94 real 1.28 user 9.68 sys >> /x86_64/qom/pc-i440fx-2.0: OK >> 10.06 real 1.32 user 8.76 sys >> /x86_64/qom/pc-i440fx-2.0: OK >> 13.38 real 1.37 user 12.04 sys >> /x86_64/qom/pc-i440fx-2.0: OK >> 16.19 real 1.46 user 14.29 sys >> /x86_64/qom/pc-i440fx-2.0: OK >> 9.70 real 1.17 user 8.51 sys >> >> Admittedly this is running in a (KVM) VM, but still, there seems >> something wrong with how long each of these is taking. On Linux >> each run is less than a second, so there's an order-of-magnitude >> slowdown here. Further, I've occasionally seen a run take 100 seconds! >> >> Does anybody else see this, and any ideas why it might be running slow? >> I'm not very familiar with debugging on netbsd; I had a look at >> ktrace output, and the QEMU process seems to sometimes spend >> quite a lot of time in a poll() loop not actually doing anything. >> I couldn't figure out how to get the ktrace logs to annotate >> which thread was making which syscall though, so they weren't >> easy to interpret. If anybody's more experienced at debugging >> things in the BSDs that would also be helpful. >> >> On OpenBSD, for comparison, each test run seems to fairly reliably >> take 5 seconds give-or-take, there's much less run-to-run >> variation, though it's still much slower than Linux is. >> The OpenBSD and FreeBSD build VMs seem to complete more >> reasonably quickly than the NetBSD one. >> >> One thing I noticed looking at ktrace output is that we do >> all our reading of QMP input and output with a read syscall >> per character. I don't think that's the cause of this slowness, >> though. >> >> thanks >> -- PMM >> > > I'm running these tests natively and get apparently expected results: > > /x86_64/qom/pc-i440fx-2.0: OK > 2,05 real 1,36 user 0,71 sys > /x86_64/qom/pc-i440fx-2.0: OK > 1,92 real 1,17 user 0,79 sys > /x86_64/qom/pc-i440fx-2.0: OK > 1,84 real 1,14 user 0,77 sys > /x86_64/qom/pc-i440fx-2.0: OK > 1,85 real 1,16 user 0,76 sys > /x86_64/qom/pc-i440fx-2.0: OK > 1,79 real 1,04 user 0,82 sys > /x86_64/qom/pc-i440fx-2.0: OK > 1,84 real 1,00 user 0,91 sys > /x86_64/qom/pc-i440fx-2.0: OK > 1,86 real 1,18 user 0,75 sys > /x86_64/qom/pc-i440fx-2.0: OK > 1,85 real 1,27 user 0,64 sys > /x86_64/qom/pc-i440fx-2.0: OK > 1,84 real 1,27 user 0,64 sys > /x86_64/qom/pc-i440fx-2.0: OK > 1,82 real 1,18 user 0,71 sys > There is a registered bug in the NetBSD database: https://gnats.netbsd.org/52184 "Recent qemu performs badly on NetBSD hosts under load" Could you please try to check if the following commit is culprit using the reproducer in gnats or running qom-test? commit 05e514b1d4d5bd4209e2c8bbc76ff05c85a235f3 Author: Paolo Bonzini <pbonzini@redhat.com> Date: Tue Jul 21 16:07:53 2015 +0200 AioContext: optimize clearing the EventNotifier It is pretty rare for aio_notify to actually set the EventNotifier. It can happen with worker threads such as thread-pool.c's, but otherwise it should never be set thanks to the ctx->notify_me optimization. The previous patch, unfortunately, added an unconditional call to event_notifier_test_and_clear; now add a userspace fast path that avoids the call. Note that it is not possible to do the same with event_notifier_set; it would break, as proved (again) by the included formal model. This patch survived over 3000 reboots on aarch64 KVM. Signed-off-by: Paolo Bonzini <pbonzini@redhat.com> Reviewed-by: Fam Zheng <famz@redhat.com> Tested-by: Richard W.M. Jones <rjones@redhat.com> Message-id: 1437487673-23740-7-git-send-email-pbonzini@redhat.com Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com> [-- Attachment #2: OpenPGP digital signature --] [-- Type: application/pgp-signature, Size: 850 bytes --] ^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: [Qemu-devel] qom-test on netbsd can be very slow 2018-04-09 17:10 [Qemu-devel] qom-test on netbsd can be very slow Peter Maydell 2018-04-09 20:51 ` Kamil Rytarowski @ 2018-04-10 8:19 ` Daniel P. Berrangé 1 sibling, 0 replies; 4+ messages in thread From: Daniel P. Berrangé @ 2018-04-10 8:19 UTC (permalink / raw) To: Peter Maydell; +Cc: QEMU Developers, Eric Blake, Markus Armbruster On Mon, Apr 09, 2018 at 06:10:43PM +0100, Peter Maydell wrote: > My NetBSD build system recently seems to have taken a nosedive > in how long it takes to finish "make check". This seems to be > because qom-test (and probably other things where the test interacts > with the QEMU process) can run very slowly. > > netbsdvm# for i in 1 2 3 4 5 6 7 8 9 10; do > (QTEST_QEMU_BINARY=x86_64-softmmu/qemu-system-x86_64 time > tests/qom-test -p /x86_64/qom/pc-i440fx-2.0); done > /x86_64/qom/pc-i440fx-2.0: OK > 8.49 real 1.18 user 7.34 sys > /x86_64/qom/pc-i440fx-2.0: OK > 10.41 real 1.32 user 9.09 sys > /x86_64/qom/pc-i440fx-2.0: OK > 8.45 real 1.24 user 7.24 sys > /x86_64/qom/pc-i440fx-2.0: OK > 9.88 real 1.10 user 8.31 sys > /x86_64/qom/pc-i440fx-2.0: OK > 11.60 real 1.47 user 9.90 sys > /x86_64/qom/pc-i440fx-2.0: OK > 10.94 real 1.28 user 9.68 sys > /x86_64/qom/pc-i440fx-2.0: OK > 10.06 real 1.32 user 8.76 sys > /x86_64/qom/pc-i440fx-2.0: OK > 13.38 real 1.37 user 12.04 sys > /x86_64/qom/pc-i440fx-2.0: OK > 16.19 real 1.46 user 14.29 sys > /x86_64/qom/pc-i440fx-2.0: OK > 9.70 real 1.17 user 8.51 sys > > Admittedly this is running in a (KVM) VM, but still, there seems > something wrong with how long each of these is taking. On Linux > each run is less than a second, so there's an order-of-magnitude > slowdown here. Further, I've occasionally seen a run take 100 seconds! > > Does anybody else see this, and any ideas why it might be running slow? My only real suggestion is to try "git bisect" as presumably this is a regression caused by something we've merged in this dev cycle ? > One thing I noticed looking at ktrace output is that we do > all our reading of QMP input and output with a read syscall > per character. I don't think that's the cause of this slowness, > though. IIRC, that has been long standing behaviour so would be unlikely to explain a recent slowdown, nor the huge variation in time for some runs. Regards, Daniel -- |: https://berrange.com -o- https://www.flickr.com/photos/dberrange :| |: https://libvirt.org -o- https://fstop138.berrange.com :| |: https://entangle-photo.org -o- https://www.instagram.com/dberrange :| ^ permalink raw reply [flat|nested] 4+ messages in thread
end of thread, other threads:[~2018-04-10 8:19 UTC | newest] Thread overview: 4+ messages (download: mbox.gz follow: Atom feed -- links below jump to the message on this page -- 2018-04-09 17:10 [Qemu-devel] qom-test on netbsd can be very slow Peter Maydell 2018-04-09 20:51 ` Kamil Rytarowski 2018-04-09 23:31 ` Kamil Rytarowski 2018-04-10 8:19 ` Daniel P. Berrangé
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).