Re: [Qemu-devel] [RFC PATCH] tests/qemu-iotests: re-format output to for make check-block

[Alex Bennée]

Vladimir Sementsov-Ogievskiy <address@hidden> writes:

> 05.05.2019 18:54, Thomas Huth wrote:
>> On 03/05/2019 18.15, Alex Bennée wrote:
>>>
>>> Thomas Huth <address@hidden> writes:
>>>
>>>> On 03/05/2019 16.39, Alex Bennée wrote:
>>>>> This attempts to clean-up the output to better match the output of the
>>>>> rest of the QEMU check system. This includes:
>>>>>
>>>>>    - formatting as "  TEST    iotest: nnn"
>>>>>    - calculating time diff at the end
>>>>>    - only dumping config on failure
>>>>>
>>>>> Signed-off-by: Alex Bennée <address@hidden>
>>>>> ---
>>>>>   tests/qemu-iotests/check | 71 +++++++++++++++++++---------------------
>>>>>   1 file changed, 34 insertions(+), 37 deletions(-)
>>>>
>>>> Thanks for tackling this! The output now looks nicer indeed if you run
>>>> "make check-qtest check-block -j8". However, if you add a "V=1" at the
>>>> end of the command line, the outputs look quite different again...
>>>>
>>>> That's why I thought that having a TAP mode for the check script could
>>>> be a good idea, too. Then we could pipe the output through the
>>>> tap-driver.pl script, too, so we get uniform output for all tests...?
>>>
>>> That would probably be a cleaner approach. What would be even better is
>>> somehow expanding the list of tests at make time so you could run your
>>> tests in parallel.
>>
>> I agree that this might be the ultimate solution ... but I'm not sure
>> whether the iotests are really ready for being run in parallel yet, so
>> it will likely take quite some while 'till we are at that point. With
>> that in mind (and thus also not sure yet whether my TAP idea is really
>> the right approach), your patch is certainly a good interim solution
>> which we should try to get merged, too, when my "make check" series gets
>> accepted?
>>
>>> I did wonder how useful the timing stuff was to developers.
>>
>> Yes, me too ... maybe the block layer folks can comment on that one...?
>>
>>   Thomas
>>
>
> Hi!
>
> It was useful to not miss performance degradation (1) and
> to understand that test hangs (2) (if you know that it should
> finish in 1 second, but 10 seconds already passed, the test
> most probably hangs)
>
> Run tests with your patch:
>
> first run:
> # check -qcow2 -T
>    TEST    iotest: 001 [20:00:30] -> [20:00:31]
>    TEST    iotest: 002 [20:00:31] -> [20:00:33]
>    TEST    iotest: 003 [20:00:33] -> [20:00:34]
>    TEST    iotest: 004 [20:00:34] -> [20:00:35]
>    TEST    iotest: 005 [20:00:35] -> [20:00:36]
>    TEST    iotest: 007 [20:00:36] -> [20:00:39]
>
>
> second run:
> # check -qcow2 -T
>    TEST    iotest: 001 [20:00:41] -> [20:00:43] 2s (last 1s)
>    TEST    iotest: 002 [20:00:43] -> [20:00:44] 1s (last 2s)
>    TEST    iotest: 003 [20:00:44] -> [20:00:46] 2s (last 1s)
>    TEST    iotest: 004 [20:00:46] -> [20:00:46] 0s (last 1s)
>    TEST    iotest: 005 [20:00:46] -> [20:00:47] 1s (last 1s)
>    TEST    iotest: 007 [20:00:47] -> [20:00:50] 3s (last 3s)
>    TEST    iotest: 008 [20:00:50] -> [20:00:51]
>    TEST    iotest: 009 [20:00:51] -> [20:00:51]
>    TEST    iotest: 010 [20:00:51] -> [20:00:51]
>
>
> So, in first run delta was not calculated and on second - calculated.
> Could you calculate delta in all cases, to make first run look like
> # check -qcow2 -T
>    TEST    iotest: 001 [20:00:30] -> [20:00:31] 1s
>    TEST    iotest: 002 [20:00:31] -> [20:00:33] 2s
>    TEST    iotest: 003 [20:00:33] -> [20:00:34] 1s
>    TEST    iotest: 004 [20:00:34] -> [20:00:35] 1s
>    TEST    iotest: 005 [20:00:35] -> [20:00:36] 1s
>    TEST    iotest: 007 [20:00:36] -> [20:00:39] 3s

Sure that seems easy enough.

--
Alex Bennée