Closed Bug 1394910 Opened 7 years ago Closed 7 years ago

test-verify sometimes doesn't notice failure / summary is incorrect

Categories

(Testing :: General, defect)

defect
Not set
normal

Tracking

(firefox57 fixed)

RESOLVED FIXED
mozilla57
Tracking Status
firefox57 --- fixed

People

(Reporter: gbrown, Assigned: gbrown)

References

(Blocks 1 open bug)

Details

Attachments

(1 file)

https://public-artifacts.taskcluster.net/aE6Oq3_wQf-fcr0rEZbOFg/0/public/logs/live_backing.log

[task 2017-08-28T16:40:59.821273Z] 16:40:59     INFO - :::
[task 2017-08-28T16:40:59.822246Z] 16:40:59     INFO - ::: Test verification summary for:
[task 2017-08-28T16:40:59.823151Z] 16:40:59     INFO - :::
[task 2017-08-28T16:40:59.824088Z] 16:40:59     INFO - ::: browser/base/content/test/performance/browser_startup.js
[task 2017-08-28T16:40:59.825020Z] 16:40:59     INFO - :::
[task 2017-08-28T16:40:59.825958Z] 16:40:59     INFO - ::: 1. Run each test 20 times in one browser. : Pass
[task 2017-08-28T16:40:59.826923Z] 16:40:59     INFO - ::: 2. Run each test 10 times in a new browser each time. : Pass
[task 2017-08-28T16:40:59.827877Z] 16:40:59     INFO - :::
[task 2017-08-28T16:40:59.828825Z] 16:40:59     INFO - ::: Test verification PASSED
[task 2017-08-28T16:40:59.829702Z] 16:40:59     INFO - :::

...but there are clearly failures. 

(The job is orange, which is great, and expected because of log parsing.)

In addition to the incorrect summary, the harness should have given up much sooner.
https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&revision=697d93c85b773258b762224cd30d9bcb2cb6d8fd&filter-searchStr=test-verify&filter-tier=1&filter-tier=2&filter-tier=3

https://public-artifacts.taskcluster.net/FlaM51HmQBmwEBButEl7kg/0/public/logs/live_backing.log

task 2017-09-10T19:14:01.258855Z] 19:14:01     INFO -  0 INFO TEST-START | Shutdown
[task 2017-09-10T19:14:01.259818Z] 19:14:01     INFO -  1 INFO Passed:  2121
[task 2017-09-10T19:14:01.260764Z] 19:14:01     INFO -  2 INFO Failed:  630
[task 2017-09-10T19:14:01.261679Z] 19:14:01     INFO -  3 INFO Todo:    0
[task 2017-09-10T19:14:01.262504Z] 19:14:01     INFO -  4 INFO Mode:    e10s
[task 2017-09-10T19:14:01.263164Z] 19:14:01     INFO -  5 INFO SimpleTest FINISHED
[task 2017-09-10T19:14:01.263241Z] 19:14:01     INFO - Buffered messages finished
[task 2017-09-10T19:14:01.263889Z] 19:14:01     INFO - SUITE-END | took 12s
[task 2017-09-10T19:14:01.264615Z] 19:14:01     INFO - :::
[task 2017-09-10T19:14:01.265310Z] 19:14:01     INFO - ::: Running test verification step "2. Run each test 10 times in a new browser each time."...
[task 2017-09-10T19:14:01.265382Z] 19:14:01     INFO - :::

...

[task 2017-09-10T19:15:10.457040Z] 19:15:10     INFO -  0 INFO TEST-START | Shutdown
[task 2017-09-10T19:15:10.458377Z] 19:15:10     INFO -  1 INFO Passed:  2231
[task 2017-09-10T19:15:10.459686Z] 19:15:10     INFO -  2 INFO Failed:  630
[task 2017-09-10T19:15:10.460972Z] 19:15:10     INFO -  3 INFO Todo:    0
[task 2017-09-10T19:15:10.462218Z] 19:15:10     INFO -  4 INFO Mode:    e10s
[task 2017-09-10T19:15:10.463528Z] 19:15:10     INFO -  5 INFO SimpleTest FINISHED
[task 2017-09-10T19:15:10.464519Z] 19:15:10     INFO - Buffered messages finished
[task 2017-09-10T19:15:10.465435Z] 19:15:10     INFO - SUITE-END | took 6s
[task 2017-09-10T19:15:10.466795Z] 19:15:10     INFO - SUITE-START | Running 1 tests
[task 2017-09-10T19:15:10.467721Z] 19:15:10     INFO - :::
[task 2017-09-10T19:15:10.469009Z] 19:15:10     INFO - ::: Test verification summary for:
[task 2017-09-10T19:15:10.469925Z] 19:15:10     INFO - :::
[task 2017-09-10T19:15:10.470831Z] 19:15:10     INFO - ::: dom/base/test/test_data_uri.html
[task 2017-09-10T19:15:10.471750Z] 19:15:10     INFO - :::
[task 2017-09-10T19:15:10.472662Z] 19:15:10     INFO - ::: 1. Run each test 20 times in one browser. : Pass
[task 2017-09-10T19:15:10.473986Z] 19:15:10     INFO - ::: 2. Run each test 10 times in a new browser each time. : Pass
[task 2017-09-10T19:15:10.474832Z] 19:15:10     INFO - :::
[task 2017-09-10T19:15:10.475671Z] 19:15:10     INFO - ::: Test verification PASSED
[task 2017-09-10T19:15:10.476581Z] 19:15:10     INFO - :::
See Also: → 1398953
The mochitest harness's runTests() function currently returns a non-zero status when there is a harness failure (like the browser cannot be launched, or the harness throws an exception) but it does not indicate whether tests passed or failed.

Returning a non-zero status from runTests() for test failures allows test verification to stop running on failure and also report a more accurate pass/fail verification status.

Most existing failures seem to be indicated with -1. I chose to return -2 for the test-failure case, in case a caller ever wants to make a distinction.

I don't think this change affects any existing caller or use case. Automation appears to not be adversely affected:

https://treeherder.mozilla.org/#/jobs?repo=try&revision=769d066a97f957412350f3bb7b0b744dd1af7b94&filter-tier=1&filter-tier=2&filter-tier=3
Attachment #8907306 - Flags: review?(jmaher)
Attachment #8907306 - Flags: review?(jmaher) → review+
Pushed by gbrown@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/20ed0d0bd4b8
Return failed status from mochitest harness when one or more tests fail; r=jmaher
Blocks: test-verify
https://hg.mozilla.org/mozilla-central/rev/20ed0d0bd4b8
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla57
Depends on: 1399769
You need to log in before you can comment on or make changes to this bug.