Commit Graph

180 Commits

Author SHA1 Message Date
Jussi Pakkanen f0fbb31ccf
Merge pull request #8200 from bonzini/mtest-asyncio-logs
mtest: improvements to logging
2021-01-30 09:52:43 +00:00
Xavier Claessens e4137ae3ec test: Make timeout <= 0 infinite duraction 2021-01-27 08:26:20 -05:00
Paolo Bonzini 12b3d05d1e mtest: log individual TAP subtests 2021-01-22 12:18:59 +01:00
Paolo Bonzini 7b02abeac6 mtest: infrastructure to print subtest results 2021-01-22 12:18:59 +01:00
Paolo Bonzini bb9d8b5b80 mtest: move --print-errorlogs output during the test run
Print the (shortened) output of the failed tests as they happen.
If neither --verbose nor --print-errorlogs was specified, omit the
summary of failures, because it is pretty much the same as the earlier
output of "meson test".
2021-01-22 12:18:59 +01:00
Paolo Bonzini 4d6a0cc174 mtest: log test start in verbose mode
In non-parallel verbose mode the output of the test/benchmark
is not buffered, therefore the command line is only printed by
ConsoleLogger for failing tests and only after the test has run.

Verbose mode is designed mostly for CI systems, where output must
be human readable but is generally consumed from a browser with "Find"
commands rather than from a terminal.  With this usecase in mind, it
is better to provide as much detail as possible, so add more output
and just tell the user which tests have started.  Do so, using the
recently introduced TestResult.RUNNING state.
2021-01-22 12:18:59 +01:00
Paolo Bonzini 959e4b3a5e mtest: call TestLogger.start_test when TestRun is in the RUNNING state 2021-01-22 12:18:59 +01:00
Paolo Bonzini 289cc2e2c5 mtest: use buffered stdout/stderr in parallel mode
Similar to ninja, buffer stdout/stderr even in verbose mode if more than one test is
being run in parallel.
2021-01-22 12:18:59 +01:00
Paolo Bonzini a0da710172 mtest: quote environment variable values and command line arguments 2021-01-22 12:18:59 +01:00
Paolo Bonzini 04bab9d595 mtest: include full environment in the TestRun object
Ensure that all the required modifications are included in the logs.
This makes it possible for users to cut-and-paste from the logs when
trying to reproduce failures outside Meson.
2021-01-22 12:18:59 +01:00
Paolo Bonzini 111f22a4f8 mtest: make log output more suitable for console
Right now the same code is used to print the logs for both the console
and the text log.  Differentiating them lets the important bits of
the console output stand out, and makes the console output a bit more
readable.
2021-01-22 12:18:59 +01:00
Paolo Bonzini a118cae9d2 mtest: small refactoring of log printing
Start moving console-specific code to ConsoleLogger, as well
as moving code out of get_log().
2021-01-22 12:18:59 +01:00
Paolo Bonzini 2386f336f1 mtest: log in verbose mode, but not in gdb mode
This is now possible because all stdout/stderr goes through asyncio pipes.
However, logs make little sense in gdb mode.
2021-01-22 12:18:59 +01:00
Paolo Bonzini 2e982a3864 mtest: collect stdout/stderr even in verbose mode
Using verbose mode dropped stdout/stderr from the logs, because
it was not captured.

Now that we can easily stick code in the middle of the reading of
stdout/stderr, use that to print stdout and stderr on the fly
while also capturing them for the logs.  The output is line-buffered.

As a side effect, this also fixes a possible deadlock due to
not using ensure_future around stdo_task and stde_task.  In
particular:

- the stdo_task coroutine would not terminate until the test closed
stdo_task

- the stde_task coroutine would not start until the stdo_task
coroutine finished

Therefore, the test could get stuck waiting for its parent to
read the contents of stderr, but that would not happen because
Meson was still in the stdo_task coroutine.
2021-01-20 15:06:59 +01:00
Paolo Bonzini e7c8555575 mtest: move I/O handling to TestSubprocess
Move the logic to start the read/decode
tasks to TestSubprocess and keep SingleTestRunner simple.

The lines() inner function is tweaked to produce stdout as a future.
This removes the nonlocal access (which is not possible anymore
when the code is moved out of _run_cmd), and also lets _run_cmd
use "await stdo_task" for both parsed and unparsed output.
2021-01-15 15:58:53 +01:00
Paolo Bonzini 401464c61a mtest: tweak the gathering of stdo_task/stde_task results
After the next patch, we will need to complete parse_task before
stdo_task (because parse_task will not set the "stdo" variable
anymore but it will still collect stdout just like now).  Do
the change now to isolate the more complicated changes.
2021-01-15 10:03:54 +01:00
Paolo Bonzini 90ea0dc583 mtest: disable the progress report in gdb mode
Signed-off-by: Paolo Bonzini <pbonzini@redhat.com>
2021-01-15 10:03:54 +01:00
Paolo Bonzini c1c1408fae mtest: introduce ConsoleUser
This new enum can be used by TestSubprocess and TestHarness to
understand (at a higher level) how SingleTestRunner sets up
stdout/stderr redirection.
2021-01-15 10:03:54 +01:00
Paolo Bonzini 1f52e2fa45 mtest: turn TestRun into a hierarchy
Make SimpleTestRunner oblivious of the various test protocols.  All
the different "complete_*" and "parse_*" methods move to the
subclasses of TestRun.
2021-01-15 10:03:54 +01:00
Paolo Bonzini 9e42048e3c mtest: pass command line to TestRun.start
The command line is already available when the test is started.  Pass it to
TestRun.start instead of TestRun.complete*.
2021-01-15 10:03:54 +01:00
Paolo Bonzini 1f5634f15d mtest: add complete_skip to TestRun 2021-01-15 10:03:54 +01:00
Paolo Bonzini c544529faa mtest: simplify complete_exitcode
There is no need anymore to pass the JUnit XML down to complete_exitcode.  Just
set self.junit in complete_gtest instead.
2021-01-15 10:03:54 +01:00
Paolo Bonzini 51e1f01c85 mtest: store the environment in the TestRun
The test_env was lost from the TestRun object in commit
30741a0f2 ("mtest: create TestRun object early on").  Fix
things.
2021-01-15 10:03:54 +01:00
Paolo Bonzini 458c3125e0 mtest: do not print time out message twice
Rebase mistake in "mtest: move timeout message to ConsoleLogger".
2021-01-15 10:03:54 +01:00
Paolo Bonzini ea2f34e286 mtest: allow quickly interrupting the test run
The new behavior of interrupting the longest running test with Ctrl-C is useful
when tests hang, but not when the run is completely broken for some reason.
Psychology tells us that the user will compulsively spam Ctrl-C in this case,
so exit if three Ctrl-C's are detected within a second.
2021-01-14 22:00:51 +00:00
Paolo Bonzini f13b2b4b1d mtest: fix flake8 2021-01-14 22:00:51 +00:00
Paolo Bonzini f13dde1f08 mtest: print TAP subtest count
The parentheses look ugly in the progress report.  To keep it aligned
with the test outcomes, remove them from the outcomes as well.
2021-01-07 19:20:40 +01:00
Paolo Bonzini b05aee5c94 mtest: print time that the test has been running
Signed-off-by: Paolo Bonzini <pbonzini@redhat.com>
2021-01-07 19:20:40 +01:00
Paolo Bonzini 4371756182 mtest: align decimal point of test durations 2021-01-07 19:20:40 +01:00
Paolo Bonzini 72e96a470a mtest: create runners in advance
Compute all options in advance so that we can compute the maximum
timeout.
2021-01-07 19:20:40 +01:00
Paolo Bonzini d470a915da mtest: move timeout message to ConsoleLogger
This adds a point where to call the progress report flush() method.

Signed-off-by: Paolo Bonzini <pbonzini@redhat.com>
2021-01-07 19:20:40 +01:00
Paolo Bonzini d1ee242e0d mtest: store timeout in TestRun
This will be useful when printing the progress report.

Signed-off-by: Paolo Bonzini <pbonzini@redhat.com>
2021-01-07 19:20:40 +01:00
Paolo Bonzini 4b8364b1e2 mtest: add more formatting options to TestHarness.format
Allow leaving extra space in the left column, as well as customizing parts of
the printed line.

Signed-off-by: Paolo Bonzini <pbonzini@redhat.com>
2021-01-07 19:20:40 +01:00
Paolo Bonzini f97521a1ff mtest: align correctly tests with wide Unicode characters
This correctly formats tests with CJK names or, well, emoji.  It is not perfect
(for example it does not correctly format emoji that are variations of 1-wide
characters), but it is as good as most terminal emulators.

Signed-off-by: Paolo Bonzini <pbonzini@redhat.com>
2021-01-07 19:20:40 +01:00
Paolo Bonzini fa4fb3e350 mtest: make test output parsing asynchronous
Instead of slurping in the entire stream, build the TestResult along
the way.  This allows reporting the results of TAP and Rust subtests as
they come in, either as part of the progress report or (in the future)
as individual lines of the output.
2021-01-07 19:20:40 +01:00
Paolo Bonzini f1938349c7 mtest: move Rust parsing inside TestRun
Make the code look like the TAP parser.  This simplifies the introduction of
asynchronous parsing.
2021-01-07 19:20:40 +01:00
Paolo Bonzini 755412b526 mtest: read test stdout/stderr via asyncio pipes
Instead of creating temporary files, get the StreamReaders from
_run_subprocess's returned object. Through asyncio magic, their
contents will be read as it becomes ready and then returned when
the StreamReader.read future is awaited.

Because of this change, the stdout and stderr can be easily
preserved when TestSubprocess returns an additional_error.

Signed-off-by: Paolo Bonzini <pbonzini@redhat.com>
2021-01-07 19:20:40 +01:00
Paolo Bonzini 0ccc70ae1b mtest: do not wait inside _run_subprocess
We would like SingleTestRunner to run code before waiting on the process,
for example starting tasks to read stdout and stderr.

Return a new object that is able to complete _run_subprocess's task.
In the next patch, SingleTestRunner will also use the object to get hold
of the stdout and stderr StreamReaders.

Signed-off-by: Paolo Bonzini <pbonzini@redhat.com>
2021-01-07 19:20:40 +01:00
Paolo Bonzini 63e26ba05f mtest: handle should_fail in common code
This is common to all protocols, place the code in a single
place.
2021-01-07 19:20:40 +01:00
Paolo Bonzini d2da7565fd mtest: reorder arguments to "complete"
Put them in the same order as complete_*.
2021-01-07 19:20:40 +01:00
Paolo Bonzini c48713e58c mtest: improve JUnit XML generation for TAP testsuites
Include the names from the TAP output and the SKIP/TODO explanations
if present.  Omit the classname attribute, it is optional.

In order to enable this, TestRun.results becomes a list of TAPParser.Test
objects.  If in the future there are other kinds of subtest results a
new class can be introduced, but for now it is enough.

Signed-off-by: Paolo Bonzini <pbonzini@redhat.com>
2021-01-07 19:20:38 +01:00
Paolo Bonzini 35d3baaa2f mtest: improvements to JUnit XML generation
Omit the classname attribute, as it is optional, and add the duration.

Signed-off-by: Paolo Bonzini <pbonzini@redhat.com>
2021-01-07 19:20:12 +01:00
Paolo Bonzini 723c4c9fef mtest: extract TAP parsing out of TestRun.make_tap
For now this is just a refactoring that simplifies the next patch.  However,
it will also come in handy when we will make the parsing asynchronous, because
it will make it possible to access subtest results while the test runs.

Signed-off-by: Paolo Bonzini <pbonzini@redhat.com>
2021-01-07 19:20:12 +01:00
Paolo Bonzini e50861e62f mtest/TAPParser: use typing.NamedTuple
It is cleaner than collections.namedtuple.  It also catches that "count()" is
a method on tuple, so rename the field to num_tests.

Signed-off-by: Paolo Bonzini <pbonzini@redhat.com>
2021-01-07 19:20:11 +01:00
Paolo Bonzini 304abaf9ee mtest: remove argument to the TAPParser constructor
Pass the StringIO object to the parse method instead, because
there will be no T.Iterator[str] to use in the asynchronous
case.

Signed-off-by: Paolo Bonzini <pbonzini@redhat.com>
2021-01-06 08:44:22 +01:00
Paolo Bonzini ee5e7977e3 mtest: allow parsing TAP line by line
This is the first step towards asynchronous parsing of the TAP output.
We will need to call the same code from both a "for" loop (for unit
tests) and an "async for" loop (for mtest itself).  Because the same
function cannot be both a generator and an asynchronous generator, we
need to build both on a common core.  This commit therefore introduces
a parse_line function that "parse" can call in a loop.  All the local
variables of TAPParser.parse move into "self".

Signed-off-by: Paolo Bonzini <pbonzini@redhat.com>
2021-01-06 08:43:26 +01:00
Dylan Baker d89ec98b47 mtest: Add support for rust unit tests
Rust has it's own built in unit test format, which is invoked by
compiling a rust executable with the `--test` flag to rustc. The tests
are then run by simply invoking that binary. They output a custom test
format, which this patch adds parsing support for. This means that we
can report each subtest in the junit we generate correctly, which should
be helpful for orchestration systems like gitlab and jenkins which can
parse junit XML.
2021-01-05 10:23:41 -08:00
Dylan Baker 07ff9c61fe mtest: Handle subtest results as a dict
for non tap tests we want to associate names with the tests, to that end
store them as a dict. For TAP tests, we'll store the "name" as an
integer string that coresponds to the order that the tests were run in.
2021-01-05 10:17:27 -08:00
Paolo Bonzini 5d97bf615f mtest: flush progress report before warning 2020-12-27 13:55:53 +01:00
Paolo Bonzini 80ba696066 mtest: flush stdout after printing test results
Flush after each output line, even if printing to a file, so that each
result is immediately visible down a pipeline.

Signed-off-by: Paolo Bonzini <pbonzini@redhat.com>
2020-12-27 13:55:53 +01:00