826308 - Robocop tests log output should contain begin/end block markers for the full test run.

Status: RESOLVED FIXED

(Testing :: Mochitest, defect)

Description

[Bob Clary [:bc] (inactive)]

The robocop tests are run via runtestsremote.py and involve running a series of tests using the mochitest runner. Each test is run via runtests.py:Mochitest.runTests and is marked in the log via the beginning and ending lines:

INFO | runtests.py | Running tests: start.
<test results>
INFO | runtests.py | Running tests: end.

After all robocop tests are completed, runtestsremote.py calls runtestsremote.py:Mochitest.printLog to dump counts for a summary of the full set of tests in the form:

0 INFO SimpleTest START
99 INFO TEST-START | Shutdown
99 INFO Passed: %s
99 INFO Failed: %s
99 INFO Todo: %s
99 INFO SimpleTest FINISHED

This looks very similar to the normal mochitest log output but does not follow the 'standard' that each mochitest run is bracketed by the "Running tests: start." and "Running tests: end." lines. It would be beneficial for the 'new' block structured log parser if we could emit overall begin/end markers for the full robocop test run, such as:

INFO | runtests.py | Robocop tests: start.

INFO | runtests.py | Running tests: start.
<test results>
INFO | runtests.py | Running tests: end.
...
INFO | runtests.py | Running tests: start.
<test results>
INFO | runtests.py | Running tests: end.

0 INFO SimpleTest START
99 INFO TEST-START | Shutdown
99 INFO Passed: %s
99 INFO Failed: %s
99 INFO Todo: %s
99 INFO SimpleTest FINISHED

INFO | runtests.py | Robocop tests: end.

This would allow us to add state to the new logparser which would allow the overall summary to be expected and properly parsed, and for the end of the full Robocop test run to be detected.

This change could be made in runtestsremote.py:main by adding the appropriate logfile.appends around the |for test in robocop_tests:| loop.

Comment 1

[Bob Clary [:bc] (inactive)]

The more I think about it, I think that comment 0's approach is wrong. It is putting a robocop begin/end block around markers (Running tests: start. and Running tests: end.) that are also used in any of the 'runtests.py' family of test runners. It is like wrapping a box with the interior of the box. I think a better approach would be to do something like:

INFO | runtests.py | Running tests: start.
<test results>
INFO | runtests.py | Running tests: end.
...
INFO | runtests.py | Running tests: start.
<test results>
INFO | runtests.py | Running tests: end.

INFO | runtests.py | Robocop summary: start.

0 INFO SimpleTest START
99 INFO TEST-START | Shutdown
99 INFO Passed: %s
99 INFO Failed: %s
99 INFO Todo: %s
99 INFO SimpleTest FINISHED

INFO | runtests.py | Robocop summary: end.

Once we see 'INFO | runtests.py | Running tests: end.', we know that either:
* the test log can terminate cleanly
* a new test run might be started
* a robocop summary might begin (for robocop tests).

Comment 2

[Joel Maher ( :jmaher ) (UTC -8)]

Attachment: and a simple fix for this (1.0)

while I don't like hacking this into robocop, it is the only harness we have that runs >1 instance of the browser in a loop and then summarizes the output.  xpcshell would be the next harness I would consider for something like this.

Comment 3

[Phil Ringnalda (:philor)]

https://hg.mozilla.org/mozilla-central/rev/ed8df7cc59ab