Re: [Qemu-devel] qom-test on netbsd can be very slow

[Kamil Rytarowski]

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 <address@hidden>
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 <address@hidden>
    Reviewed-by: Fam Zheng <address@hidden>
    Tested-by: Richard W.M. Jones <address@hidden>
    Message-id: address@hidden
    Signed-off-by: Stefan Hajnoczi <address@hidden>

signature.asc
Description: OpenPGP digital signature