sanitycheck: show handler_time in -v output (qemu 2.032s)

We already have the info so let's show it. This helps spots intermittent
issues[*], gives an indication of the time --build-only saves, can help
spot an overloaded test system, highlights the most time-consuming tests
which may need a longer timeout in their config, shows the effective
timeout value when one occurs... all this for a dirt cheap screen estate
price and two extra lines of code.

Sample -v output:

32/81 board123  tests/testme              PASSED (qemu 2.049s)
33/81 board456  samples/hello             PASSED (build)
34/81 qemu_x3   tests/kernel.stack.usage  FAILED: timeout (qemu 60.029s)
     see: sanity-out/qemu_x3/tests/kernel.stack.usage/handler.log
35/81 board456  tests/testme              PASSED (build)
36/81 qemu_x5   tests/kernel.queue        FAILED: failed (qemu 2.191s)
     see: sanity-out/qemu_x5/tests/kernel.queue/handler.log

[*] running qemu in heavily packed cloud virtual machines comes to mind,
    also see #12553, #14173 etc.

Signed-off-by: Marc Herbert <marc.herbert@intel.com>
This commit is contained in:
Marc Herbert 2019-06-20 10:00:20 -07:00 committed by Anas Nashif
parent 58e05ddcc1
commit 35dc96399c

View file

@ -3094,6 +3094,9 @@ def chatty_test_cb(instances, goals, goal):
if goal.handler:
handler_type = goal.handler.type_str
htime = goal.metrics.get("handler_time", None)
if htime:
handler_type += " {:.3f}s".format(htime)
else:
handler_type = "build"