Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

scripts: twister: Enhance TestCase/Instance information and presentation #77488

Conversation

LukaszMrugala
Copy link
Collaborator

@LukaszMrugala LukaszMrugala commented Aug 23, 2024

Description

ExecutionCounter has been expanded and now hold i.a. more information on the statuses of TestCases. This information is now incorporated in relevant summaries - runner.py and reports.py. Layout of those was changed to present that and previous information in a clear and concise way.

TestInstance execution counter now is more intuitive. Instances filtered out before running are no longer included there. Retries now properly reset the counter.

TestCases with NONE and other incorrect final statuses are logged as errors, but do not exit Twister with a nonzero exit code. This is because NONE statuses, although incorrect, are currently common.

Note that this PR does not concern itself with the logic of status assignments and will not be fixing some peculiarities of current status regime.

Demonstration

To illustrate the difference, I have run the tests/ztest tests with an additional tests/ztest/temp directory, containing the following testsuites, allowing for a wider status spread:

  • testing.ztest.temp.error - a test that always errors out
  • testing.ztest.temp.fail - a test that always fails
  • testing.ztest.temp.filter - a test skipped by a filter statically
  • testing.ztest.temp.runtime_filter - a test skipped by a filter at runtime
  • testing.ztest.temp.pass - a simple test that should pass
  • testing.ztest.temp.build_only_skip - a test that is build_only

runner.py summary

Old style:

--------------------------------
Total test suites: 32
Total test cases: 148
Executed test cases: 118
Skipped test cases: 30
Completed test suites: 31
Passing test suites: 12
Failing test suites: 1
Skipped test suites: 18
Skipped test suites (runtime): 1
Skipped test suites (filter): 17
Errors: 1
--------------------------------

New style:

--------------------------------------------------
Total test suites:     32
Processed test suites: 32
├─ Filtered test suites (static):       17
└─ Completed test suites:               15
   ├─ Filtered test suites (at runtime):    1
   ├─ Passed test suites:                  12
   ├─ Failed test suites:                   1
   └─ Errors in test suites:                1

Filtered test suites: 18
├─ Filtered test suites (static):        17
└─ Filtered test suites (at runtime):     1
----------------------      ----------------------
Total test cases: 148
├─ Filtered test cases:  28
├─ Skipped test cases:    2
└─ Executed test cases: 118
   ├─ Passed test cases:       110
   ├─ Blocked test cases:        1
   ├─ Failed test cases:         1
   ├─ Errors in test cases:      0
   ├──── The following test case statuses should not appear in a proper execution ───
   └─ Statusless test cases:     6
--------------------------------------------------

Full run log

Old style:

<user>:<ZEPHYR_BASE>$ twister -T tests/ztest/ -v -p qemu_x86_64 --retry-failed 1
Renaming output directory to <ZEPHYR_BASE>/twister-out.10
INFO    - Using Ninja..
INFO    - Zephyr version: v3.7.0-1575-g45705a84ab8e
INFO    - Using 'zephyr' toolchain.
INFO    - Building initial testsuite list...
INFO    - Writing JSON report <ZEPHYR_BASE>/twister-out/testplan.json
INFO    - JOBS: 12
INFO    - Adding tasks to the queue...
INFO    - Added initial list of jobs to queue
INFO    - 18/32 qemu_x86_64               tests/ztest/temp/subgroup_runtime_filter/testing.ztest.temp.runtime_filter SKIPPED (runtime filter)
INFO    - 19/32 qemu_x86_64               tests/ztest/temp/subgroup_error/testing.ztest.temp.error  ERROR Build failure (qemu)
ERROR   - see: <ZEPHYR_BASE>/twister-out/qemu_x86_64/tests/ztest/temp/subgroup_error/testing.ztest.temp.error/build.log
INFO    - 20/32 qemu_x86_64               tests/ztest/temp/subgroup_skip/testing.ztest.temp.build_only_skip PASSED (build)
INFO    - 21/32 qemu_x86_64               tests/ztest/base/testing.ztest.base.verbose_2      PASSED (qemu 1.451s)
INFO    - 22/32 qemu_x86_64               tests/ztest/error_hook/testing.ztest.error_hook.no_userspace PASSED (qemu 1.448s)
INFO    - 23/32 qemu_x86_64               tests/ztest/base/testing.ztest.base.verbose_1      PASSED (qemu 1.359s)
INFO    - 24/32 qemu_x86_64               tests/ztest/zexpect/testing.ztest.expect_cpp       PASSED (qemu 1.246s)
INFO    - 25/32 qemu_x86_64               tests/ztest/zexpect/testing.ztest.expect           PASSED (qemu 1.337s)
INFO    - 26/32 qemu_x86_64               tests/ztest/temp/subgroup_fail/testing.ztest.temp.fail  FAILED Testsuite failed (qemu 1.188s)
ERROR   - see:<ZEPHYR_BASE>/twister-out/qemu_x86_64/tests/ztest/temp/subgroup_fail/testing.ztest.temp.fail/handler.log
INFO    - 27/32 qemu_x86_64               tests/ztest/temp/subgroup_pass/testing.ztest.temp.pass PASSED (qemu 1.233s)
INFO    - 28/32 qemu_x86_64               tests/ztest/ztress/testing.ztest.ztress            PASSED (qemu 6.970s)
INFO    - 29/32 qemu_x86_64               tests/ztest/base/testing.ztest.base.verbose_0      PASSED (qemu 1.350s)
INFO    - 30/32 qemu_x86_64               tests/ztest/summary/testing.ztest.summary.shared_unit_test PASSED (qemu 1.220s)
INFO    - 31/32 qemu_x86_64               tests/ztest/error_hook/testing.ztest.error_hook    PASSED (qemu 1.213s)
INFO    - 32/32 qemu_x86_64               tests/ztest/base/testing.ztest.base.verbose_0_userspace PASSED (qemu 1.215s)

INFO    - 2 Iteration:
INFO    - Adding tasks to the queue...
INFO    - Added initial list of jobs to queue
INFO    - 31/32 qemu_x86_64               tests/ztest/temp/subgroup_fail/testing.ztest.temp.fail  FAILED Testsuite failed (qemu 1.135s)
ERROR   - see:<ZEPHYR_BASE>/twister-out/qemu_x86_64/tests/ztest/temp/subgroup_fail/testing.ztest.temp.fail/handler.log

INFO    - 35 test scenarios (32 test instances) selected, 18 configurations skipped (17 by static filter, 1 at runtime).
INFO    - 12 of 32 test configurations passed (85.71%), 1 failed, 1 errored, 18 skipped with 0 warnings in 163.02 seconds
INFO    - In total 118 test cases were executed, 30 skipped on 1 out of total 2 platforms (50.00%)
INFO    - 12 test configurations executed on platforms, 2 test configurations were only built.
INFO    - Saving reports...
INFO    - Writing JSON report <ZEPHYR_BASE>/twister-out/twister.json
INFO    - Writing xunit report <ZEPHYR_BASE>/twister-out/twister.xml...
INFO    - Writing xunit report <ZEPHYR_BASE>/twister-out/twister_report.xml...
INFO    - -+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+
INFO    - The following issues were found (showing the top 10 items):
INFO    - 1) tests/ztest/temp/subgroup_fail/testing.ztest.temp.fail on qemu_x86_64 failed (Testsuite failed)
INFO    - 2) tests/ztest/temp/subgroup_error/testing.ztest.temp.error on qemu_x86_64 error (Build failure)
INFO    - 
INFO    - To rerun the tests, call twister using the following commandline:
INFO    - west twister -p <PLATFORM> -s <TEST ID>, for example:
INFO    - 
INFO    - west twister -p qemu_x86_64 -s tests/ztest/temp/subgroup_error/testing.ztest.temp.error
INFO    - or with west:
INFO    - west build -p -b qemu_x86_64 tests/ztest/temp/subgroup_error -T testing.ztest.temp.error
INFO    - -+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+
INFO    - Run completed

New style:

<user>:<ZEPHYR_BASE>$ twister -T tests/ztest/ -v -p qemu_x86_64 --retry-failed 1
Renaming output directory to <ZEPHYR_BASE>/twister-out.9
INFO    - Using Ninja..
INFO    - Zephyr version: v3.7.0-1378-g18cf1f3194af
INFO    - Using 'zephyr' toolchain.
INFO    - Building initial testsuite list...
INFO    - Writing JSON report <ZEPHYR_BASE>/twister-out/testplan.json
INFO    - JOBS: 12
INFO    - Adding tasks to the queue...
INFO    - Added initial list of jobs to queue
INFO    -  1/15 qemu_x86_64               tests/ztest/temp/subgroup_runtime_filter/testing.ztest.temp.runtime_filter FILTERED (runtime filter)
INFO    -  2/15 qemu_x86_64               tests/ztest/temp/subgroup_error/testing.ztest.temp.error  ERROR Build failure (qemu)
ERROR   - see: <ZEPHYR_BASE>/twister-out/qemu_x86_64/tests/ztest/temp/subgroup_error/testing.ztest.temp.error/build.log
INFO    -  3/15 qemu_x86_64               tests/ztest/base/testing.ztest.base.verbose_2      PASSED (qemu 1.457s)
INFO    -  4/15 qemu_x86_64               tests/ztest/temp/subgroup_pass/testing.ztest.temp.pass PASSED (qemu 1.346s)
INFO    -  5/15 qemu_x86_64               tests/ztest/zexpect/testing.ztest.expect           PASSED (qemu 1.512s)
INFO    -  6/15 qemu_x86_64               tests/ztest/zexpect/testing.ztest.expect_cpp       PASSED (qemu 1.338s)
INFO    -  7/15 qemu_x86_64               tests/ztest/temp/subgroup_fail/testing.ztest.temp.fail  FAILED Testsuite failed (qemu 1.138s)
ERROR   - see: <ZEPHYR_BASE>/twister-out/qemu_x86_64/tests/ztest/temp/subgroup_fail/testing.ztest.temp.fail/handler.log
ERROR   - A None status detected in instance qemu_x86_64/tests/ztest/temp/subgroup_skip/testing.ztest.temp.build_only_skip, test case testing.ztest.temp.build_only_skip.skip.
INFO    -  8/15 qemu_x86_64               tests/ztest/temp/subgroup_skip/testing.ztest.temp.build_only_skip PASSED (build)
INFO    -  9/15 qemu_x86_64               tests/ztest/base/testing.ztest.base.verbose_1      PASSED (qemu 1.274s)
ERROR   - A None status detected in instance qemu_x86_64/tests/ztest/error_hook/testing.ztest.error_hook.no_userspace, test case testing.ztest.error_hook.no_userspace.to_skip1.
ERROR   - A None status detected in instance qemu_x86_64/tests/ztest/error_hook/testing.ztest.error_hook.no_userspace, test case testing.ztest.error_hook.no_userspace.to_skip0.
INFO    - 10/15 qemu_x86_64               tests/ztest/error_hook/testing.ztest.error_hook.no_userspace PASSED (qemu 1.199s)
INFO    - 11/15 qemu_x86_64               tests/ztest/ztress/testing.ztest.ztress            PASSED (qemu 7.027s)
INFO    - 12/15 qemu_x86_64               tests/ztest/base/testing.ztest.base.verbose_0      PASSED (qemu 1.255s)
ERROR   - A None status detected in instance qemu_x86_64/tests/ztest/summary/testing.ztest.summary.shared_unit_test, test case testing.ztest.summary.shared_unit_test.foo.
INFO    - 13/15 qemu_x86_64               tests/ztest/summary/testing.ztest.summary.shared_unit_test PASSED (qemu 1.141s)
ERROR   - A None status detected in instance qemu_x86_64/tests/ztest/error_hook/testing.ztest.error_hook, test case testing.ztest.error_hook.to_skip1.
ERROR   - A None status detected in instance qemu_x86_64/tests/ztest/error_hook/testing.ztest.error_hook, test case testing.ztest.error_hook.to_skip0.
INFO    - 14/15 qemu_x86_64               tests/ztest/error_hook/testing.ztest.error_hook    PASSED (qemu 1.199s)
INFO    - 15/15 qemu_x86_64               tests/ztest/base/testing.ztest.base.verbose_0_userspace PASSED (qemu 1.208s)

INFO    - 2 Iteration:
INFO    - Adding tasks to the queue...
INFO    - Added initial list of jobs to queue
INFO    - 15/15 qemu_x86_64               tests/ztest/temp/subgroup_fail/testing.ztest.temp.fail  FAILED Testsuite failed (qemu 1.165s)
ERROR   - see: <ZEPHYR_BASE>/twister-out/qemu_x86_64/tests/ztest/temp/subgroup_fail/testing.ztest.temp.fail/handler.log

INFO    - 35 test scenarios (32 test instances) selected, 18 configurations skipped (17 by static filter, 1 at runtime).
INFO    - 12 of 14 executed test configurations passed (85.71%), 1 failed, 1 errored, with no warnings in 144.19 seconds.
INFO    - 110 of 118 executed test cases passed (93.22%), 1 blocked, 1 failed, 6 without a status on 1 out of total 2 platforms (50.00%).
INFO    - 30 selected test cases not executed: 2 skipped, 28 filtered.
INFO    - 12 test configurations executed on platforms, 2 test configurations were only built.
INFO    - Saving reports...
INFO    - Writing JSON report <ZEPHYR_BASE>/twister-out/twister.json
INFO    - Writing xunit report <ZEPHYR_BASE>/twister-out/twister.xml...
INFO    - Writing xunit report <ZEPHYR_BASE>/twister-out/twister_report.xml...
INFO    - -+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+
INFO    - The following issues were found (showing the top 10 items):
INFO    - 1) tests/ztest/temp/subgroup_fail/testing.ztest.temp.fail on qemu_x86_64 failed (Testsuite failed)
INFO    - 2) tests/ztest/temp/subgroup_error/testing.ztest.temp.error on qemu_x86_64 error (Build failure)
INFO    - 
INFO    - To rerun the tests, call twister using the following commandline:
INFO    - west twister -p <PLATFORM> -s <TEST ID>, for example:
INFO    - 
INFO    - west twister -p qemu_x86_64 -s tests/ztest/temp/subgroup_error/testing.ztest.temp.error
INFO    - or with west:
INFO    - west build -p -b qemu_x86_64 tests/ztest/temp/subgroup_error -T testing.ztest.temp.error
INFO    - -+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+
INFO    - Run completed

@LukaszMrugala LukaszMrugala added the DNM This PR should not be merged (Do Not Merge) label Aug 23, 2024
@LukaszMrugala LukaszMrugala force-pushed the lmrugalx_expand_execution_counter branch 3 times, most recently from cc8c848 to 5dca931 Compare August 26, 2024 15:00
@LukaszMrugala LukaszMrugala removed the DNM This PR should not be merged (Do Not Merge) label Aug 27, 2024
@LukaszMrugala LukaszMrugala marked this pull request as ready for review August 27, 2024 07:31
@zephyrbot zephyrbot added the area: Twister Twister label Aug 27, 2024
mdubielx
mdubielx previously approved these changes Sep 2, 2024
arikgreen
arikgreen previously approved these changes Sep 2, 2024
KamilxPaszkiet
KamilxPaszkiet previously approved these changes Sep 2, 2024
# updated in report_out
self._cases = Value('i', 0)

# updated by update_counting_before_pipeline() and report_out()
self._skipped_cases = Value('i', 0)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

please update __init__() comment (lines 64--69) accordingly

scripts/pylib/twister/twisterlib/runner.py Outdated Show resolved Hide resolved
print(f"Executed test cases: {self.cases - self.skipped_cases}")
print(f"Skipped test cases: {self.skipped_cases}")
print(f"Completed test suites: {self.done}")
print(f"Added to pipeline test suites: {self.done}")
Copy link
Member

@golowanow golowanow Sep 2, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

hmm, I might be lost in the example from PR description, but the New style is still something I need to translate in my mind (ordered more like as it happened):

Test Suites:
 selected(32) = filtered(17) + built(15)
 executed(15) = filtered(1) + errored(1) + failed(1) + passed(12)

Test Cases in Suites - built(148):
 not executed (30) = filtered(28) + skipped(2)
 executed (118) = no status(6) +  blocked(1) + errored(0) + failed(1) + passed(110)

Copy link
Collaborator Author

@LukaszMrugala LukaszMrugala Sep 2, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I've taken a page out of Linux tree command and designed this summary:

--------------------------------------------------
Total test suites: 32
Processed test suites: 32
├─ Skipped test suites (static filter): 17
└─ Completed test suites: 15
   ├─ Passing test suites: 12
   ├─ Failing test suites: 1
   ├─ Errors in test suites: 1
   └─ Skipped test suites (at runtime): 1

Skipped test suites: 18
├─ Skipped test suites (at runtime): 1
└─ Skipped test suites (static filter): 17
----------------------      ----------------------
Total test cases: 148
├─ Filtered test cases: 28
├─ Skipped test cases: 2
└─ Executed test cases: 118
   ├─ Failed test cases: 2
   ├─ Error test cases: 0
   ├─ Blocked test cases: 1
   ├─ Passed test cases: 110
   └─ Test cases without a status: 6
--------------------------------------------------

It duplicates some information (test suite skips), but I think it is worth it for the clarity of the connections between the statistics. Would you agree that this is a clear summary?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Just few suggestions:

  • let's always think this output will be parsed by someone with a script using regular expressions, etc.
  • use same words in same form (like 'Passed', not 'Passing').
  • keep rows ordered in sequence of state transitions.
Total Skipped test Suites: 18
├─ Skipped test Suites (static filter): 17
└─ Skipped test Suites (at runtime): 1

And naive questions:

  • Why Executed test cases: 118 don't match to the sum at its sub-items ?

  • what to do with this ?

Test cases without a status: 6

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In order:

  • OK; new output should be easily processed by relying on common breaking symbols - there is always colon, then whitespace, then number and the first word of each line is unique if grouped by tree.
  • OK; Naming is more consistent and a bit shorter now.
  • OK; now the order is roughly conforming to the processing order.
  • This is because we have retries. The failed instance is retried and its cases counted twice. I should reset it like the test suites are when a retry is attempted. From my code analysis, a retry assumes the previous run null and void and should not be reported in the summary. I've changed that so failed instance testcases are not double-counted
  • This is an indication that the current status system has its problems. NONE and STARTED statuses are not proper terminal statuses. However, this change did not cause them, but merely extracted them so they can be viewed by the user. I have added an additional line shortly explaining that to the end user, easily discarded by an automatic user.

With those comments in mind and with formatting changes (right-alignment for numbers, common column length), here is a new design:

--------------------------------------------------
Total test suites:     32
Processed test suites: 32
├─ Skipped test suites (static filter): 17
└─ Completed test suites:               15
   ├─ Skipped test suites (at runtime):     1
   ├─ Passed test suites:                  12
   ├─ Failed test suites:                   1
   └─ Errors in test suites:                1

Skipped test suites: 18
├─ Skipped test suites (static filter): 17
└─ Skipped test suites (at runtime):     1
----------------------      ----------------------
Total test cases: 148
├─ Filtered test cases:  28
├─ Skipped test cases:    2
└─ Executed test cases: 118
   ├─ Passed test cases:       110
   ├─ Blocked test cases:        1
   ├─ Failed test cases:         1
   ├─ Errors in test cases:      0
   ├──── The following test case statuses should not appear in a proper execution ───
   └─ Statusless test cases:     6
--------------------------------------------------

@LukaszMrugala LukaszMrugala added the DNM This PR should not be merged (Do Not Merge) label Sep 2, 2024
@LukaszMrugala LukaszMrugala force-pushed the lmrugalx_expand_execution_counter branch 2 times, most recently from 2f54f04 to a5fc74b Compare September 3, 2024 13:49
@LukaszMrugala LukaszMrugala removed the DNM This PR should not be merged (Do Not Merge) label Sep 3, 2024
@LukaszMrugala LukaszMrugala added the Enhancement Changes/Updates/Additions to existing features label Sep 4, 2024
@LukaszMrugala LukaszMrugala added the DNM This PR should not be merged (Do Not Merge) label Oct 17, 2024
@LukaszMrugala LukaszMrugala dismissed stale reviews from arikgreen and nashif via ade1020 October 18, 2024 07:15
@LukaszMrugala LukaszMrugala force-pushed the lmrugalx_expand_execution_counter branch 2 times, most recently from ade1020 to 579fd3b Compare October 18, 2024 08:22
@LukaszMrugala LukaszMrugala removed the DNM This PR should not be merged (Do Not Merge) label Oct 18, 2024
arikgreen
arikgreen previously approved these changes Oct 21, 2024
@LukaszMrugala LukaszMrugala force-pushed the lmrugalx_expand_execution_counter branch 3 times, most recently from 4662fcd to a88f339 Compare October 24, 2024 10:15
ExecutionCounter has been expanded and now hold i.a.
more information on the statuses of TestCases.
This information is now incorporated in relevant summaries
- runner.py and reports.py.
Layout of those was changed to present that
and previous information in a clear and concise way.

TestInstance execution counter now is more intuitive.
Instances filtered out before running are no longer included there.
Retries now properly reset the counter.

TestCases with None and other incorrect final statuses
are logged as errors, but do not
exit Twister with a nonzero exit code.
This is because None statuses, although incorrect,
are currently common.

Inconsistent spacing in ERROR and FAILED fixed.

Signed-off-by: Lukasz Mrugala <lukaszx.mrugala@intel.com>

scripts: Dmitri fix

Fix of a problem noticed by Dmitri

Removed unnecessary additional spaces when
printing FAILED and ERROR status.
Now TwisterStatus.get_color is used more.

Signed-off-by: Lukasz Mrugala <lukaszx.mrugala@intel.com>
@mmahadevan108 mmahadevan108 added this to the future milestone Oct 29, 2024
@mmahadevan108 mmahadevan108 modified the milestones: future, v4.1.0 Oct 30, 2024
@nashif nashif modified the milestones: v4.1.0, v4.0.0 Oct 31, 2024
@nashif nashif removed the Enhancement Changes/Updates/Additions to existing features label Oct 31, 2024
@nashif
Copy link
Member

nashif commented Oct 31, 2024

@mmahadevan108 @dkalowsk This one fixes a few issues I found in twister, while it does add some additional information in the output (what was considered an enhancement) the issues it fixes are significant to be in the 4.0 release. Thanks.

@mmahadevan108 mmahadevan108 merged commit ff1857a into zephyrproject-rtos:main Oct 31, 2024
32 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging this pull request may close these issues.

9 participants