[task 2018-07-04T17:41:18.997Z] INFO - Buffered messages finished [task 2018-07-04T17:41:18.997Z] INFO - 0 INFO TEST-START | Shutdown [task 2018-07-04T17:41:18.998Z] INFO - 1 INFO Passed: 0 [task 2018-07-04T17:41:18.998Z] INFO - 2 INFO Failed: 0 [task 2018-07-04T17:41:18.998Z] INFO - 3 INFO Todo: 1 [task 2018-07-04T17:41:18.999Z] INFO - 4 INFO Mode: e10s [task 2018-07-04T17:41:18.999Z] INFO - 5 INFO SimpleTest FINISHED [task 2018-07-04T17:41:18.999Z] INFO - Buffered messages finished [task 2018-07-04T17:41:19.000Z] INFO - SUITE-END | took 40s [task 2018-07-04T17:41:19.881Z] ERROR - Return code: 1 [task 2018-07-04T17:41:19.915Z] cesTestUtils.jsm, removing record [task 2018-07-04T17:41:19.915Z] Error: No objdir path for resource://testing-common/TestUtils.jsm. [task 2018-07-04T17:41:19.915Z] Couldn't find source info for resource://testing-common/TestUtils.jsm, removing record [task 2018-07-04T17:41:19.915Z] Error: No objdir path for resource://testing-common/PromiseTestUtils.jsm. [task 2018-07-04T17:41:19.916Z] Couldn't find source info for resource://testing-common/PromiseTestUtils.jsm, removing record [task 2018-07-04T17:41:19.916Z] Error: No objdir path for resource://specialpowers/MozillaLogger.js. [task 2018-07-04T17:41:19.916Z] Couldn't find source info for resource://specialpowers/MozillaLogger.js, removing record [task 2018-07-04T17:41:19.916Z] Error: No objdir path for resource://specialpowers/specialpowersAPI.js. [task 2018-07-04T17:41:19.916Z] Couldn't find source info for resource://specialpowers/specialpowersAPI.js, removing record [task 2018-07-04T17:41:19.916Z] Error: No objdir path for resource://specialpowers/specialpowers.js. [task 2018-07-04T17:41:19.916Z] Couldn't find source info for resource://specialpowers/specialpowers.js, removing record [task 2018-07-04T17:41:19.916Z] Error: No objdir path for resource://specialpowers/MockFilePicker.jsm. [task 2018-07-04T17:41:19.916Z] Couldn't find source info for resource://specialpowers/MockFilePicker.jsm, removing record [task 2018-07-04T17:41:19.916Z] Error: No objdir path for resource://specialpowers/MockColorPicker.jsm. [task 2018-07-04T17:41:19.916Z] Couldn't find source info for resource://specialpowers/MockColorPicker.jsm, removing record [task 2018-07-04T17:41:19.916Z] Error: No objdir path for resource://specialpowers/MockPermissionPrompt.jsm. [task 2018-07-04T17:41:19.916Z] Couldn't find source info for resource://specialpowers/MockPermissionPrompt.jsm, removing record [task 2018-07-04T17:41:19.916Z] Error: No objdir path for self-hosted. [task 2018-07-04T17:41:19.916Z] Couldn't find source info for self-hosted, removing record [task 2018-07-04T17:41:19.916Z] Error: Couldn't find entry in manifest for dist/xpi-stage/special-powers/api.js. [task 2018-07-04T17:41:19.916Z] Couldn't find source info for jar:file:///tmp/tmpkL7vk_.mozrunner/extensions/special-powers@mozilla.org.xpi!/api.js, removing record [task 2018-07-04T17:41:19.916Z] Error: No objdir path for resource://specialpowers/SpecialPowersObserverAPI.js. [task 2018-07-04T17:41:19.916Z] Couldn't find source info for resource://specialpowers/SpecialPowersObserver.jsm -> resource://specialpowers/SpecialPowersObserverAPI.js, removing record [task 2018-07-04T17:41:19.916Z] Error: No objdir path for resource://specialpowers/SpecialPowersObserver.jsm. [task 2018-07-04T17:41:19.916Z] Couldn't find source info for resource://specialpowers/SpecialPowersObserver.jsm, removing record [task 2018-07-04T17:41:19.916Z] Error: Couldn't find entry in manifest for dist/xpi-stage/mochikit/bootstrap.js. [task 2018-07-04T17:41:19.916Z] Couldn't find source info for resource://gre/modules/addons/XPIProvider.jsm -> jar:file:///tmp/tmpkL7vk_.mozrunner/extensions/mochikit@mozilla.org.xpi!/bootstrap.js, removing record [task 2018-07-04T17:41:19.916Z] Error: No objdir path for chrome://mochitests/content/browser/testing/mochitest/baselinecoverage/browser_chrome/browser_baselinecoverage.js. [task 2018-07-04T17:41:19.916Z] Couldn't find source info for chrome://mochitests/content/browser/testing/mochitest/baselinecoverage/browser_chrome/browser_baselinecoverage.js, removing record [task 2018-07-04T17:41:19.916Z] Error: No objdir path for tests/mochitest/runtests.py. [task 2018-07-04T17:41:19.916Z] Couldn't find source info for tests/mochitest/runtests.py, removing record [task 2018-07-04T17:41:19.916Z] Error: No objdir path for moz-extension://ed5bf4eb-fca9-4a1b-8160-24517bf12d2e/background.js. [task 2018-07-04T17:41:19.916Z] Couldn't find source info for moz-extension://ed5bf4eb-fca9-4a1b-8160-24517bf12d2e/background.js, removing record [task 2018-07-04T17:41:19.916Z] Error: No objdir path for resource://testing-common/ExtensionTestCommon.jsm. [task 2018-07-04T17:41:19.916Z] Couldn't find source info for resource://testing-common/ExtensionTestCommon.jsm, removing record [task 2018-07-04T17:41:19.917Z] Error: No objdir path for resource://testing-common/ContentTask.jsm. [task 2018-07-04T17:41:19.917Z] Couldn't find source info for resource://testing-common/ContentTask.jsm, removing record [task 2018-07-04T17:41:19.917Z] Error: No objdir path for resource://testing-common/BrowserTestUtils.jsm. [task 2018-07-04T17:41:19.917Z] Couldn't find source info for resource://testing-common/BrowserTestUtils.jsm, removing record [task 2018-07-04T17:41:19.917Z] Error: No objdir path for resource://testing-common/PromiseTestUtils.jsm. [task 2018-07-04T17:41:19.917Z] Couldn't find source info for resource://testing-common/PromiseTestUtils.jsm, removing record [task 2018-07-04T17:41:19.917Z] Error: No objdir path for resource://testing-common/Assert.jsm. [task 2018-07-04T17:41:19.917Z] Couldn't find source info for resource://testing-common/Assert.jsm, removing record [task 2018-07-04T17:41:19.917Z] Error: No objdir path for resource://testing-common/TestUtils.jsm. [task 2018-07-04T17:41:19.917Z] Couldn't find source info for resource://testing-common/TestUtils.jsm, removing record [task 2018-07-04T17:41:19.917Z] Error: No objdir path for resource://specialpowers/MozillaLogger.js. [task 2018-07-04T17:41:19.918Z] Couldn't find source info for resource://specialpowers/MozillaLogger.js, removing record [task 2018-07-04T17:41:20.152Z] Error: INFO - Getting output from command: ['/tmp/tmpVGJ0bj/grcov', '-t', 'coveralls', '-p', '/builds/worker/workspace/build/src/', '--ignore-dir', 'gcc*', '--ignore-dir', 'vs2017_*', '/tmp/tmpVGJ0bj/target.code-coverage-gcno.zip', '/tmp/tmpYcAfDL', '--token', 'UNUSED', '--commit-sha', 'UNUSED', 'jsvm_lcov_output.info', '--filter', 'covered'] [task 2018-07-04T17:41:20.152Z] INFO - Copy/paste: /tmp/tmpVGJ0bj/grcov -t coveralls -p /builds/worker/workspace/build/src/ --ignore-dir gcc* --ignore-dir vs2017_* /tmp/tmpVGJ0bj/target.code-coverage-gcno.zip /tmp/tmpYcAfDL --token UNUSED --commit-sha UNUSED jsvm_lcov_output.info --filter covered [task 2018-07-04T17:41:36.924Z] INFO - TinderboxPrint: mochitest-plain<br/>2/0/1 [task 2018-07-04T17:41:36.924Z] ERROR - # TBPL FAILURE # [task 2018-07-04T17:41:36.925Z] WARNING - setting return code to 2 [task 2018-07-04T17:41:36.925Z] ERROR - TinderboxPrint: Per-test run of .../tests/test_bug1425997.html<br/>: FAILURE [task 2018-07-04T17:41:36.925Z] INFO - Running command: ['/builds/worker/workspace/build/venv/bin/python', '-u', '/builds/worker/workspace/build/tests/mochitest/runtests.py', '--appname=/builds/worker/workspace/build/application/firefox/firefox', '--utility-path=tests/bin', '--extra-profile-file=tests/bin/plugins', '--symbols-path=/builds/worker/workspace/build/symbols', '--certificate-path=tests/certs', '--setpref=webgl.force-enabled=true', '--quiet', '--log-raw=/builds/worker/workspace/build/blobber_upload_dir/plain_raw.log', '--log-errorsummary=/builds/worker/workspace/build/blobber_upload_dir/plain_errorsummary.log', '--use-test-media-devices', '--screenshot-on-fail', '--cleanup-crashes', '--marionette-startup-timeout=180', '--sandbox-read-whitelist=/builds/worker/workspace/build', '--log-raw=-', 'testing/mochitest/baselinecoverage/plain/test_baselinecoverage.html'] in /builds/worker/workspace/build [task 2018-07-04T17:41:36.926Z] INFO - Copy/paste: /builds/worker/workspace/build/venv/bin/python -u /builds/worker/workspace/build/tests/mochitest/runtests.py --appname=/builds/worker/workspace/build/application/firefox/firefox --utility-path=tests/bin --extra-profile-file=tests/bin/plugins --symbols-path=/builds/worker/workspace/build/symbols --certificate-path=tests/certs --setpref=webgl.force-enabled=true --quiet --log-raw=/builds/worker/workspace/build/blobber_upload_dir/plain_raw.log --log-errorsummary=/builds/worker/workspace/build/blobber_upload_dir/plain_errorsummary.log --use-test-media-devices --screenshot-on-fail --cleanup-crashes --marionette-startup-timeout=180 --sandbox-read-whitelist=/builds/worker/workspace/build --log-raw=- testing/mochitest/baselinecoverage/plain/test_baselinecoverage.html [task 2018-07-04T17:41:36.926Z] INFO - Using env: (same as previous command) [task 2018-07-04T17:41:36.926Z] INFO - Calling ['/builds/worker/workspace/build/venv/bin/python', '-u', '/builds/worker/workspace/build/tests/mochitest/runtests.py', '--appname=/builds/worker/workspace/build/application/firefox/firefox', '--utility-path=tests/bin', '--extra-profile-file=tests/bin/plugins', '--symbols-path=/builds/worker/workspace/build/symbols', '--certificate-path=tests/certs', '--setpref=webgl.force-enabled=true', '--quiet', '--log-raw=/builds/worker/workspace/build/blobber_upload_dir/plain_raw.log', '--log-errorsummary=/builds/worker/workspace/build/blobber_upload_dir/plain_errorsummary.log', '--use-test-media-devices', '--screenshot-on-fail', '--cleanup-crashes', '--marionette-startup-timeout=180', '--sandbox-read-whitelist=/builds/worker/workspace/build', '--log-raw=-', 'testing/mochitest/baselinecoverage/plain/test_baselinecoverage.html'] with output_timeout 1000 [task 2018-07-04T17:41:37.177Z] INFO - Checking for ssltunnel processes... [task 2018-07-04T17:41:37.185Z] INFO - Checking for xpcshell processes... [task 2018-07-04T17:41:37.193Z] INFO - mozcrash Removed pending crash reports at '/builds/worker/.mozilla/firefox/Crash Reports' [task 2018-07-04T17:41:37.613Z] INFO - SUITE-START | Running 1 tests [task 2018-07-04T17:41:37.613Z] INFO - Running manifest: testing/mochitest/baselinecoverage/plain/mochitest.ini [task 2018-07-04T17:41:37.641Z] INFO - Setting pipeline to PAUSED ... [task 2018-07-04T17:41:37.641Z] INFO - Pipeline is PREROLLING ... [task 2018-07-04T17:41:37.641Z] INFO - Pipeline is PREROLLED ... [task 2018-07-04T17:41:37.642Z] INFO - Setting pipeline to PLAYING ... [task 2018-07-04T17:41:37.642Z] INFO - New clock: GstSystemClock [task 2018-07-04T17:41:37.678Z] INFO - Got EOS from element "pipeline0". [task 2018-07-04T17:41:37.678Z] INFO - Execution ended after 0:00:00.033547190 [task 2018-07-04T17:41:37.678Z] INFO - Setting pipeline to PAUSED ... [task 2018-07-04T17:41:37.679Z] INFO - Setting pipeline to READY ... [task 2018-07-04T17:41:37.679Z] INFO - (gst-launch-1.0:4461): GStreamer-CRITICAL **: gst_object_unref: assertion '((GObject *) object)->ref_count > 0' failed [task 2018-07-04T17:41:37.680Z] INFO - Setting pipeline to NULL ... [task 2018-07-04T17:41:37.680Z] INFO - Freeing pipeline ... [task 2018-07-04T17:41:37.990Z] INFO - pk12util: PKCS12 IMPORT SUCCESSFUL [task 2018-07-04T17:41:38.087Z] INFO - MochitestServer : launching [u'/builds/worker/workspace/build/tests/bin/xpcshell', '-g', '/builds/worker/workspace/build/application/firefox', '-f', '/builds/worker/workspace/build/tests/bin/components/httpd.js', '-e', "const _PROFILE_PATH = '/tmp/tmpCUWHuR.mozrunner'; const _SERVER_PORT = '8888'; const _SERVER_ADDR = '127.0.0.1'; const _TEST_PREFIX = undefined; const _DISPLAY_RESULTS = false;", '-f', '/builds/worker/workspace/build/tests/mochitest/server.js'] [task 2018-07-04T17:41:38.088Z] INFO - runtests.py | Server pid: 4484 [task 2018-07-04T17:41:38.089Z] INFO - runtests.py | Websocket server pid: 4487 [task 2018-07-04T17:41:38.097Z] INFO - runtests.py | SSL tunnel pid: 4490 [task 2018-07-04T17:41:38.307Z] INFO - [CodeCoverage] Setting handlers for process 4484. [task 2018-07-04T17:41:38.448Z] INFO - runtests.py | Running with e10s: True [task 2018-07-04T17:41:38.449Z] INFO - runtests.py | Running tests: start.

Log: https://treeherder.mozilla.org/logviewer.html#?job_id=186472539&repo=mozilla-central This is a permafail: https://treeherder.mozilla.org/#/jobs?repo=mozilla-central&revision=a07cf0515fe3ab55353749a088429484d8cb8bb9&filter-resultStatus=testfailed&filter-resultStatus=busted&filter-resultStatus=exception&filter-resultStatus=success&filter-classifiedState=unclassified&filter-searchStr=coverage

Those error messages can be ignored, the failure should be somewhere else.

The log says "Per-test run of .../tests/test_bug1425997.html<br/>: FAILURE" [task 2018-07-04T17:40:53.364Z] INFO - TEST-START | editor/libeditor/tests/test_bug1425997.html ... [task 2018-07-04T17:41:18.837Z] INFO - TEST-OK | editor/libeditor/tests/test_bug1425997.html | took 1823ms ... [task 2018-07-04T17:41:18.838Z] INFO - TEST-KNOWN-FAIL | editor/libeditor/tests/test_bug1425997.html | assertion count 3 matches expected 3 assertions [task 2018-07-04T17:41:18.838Z] INFO - TEST-START | Shutdown [task 2018-07-04T17:41:18.840Z] INFO - Passed: 0 [task 2018-07-04T17:41:18.840Z] INFO - Failed: 0 [task 2018-07-04T17:41:18.841Z] INFO - Todo: 1 [task 2018-07-04T17:41:18.841Z] INFO - Mode: e10s [task 2018-07-04T17:41:18.842Z] INFO - Slowest: 1822ms - /tests/editor/libeditor/tests/test_bug1425997.html [task 2018-07-04T17:41:18.842Z] INFO - SimpleTest FINISHED [task 2018-07-04T17:41:18.843Z] INFO - TEST-INFO | Ran 1 Loops [task 2018-07-04T17:41:18.843Z] INFO - SimpleTest FINISHED ... [task 2018-07-04T17:41:18.981Z] INFO - TEST-PASS | leakcheck | tab process: no leaks detected! [task 2018-07-04T17:41:18.981Z] INFO - runtests.py | Running tests: end. [task 2018-07-04T17:41:18.997Z] INFO - Buffered messages finished [task 2018-07-04T17:41:18.997Z] INFO - 0 INFO TEST-START | Shutdown [task 2018-07-04T17:41:18.998Z] INFO - 1 INFO Passed: 0 [task 2018-07-04T17:41:18.998Z] INFO - 2 INFO Failed: 0 [task 2018-07-04T17:41:18.998Z] INFO - 3 INFO Todo: 1 [task 2018-07-04T17:41:18.999Z] INFO - 4 INFO Mode: e10s [task 2018-07-04T17:41:18.999Z] INFO - 5 INFO SimpleTest FINISHED [task 2018-07-04T17:41:18.999Z] INFO - Buffered messages finished [task 2018-07-04T17:41:19.000Z] INFO - SUITE-END | took 40s [task 2018-07-04T17:41:19.881Z] ERROR - Return code: 1 ... [task 2018-07-04T17:41:36.924Z] INFO - TinderboxPrint: mochitest-plain<br/>2/0/1 [task 2018-07-04T17:41:36.924Z] ERROR - # TBPL FAILURE # [task 2018-07-04T17:41:36.925Z] WARNING - setting return code to 2 [task 2018-07-04T17:41:36.925Z] ERROR - TinderboxPrint: Per-test run of .../tests/test_bug1425997.html<br/>: FAILURE Maybe test-coverage mode doesn't handle well todo tests?

in this case we fail on |ERROR - Return code: 1|, so I am not sure why we return a 1 in this case, I will look into this a bit more to see if a TODO results in a return code 1. I looked at the history here and I see this failure has stopped. I also see that some of the logs linked to this bug are related to assertions, possibly those are getting caught in a log parser even though they are marked as todo.

so we need to have test-verify account for a test that runs but only has todo (I get the same results on my local win10 opt build/run). A shortcut is to skip the test in test-verify mode...what is the point of having the test if we don't run anything? Regardless, this is a case we should support in test-verify. this is where we are getting a failure: https://searchfox.org/mozilla-central/source/testing/mochitest/runtests.py#2640 if not result and not self.countpass: # either tests failed or no tests run result = 1 possibly we can add an extra clause here for self.todo or if we are in verify mode.

This is pretty important for test-coverage, in a full try run made by jmaher we saw this problem very often.

116 jobs failed, randomly clicking around on a dozen, they all seem to be related to the todo case: https://treeherder.mozilla.org/#/jobs?repo=try&revision=7066499faef1bfbf46411f14ad60523cbfe26265&selectedJob=192015745

Here's a working patch to fix this bug: https://treeherder.mozilla.org/#/jobs?repo=try&revision=d00645a8c64742a5fc2a72fa25ec93c19b813911 I could only get around it by adding an option to state that we are in per-test-coverage mode since nothing else can tell us this. This means we would have to add this argument to all suites, like for `--jscov-dir-prefix` or `--verify`. We need to add an extra option to solve the following bug as well since there is nothing available in wpt that can tell us when we are in per-test-coverage mode: https://bugzilla.mozilla.org/show_bug.cgi?id=1469118

This problem is not in all suites (xpcshell, for instance, just checks for the failure count) so I've made a patch for only mochitest: https://hg.mozilla.org/try/rev/a85df788998be72005fdaebc123e400ce4a861af I'll do the same thing for wpt in bug 1469118.

Comment on attachment 8999041 [details] [diff] [review] bug1473392.patch Review of attachment 8999041 [details] [diff] [review]: ----------------------------------------------------------------- I am not a fan of yet another command line argument and then checking multiple conditions inside the harnesses. Right now that is the most straightforward approach without refactoring and having all parsing fall into "per test mode" and then a few exceptions for verify || coverage.

I agree, it would be better that way. One thing I am wondering about is that if we bring all harnesses into a per-test mode by default then they should all have to deal with this case in the same way. Would you know why mochitest can't just check for a failure count? It's a bit confusing that TODO tests and what they mean are defined differently in one suite from another (one fails, the other doesn't). Could we instead change the way mochitest passes and fails by just checking for a failure count greater than 0?

I looked into that option in a little more depth - and it looks like this could be considered as an edge case when the mumber of chunks is increased to equal the number of tests. Eventually, this failure would have occurred in any mode and on any platform, and there doesn't seem to be any protections against this that I can see, neither is there a reason for failing in the way it is failed. Currently, the code assumes that a failure state exists when the result is 0 (tests all passed) but there are no explicitly passing tests (countpass == 0), it doesn't take into consideration the fact that some tests don't change pass counts, only the todo count. Furthermore, suppose that all the tests being run in a chunk are todo tests. Then, even though the chunk should pass, it would fail. To me, it makes sense to change the passing condition for all mochitests, regardless of platform or mode they are running in.

What you are proposing here sounds reasonable and we just haven't hit the case where only a todo results show up in our normal automation. Lets move forward with the change.

This patch changes the failure condition of all mochitest tests to only take the number of failures (given by self.countfail) into account. With this change, mochitest test chunks will only fail if the failure count is not 0. This fixes a case where the TODO tests were considered as failures when no passing tests were run along side them.

Comment on attachment 8999960 [details] Bug 1473392 - Change failure condition for all mochitest tests. r?jmaher Joel Maher ( :jmaher ) (UTC+2) has approved the revision.

Pushed by gmierz2@outlook.com: https://hg.mozilla.org/integration/autoland/rev/93877b72e677 Change failure condition for all mochitest tests. r=jmaher

Backed out changeset 93877b72e677 (Bug 1473392) for causing mch perma failures in testing/mochitest/tests/python/test_basic_mochitest_plain.py a=backout Push with failures: https://treeherder.mozilla.org/#/jobs?repo=autoland&revision=93877b72e6777bd8ea019a3693904cd2b3779f38&selectedJob=194451399 Failure log: https://treeherder.mozilla.org/#/jobs?repo=autoland&revision=93877b72e6777bd8ea019a3693904cd2b3779f38&selectedJob=194451399 Backout from central: https://treeherder.mozilla.org/#/jobs?repo=mozilla-central&revision=131363332762842ba327166bdc361c6fffc4858f&filter-resultStatus=testfailed&filter-resultStatus=busted&filter-resultStatus=exception

This is the reason why the failure condition didn't take self.countfail into account, because it was guarding from crash failures that resulted in no changes to the counts. I'll leave this condition, but I'll add a second one after this that will be `if not result and not (self.counttodo or self.countpass)`. This would mean that there were no recorded failures, and no recorded test passes or todos.

This patch changes the failure condition of all mochitest tests to take the number of failures (given by self.countfail). It also adds a condition to check if there are passing and todo counts, and if there are not, the test chunk fails. With this change, mochitest test chunks will fail if the failure count is not 0, or all the counts (pass, todo, and fail) are 0. This fixes a case where the TODO tests were considered as failures when no passing tests were run along side them.

Comment on attachment 9001966 [details] Bug 1473392 - Fix failure conditions for all mochitest tests. r?jmaher Joel Maher ( :jmaher ) (UTC+2) has approved the revision.

Pushed by gmierz2@outlook.com: https://hg.mozilla.org/integration/autoland/rev/25d58e97db2d Fix failure conditions for all mochitest tests. r=jmaher