Closed Bug 1098700 Opened 7 years ago Closed 7 years ago

Mochitests that are annotated fails-if don't output a useful error if they unexpectedly pass

Categories

(Testing :: Mochitest, defect)

defect
Not set
normal

Tracking

(Not tracked)

RESOLVED FIXED
mozilla37

People

(Reporter: RyanVM, Assigned: kaustabh93)

References

Details

Attachments

(1 file, 2 obsolete files)

Found this out by accident tonight when adding another condition to what I thought was a skip-if condition. Turns out it was a fails-if, which rightfully turned the run orange (since the test was now unexpectedly passing on that platform).

However, instead of outputting TEST-UNEXPECTED-PASS as would be expected in that situation, it instead showed TEST-OK and just turned the run orange instead. Thankfully it was my push that did it and I was able to track down pretty quickly what had happened. I could forsee this being a nightmare for a someone to track down otherwise.

Example log:
http://ftp.mozilla.org/pub/mozilla.org/b2g/tinderbox-builds/mozilla-inbound-linux64-mulet/1415914808/mozilla-inbound_ubuntu64_vm-mulet_test-mochitest-1-bm53-tests1-linux64-build132.txt.gz

test_hidden_alpha.html was the test in question.
I don't know how these tests are run, but looks like failureInfo around http://hg.mozilla.org/mozilla-central/file/7f0d92595432/testing/mochitest/tests/SimpleTest/SimpleTest.js#l847 should be:

{status:"PASS", expected:"FAIL", message:"TEST-UNEXPECTED-PASS"}
These would be green according to the structured log.
Blocks: 1071227
Attached patch unexpected_pass.patch (obsolete) — Splinter Review
Comment on attachment 8541124 [details] [diff] [review]
unexpected_pass.patch

Review of attachment 8541124 [details] [diff] [review]:
-----------------------------------------------------------------

let me push to try, if all goes well we can land this!  Thanks!
Attachment #8541124 - Flags: review+
try is green
Keywords: checkin-needed
https://hg.mozilla.org/mozilla-central/rev/9e126e97e347
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla37
oh fun, looking at this I realized that the jobs are green even though mochitest returns a code of 1 because we didn't update the unittests and now print TEST-UNEXPECTED-PASS.

So this is good- we have a logical error printed and a valid return code from the entire harness, but still we fail to turn the job orange.

Ryan, what are your thoughts on this?  Obviously we need to fix the unittests, but for the error message and turning the job orange.  For an example of the error look on win7 m-oth
Status: RESOLVED → REOPENED
Flags: needinfo?(ryanvm)
Resolution: FIXED → ---
I think we should backout for now. Can you please do the honors?
Flags: needinfo?(ryanvm)
Duplicate of this bug: 1116034
I am really confused by this bug, Kaustabh and I have been looking at it.  There exists some failure condition where we annotate fail-if and we don't print test-unexpected-* while returning non zero.  

Replicating this is not straightforward.  In fact, the unittests cover expected failures, and switching something to use or not use fail-if output the proper behaviour.

Maybe there is something we are overlooking, please chime in with some specifics about what we should be doing here, or otherwise lets close this bug out.
I'm not sure how to better clarify comment 0. The status quo at the moment is that the test unexpectedly passes, turns the run orange, and provides *zero* usable output to indicate what is wrong. That's not acceptable.

I'm not sure what the way forward is. Maybe Chris or someone have an idea.
Flags: needinfo?(cmanchester)
well comment 0 makes no sense to me.  if I set up a test to unexpectedly pass, it reports 'test-unexpected-pass' and returns a non zero, something like this:
INFO TEST-FAIL | /path/test.html | fail-if condition in manifest - We expected at least one failure

If that is what we currently have, should it be changed?  Is there a random corner case that doesn't yield this?
I can reproduce the issue by changing the assertion in test_sanity_manifest.html from "ok(false, "We expect this to fail");" to "ok(true, "This test unexpectedly passes")" and running |./mach mochitest-plain testing/mochitest/tests/Harness_sanity/ --quiet| (the "--quiet" keeps the relevant info out of logs running in our infrastructure). The output for this test in the run is:

35 INFO TEST-START | testing/mochitest/tests/Harness_sanity/test_sanity_manifest.html
-*-*- UserCustomizations (parent): document created: http://mochi.test:8888/tests/testing/mochitest/tests/Harness_sanity/test_sanity_manifest.html
-*-*- UserCustomizations (parent): _injectInWindow
-*-*- UserCustomizations (parent): principal status: 0
36 INFO TEST-OK | testing/mochitest/tests/Harness_sanity/test_sanity_manifest.html | took 21ms

I believe comment 1 is the right fix. With it the test outputs:

35 INFO TEST-START | testing/mochitest/tests/Harness_sanity/test_sanity_manifest.html
-*-*- UserCustomizations (parent): document created: http://mochi.test:8888/tests/testing/mochitest/tests/Harness_sanity/test_sanity_manifest.html
-*-*- UserCustomizations (parent): _injectInWindow
-*-*- UserCustomizations (parent): principal status: 0
36 INFO TEST-PASS | testing/mochitest/tests/Harness_sanity/test_sanity_manifest.html | This test unexpectedly passes 
37 INFO TEST-UNEXPECTED-PASS | testing/mochitest/tests/Harness_sanity/test_sanity_manifest.html | fail-if condition in manifest - We expected at least one failure
TEST-INFO | expected FAIL
38 INFO MEMORY STAT vsize after test: 842244096
39 INFO MEMORY STAT residentFast after test: 147369984
40 INFO MEMORY STAT heapAllocated after test: 58838120
41 INFO TEST-OK | testing/mochitest/tests/Harness_sanity/test_sanity_manifest.html | took 26ms
Flags: needinfo?(cmanchester)
https://treeherder.mozilla.org/ui/#/jobs?repo=mozilla-inbound&revision=9e126e97e347 (when this landed), b2g opt mochitest-3 and debug mochitest-6. Crapload of webgl things are annotated fail-if b2g, they apparently don't fail, so with this landed they at least came slightly closer to showing the real state, expected to fail but not failing anything. No idea whether there are others, someone would have to look at every single suite run by the mochitest harness, on every OS, opt and debug, and thus across several pushes since that didn't get 10.8 debug and had a bunch of Win jobs coalesced away.
Attached patch bug.patch (obsolete) — Splinter Review
Attachment #8541124 - Attachment is obsolete: true
Comment on attachment 8546070 [details] [diff] [review]
bug.patch

Review of attachment 8546070 [details] [diff] [review]:
-----------------------------------------------------------------

Overall this is exactly what we need.  We do need to look at browser-test.js as browser-chrome tests are reporting test-unexpected-fail when they should be reporting test-unexpected-pass.
Attachment #8546070 - Flags: review-
Attached patch fail_if.patchSplinter Review
Attachment #8546070 - Attachment is obsolete: true
Comment on attachment 8546835 [details] [diff] [review]
fail_if.patch

looks good to me!
Attachment #8546835 - Flags: review+
https://hg.mozilla.org/mozilla-central/rev/ef1bb856aeb2
Status: REOPENED → RESOLVED
Closed: 7 years ago7 years ago
Flags: in-testsuite+
Resolution: --- → FIXED
You need to log in before you can comment on or make changes to this bug.