Re: [RFC PATCH 0/2] qtest: Log verbosity changes

[Markus Armbruster <armbru@redhat.com>]

Fabiano Rosas <farosas@suse.de> writes:

> Peter Maydell <peter.maydell@linaro.org> writes:
>
>> On Fri, 6 Sept 2024 at 09:14, Daniel P. Berrangé <berrange@redhat.com> wrote:
>>>
>>> On Fri, Sep 06, 2024 at 08:16:31AM +0200, Thomas Huth wrote:
>>> > On 05/09/2024 23.03, Fabiano Rosas wrote:
>>> > > Hi,
>>> > >
>>> > > This series silences QEMU stderr unless the QTEST_LOG variable is set
>>> > > and silences -qtest-log unless both QTEST_LOG and gtest's --verbose
>>> > > flag is passed.
>>> > >
>>> > > This was motivated by Peter Maydell's ask to suppress deprecation
>>> > > warn_report messages from the migration-tests and by my own
>>> > > frustration over noisy output from qtest.
>>
>> This isn't what I want, though -- what I want is that a
>> qtest run should not print "warning:" messages for things
>> that we expect to happen when we run that test. I *do* want
>> warnings for things that we do not expect to happen when
>> we run the test.
>>
>>> > Not sure whether we want to ignore stderr by default... we might also miss
>>> > important warnings or error messages that way...?
>>>
>>> I would prefer if our tests were quiet by default, and just printed
>>> clear pass/fail notices without extraneous fluff. Having an opt-in
>>> to see full messages from stderr feels good enough for debugging cases
>>> where you need more info from a particular test.
>>
>> I find it is not uncommon that something fails and
>> you don't necessarily have the option to re-run it with
>> the "give me the error message this time" flag turn on.
>> CI is just the most obvious example; other kinds of
>> intermittent failure can be similar.
>>
>>> Probably we should set verbose mode in CI though, since it is tedious
>>> to re-run CI on failure to gather more info
>>>
>>> > If you just want to suppress one certain warning, I think it's maybe best to
>>> > fence it with "if (!qtest_enabled()) { ... }" on the QEMU side - at least
>>> > that's what we did in similar cases a couple of times, IIRC.
>>>
>>> We're got a surprisingly large mumber of if(qtest_enabled()) conditions
>>> in the code. I can't help feeling this is a bad idea in the long term,
>>> as its making us take different codepaths when testing from production.
>>
>> What I want from CI and from tests in general:
>>  * if something fails, I want all the information
>>  * if something unexpected happens I want the warning even
>>    if the test passes (this is why I grep the logs for
>>    "warning:" in the first place -- it is to catch the case
>>    of "something went wrong but it didn't result in QEMU or
>>    the test case exiting with a failure status")
>>  * if something is expected, it should be silent
>>
>> That means there's a class of messages where we want to warn
>> the user that they're doing something that might not be what
>> they intended or which is deprecated and will go away soon,
>> but where we do not want to "warn" in the test logging because
>> the test is deliberately setting up that oddball corner case.
>>
>> It might be useful to have a look at where we're using
>> if (qtest_enabled()) to see if we can make some subcategories
>> avoid the explicit if(), e.g. by having a warn_deprecated(...)
>> and hide the "don't print if qtest" inside the function.
>>
>
> I could add error/warn variants that are noop in case qtest is
> enabled. It would, however, lead to this pattern which is discouraged by
> the error.h documentation (+Cc Markus for advice):
>
> before:
>     if (!dinfo && !qtest_enabled()) {
>         error_report("A flash image must be given with the "
>                      "'pflash' parameter");
>         exit(1);
>     }

This is connex_init() and verdex_init() in hw/arm/gumstix.c.

qtest_enabled() is *not* just suppressing a warning here, it's
suppressing a fatal error.  We use it to take a different codepath,
which is what Peter called out as a bad idea.

Comes from commit bdf921d65f8 (gumstix: Don't enforce use of -pflash for
qtest).

> after:
>     if (!dinfo) {
>         error_report_noqtest(&error_fatal,
>                              "A flash image must be given with the "
>                              "'pflash' parameter");
>     }

I don't like creating infrastructure to make bad ideas look less
obviously bad.

> For both error/warn, we'd reduce the amount of qtest_enabled() to only
> the special cases not related to printing. We'd remove ~35/83 instances,
> not counting the 7 printfs.
>
>> Some categories as a starter:
>>  * some board models will error-and-exit if the user
>>    didn't provide any guest code (eg no -kernel option),
>>    like hw/m68k/an5206.c. When we're running with the
>>    qtest accelerator it's fine and expected that there's
>>    no guest code loaded because we'll never run any guest code

Having tests provide the things users need to provide feels better.  It
may not always be practical.

I guess the example above is in this camp.

>>  * in some places (eg target/arm/cpu.c) we treat qtest as
>>    another accelerator type, so we might say
>>    if (tcg_enabled() || qtest_enabled()) to mean "not
>>    hvf or kvm"
>>  * sometimes we print a deprecation message only if
>>    not qtest, eg hw/core/numa.c or hw/core/machine.c

This is obviously fine, and if you guys want infrastructure for that,
I'll give it a sympathetic review.

>>  * the clock related code needs to be qtest aware because
>>    under qtest it's the qtest protocol that advances the
>>    clock
>>  * sometimes we warn about possible user error if not
>>    qtest, eg hw/ppc/pnv.c or target/mips/cpu.c

This can be fine, but it's not obviously fine.