Bug 52210 - ucs-test console output doesn't show filename of failing tests
ucs-test console output doesn't show filename of failing tests
Status: CLOSED FIXED
Product: UCS Test
Classification: Unclassified
Component: General
unspecified
Other Linux
: P5 normal (vote)
: UCS 5.0
Assigned To: Philipp Hahn
Florian Best
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2020-10-13 12:58 CEST by Arvid Requate
Modified: 2021-05-25 16:00 CEST (History)
3 users (show)

See Also:
What kind of report is it?: Development Internal
What type of bug is this?: ---
Who will be affected by this bug?: ---
How will those affected feel about the bug?: ---
User Pain:
Enterprise Customer affected?:
School Customer affected?:
ISV affected?:
Waiting Support:
Flags outvoted (downgraded) after PO Review:
Ticket number:
Bug group (optional):
Max CVSS v3 score:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Arvid Requate univentionstaff 2020-10-13 12:58:52 CEST
It would be great if the ucs-test console output would show the actual filename of the test case. Currently it doesn't, example:

Create and modify UCS-User and verify attributes in sync-mode..... Test failed

So each time you have to search the log file for the string first to find out the filename.
Comment 1 Felix Botner univentionstaff 2020-10-13 13:36:32 CEST
we already have -v

-> ucs-test  -s checks -v
Starting 1 ucs-test at 2020-10-13 12:54:43 to /var/log/univention/test_1602586482.log
UCS 4.4-6-e750 ucs-test 9.0.5-11A~4.4.0.202010061437
===================================================================================== Section 'checks' ====================================================================================
2020-10-13 12:54:43,786 INFO:test.case:Loading test /usr/share/ucs-test/00_checks/04_check_root_password
2020-10-13 12:54:43,789 INFO:test.case:Checking test /usr/share/ucs-test/00_checks/04_check_root_password
Check root password is sha-512..............................................................................

would that be OK, otherwise we could change the default (text) output to something like

Check root password is sha-512 (04_check_root_password)................................................................................................ Test passed

or

Check root password is sha-512 (/usr/share/ucs-test/00_checks/04_check_root_password).................................................................. Test passe

or
===================================================================================== Section 'checks' ====================================================================================
/usr/share/ucs-test/00_checks/04_check_root_password
Check root password is sha-512......................................................................................................................... Test passed
Comment 2 Arvid Requate univentionstaff 2020-10-14 12:17:51 CEST
The first one works but the second one would ease parsing, e.g. when grepping for "Test failed"
Comment 3 Arvid Requate univentionstaff 2020-10-14 12:23:20 CEST
Also the output looks pretty strange:

2020-10-14 11:53:38,081 INFO:test.case:Loading test /usr/share/ucs-test/52_s4connector/120sync_create_and_modify_ucs_user
2020-10-14 11:53:38,088 INFO:test.case:Checking test /usr/share/ucs-test/52_s4connector/120sync_create_and_modify_ucs_user
Create and modify UCS-User and verify attributes in sync-mode.............................................................................. 2020-10-14 11:56:46,778 INFO:test.case:Test [u'/bin/bash', '120sync_create_and_modify_ucs_user'] using /bin/bash in /usr/share/ucs-test/52_s4connector returned 121 in 188687.946 ms
Test failed

And with "| tee foo.log" the line order changes and wrapping is strange:

Create and modify UCS-User and verify attrib
utes in sync-mode........................... 2020-10-14 12:19:06,271 INFO:test.case:Test [u'/bin/bash', '120sync_create_and_modify_ucs_user'] using /bin/bash in /usr/share/ucs-test/52_s4connector returned 100 in 185367.386 ms
2020-10-14 12:19:06,272 INFO:test.case:Loading test /usr/share/ucs-test/52_s4connector/122sync_delete_ucs_user_attribute
2020-10-14 12:19:06,274 INFO:test.case:Checking test /usr/share/ucs-test/52_s4connector/122sync_delete_ucs_user_attribute
Test passed
Comment 4 Philipp Hahn univentionstaff 2020-11-10 11:28:14 CET
(In reply to Arvid Requate from comment #3)
> Also the output looks pretty strange:

> 2020-10-14 11:53:38,081 INFO:test.case:Loading test /usr/share/ucs-test/52_s4connector/120sync_create_and_modify_ucs_user
> 2020-10-14 11:53:38,088 INFO:test.case:Checking test /usr/share/ucs-test/52_s4connector/120sync_create_and_modify_ucs_user

The ucs-test framework logs to STDERR

> Create and modify UCS-User and verify attributes in sync-mode..............................................................................

while the "nice output got humans" goes to STDOUT.

>  2020-10-14 11:56:46,778 INFO:test.case:Test [u'/bin/bash', '120sync_create_and_modify_ucs_user'] using /bin/bash in /usr/share/ucs-test/52_s4connector returned 121 in 188687.946 ms
Test failed

> And with "| tee foo.log" the line order changes and wrapping is strange:

This is because "| tee" only processed STDOUT, while STDERR still goes directly to your terminal. Use "2>&1 | tee" to mix the output yourself.

PS: "ucs-test --format" can be used to select between multiple output formats: TAP, Jenkins.xml, text, html, JUnix.xml.
Several of them distinguish between STDOUT and STDERR, so ucs-test tries hard to keep the output of the individual test cases separate and does the mixing itself only at the end. As ucs-test uses STDOUT and STDERR itself the output sometimes looks strange.
If you want to post-process the results use one of the output formats above which have a stable API.


(In reply to Arvid Requate from comment #0)
> It would be great if the ucs-test console output would show the actual
> filename of the test case. Currently it doesn't, example:

The available space on screen is often quiet limited ($COLUMNS), so cluttering the output with the additional filename is contra productive.
I've added '--format raw':

[5.0-0] a503c11388 Bug #52210 test: Fix TestCase().load()
 test/ucs-test/bin/runner                           |  2 +-
 test/ucs-test/bin/ucs-test                         |  2 +-
 test/ucs-test/univention/testing/data.py           | 22 ++++++++++------------
 test/ucs-test/univention/testing/format/html.py    |  3 +--
 test/ucs-test/univention/testing/format/jenkins.py |  3 +--
 test/ucs-test/univention/testing/format/junit.py   |  3 +--
 test/ucs-test/univention/testing/format/tap.py     |  3 +--
 test/ucs-test/univention/testing/format/text.py    |  3 +--
 8 files changed, 17 insertions(+), 24 deletions(-)

[5.0-0] a3c87c929e Bug #52210 test: Add `Raw` output format
 test/ucs-test/debian/changelog                     |  1 +
 .../ucs-test/univention/testing/format/__init__.py | 10 +++++-----
 test/ucs-test/univention/testing/format/text.py    | 23 +++++++++++++++++++++-
 3 files changed, 28 insertions(+), 6 deletions(-)

[5.0-0] 71df119c80 Bug #52229 test: Fix updater tests
 test/ucs-test/debian/changelog                  |  6 +++++
 test/ucs-test/tests/09_updater/20patch-single   |  4 +--
 test/ucs-test/tests/09_updater/21patch-multiple |  6 ++---
 test/ucs-test/tests/09_updater/22minor          |  6 ++---
 test/ucs-test/tests/09_updater/23major          |  8 +++---
 test/ucs-test/tests/09_updater/27updateto       |  8 +++---
 test/ucs-test/tests/09_updater/28errors         |  8 +++---
 test/ucs-test/tests/09_updater/29updater-status | 34 +++++++++++++++----------
 test/ucs-test/tests/09_updater/33source         |  2 +-
 test/ucs-test/tests/09_updater/34updater-check  |  4 +--
 ...
 28 files changed, 372 insertions(+), 243 deletions(-)

[5.0-0] 6e62e43b63 Bug #52197 test: Cleanup argument parser
 test/ucs-test/bin/runner                           |  65 +++++--
 test/ucs-test/bin/ucs-test                         |  56 +++---
 .../tests/80_docker/53_missing_dockerimage         |   4 +-
 test/ucs-test/univention/testing/codes.py          |   8 +-
 test/ucs-test/univention/testing/data.py           | 193 +++++++++++----------
 test/ucs-test/univention/testing/format/html.py    |  28 +--
 test/ucs-test/univention/testing/format/jenkins.py |  28 +--
 test/ucs-test/univention/testing/format/junit.py   |  31 ++--
 test/ucs-test/univention/testing/format/tap.py     |  20 ++-
 test/ucs-test/univention/testing/format/text.py    |  36 ++--
 ...
 13 files changed, 381 insertions(+), 274 deletions(-)

Package: ucs-test
Version: 10.0.1-25A~5.0.0.202011101123
Branch: ucs_5.0-0

# ucs-test -E dangerous --format raw --count
...
> Starting 54 ucs-test at 2020-11-10 11:21:17 to /var/log/univention/test_1605003676.log
> UCS 5.0-0-e0 ucs-test 10.0.1-25
> ============= Section 'updater' =========================
> 01/54 09_updater/10online.................... Test passed
...
Comment 5 Philipp Hahn univentionstaff 2021-02-02 06:25:10 CET
From Bug #51316:
[5.0-0] 2534adbf0b fix Bug #52210 test: Add `Raw` output format

Package: ucs-test
Version: 10.0.3-1A~5.0.0.202102011834
Comment 6 Florian Best univentionstaff 2021-02-05 11:59:05 CET
OK: ucs-test -F raw

very nice, I just used it when migrating a whole section to Python 3.
Comment 7 Florian Best univentionstaff 2021-05-25 16:00:00 CEST
UCS 5.0 has been released:
 https://docs.software-univention.de/release-notes-5.0-0-en.html
 https://docs.software-univention.de/release-notes-5.0-0-de.html

If this error occurs again, please use "Clone This Bug".