https://treeherder.mozilla.org/logviewer.html#?job_id=23919611&repo=mozilla-inbound Here the full command which was run: ['/home/worker/workspace/build/venv/bin/python', '/home/worker/workspace/build/venv/lib/python2.7/site-packages/firefox_ui_harness/cli_functional.py', '--binary', '/home/worker/workspace/build/application/firefox/firefox', '--address', 'localhost:2828', '--server-root', '/home/worker/workspace/build/tests/firefox-ui/resources', '--workspace', '/home/worker/workspace/build', '--gecko-log=-', '--log-raw=-', '--log-html', '/home/worker/workspace/reports/report.html', '--log-xunit', '/home/worker/workspace/reports/report.xml', '--symbols-path', 'https://queue.taskcluster.net/v1/task/SZp-00aPTHmcha9pMky7FA/artifacts/public/build/target.crashreporter-symbols.zip', '/home/worker/workspace/build/tests/firefox-ui/tests/puppeteer/manifest.ini', '/home/worker/workspace/build/tests/firefox-ui/tests/functional/manifest.ini'] Log excerpt: 15:41:25 INFO - 1458142885225 Marionette TRACE conn175 <- [1,358,null,{}] 15:41:25 INFO - --DOMWINDOW == 98 (0x7fbc04e7cc00) [pid = 932] [serial = 396] [outer = (nil)] [url = about:blank] 15:41:25 INFO - --DOMWINDOW == 97 (0x7fbc04ef2000) [pid = 932] [serial = 398] [outer = (nil)] [url = about:blocked?e=unwantedBlocked&u=https%3A//www.itisatrap.org/firefox/unwanted.html&o=1&s=blacklist&c=UTF-8&f=regular&d=The%20site%20at%20www.itisatrap.org%20has%20been%20reported%20as%20serving%20unwanted%20software%20and%20has%20been%20blocked%20based%20on%20your%20security%20preferences.] 15:41:25 INFO - --DOMWINDOW == 96 (0x7fbc06d76400) [pid = 932] [serial = 399] [outer = (nil)] [url = https://www.itisatrap.org/firefox/unwanted.html] 15:41:25 INFO - [932] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0xC1F30001: file /home/worker/workspace/build/src/netwerk/cache2/CacheFileMetadata.cpp, line 308 15:41:26 INFO - 1458142886231 Marionette TRACE conn175 -> [0,359,"findElement",{"using":"id","value":"ignoreWarningButton"}] 15:41:26 INFO - 1458142886261 Marionette TRACE conn175 <- [1,359,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"cefc9712-8b2b-433b-b901-7c53b4795426","ELEMENT":"cefc9712-8b2b-433b-b901-7c53b4795426"}}] 15:41:26 INFO - 1458142886266 Marionette TRACE conn175 -> [0,360,"clickElement",{"id":"cefc9712-8b2b-433b-b901-7c53b4795426"}] 15:41:26 INFO - [932] WARNING: We should have hit the document element...: file /home/worker/workspace/build/src/layout/xul/BoxObject.cpp, line 175 15:41:26 INFO - 1458142886442 Marionette TRACE conn175 <- [1,360,null,{}] 15:41:26 INFO - ++DOMWINDOW == 97 (0x7fbc0694f000) [pid = 932] [serial = 421] [outer = 0x7fbc0e38b000] 15:46:26 INFO - Automation Error: mozprocess timed out after 300 seconds running ['/home/worker/workspace/build/venv/bin/python', '/home/worker/workspace/build/venv/lib/python2.7/site-packages/firefox_ui_harness/cli_functional.py', '--binary', '/home/worker/workspace/build/application/firefox/firefox', '--address', 'localhost:2828', '--server-root', '/home/worker/workspace/build/tests/firefox-ui/resources', '--workspace', '/home/worker/workspace/build', '--gecko-log=-', '--log-raw=-', '--log-html', '/home/worker/workspace/reports/report.html', '--log-xunit', '/home/worker/workspace/reports/report.xml', '--symbols-path', 'https://queue.taskcluster.net/v1/task/SZp-00aPTHmcha9pMky7FA/artifacts/public/build/target.crashreporter-symbols.zip', '/home/worker/workspace/build/tests/firefox-ui/tests/puppeteer/manifest.ini', '/home/worker/workspace/build/tests/firefox-ui/tests/functional/manifest.ini'] 15:46:26 ERROR - timed out after 300 seconds of no output 15:46:26 ERROR - Return code: -9 15:46:26 ERROR - No suite end message was emitted by this harness. 15:46:26 ERROR - # TBPL FAILURE # Looks like we hang inside the functional/security/test_safe_browsing_notification.py:test_notification_bar test.

Not sure why we actually get this failure at all given that this happens BEFORE we actually run into the socket timeout error with Marionette which is currently set to 360s. It looks like there is a strange situation when the harness is killing us: https://tools.taskcluster.net/task-inspector/#AS0spzqcTy2EqZlOvFWe4g/0 > 13:02:19 INFO - JavaScript error: chrome://marionette/content/listener.js, line 1038: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIWebProgress.removeProgressListener] > 13:07:19 INFO - Automation Error: mozprocess timed out after 300 seconds running ['/home/worker/workspace/build/venv/bin/python', '/home/worker/workspace/build/venv/lib/python2.7/site-packages/firefox_ui_harness/cli_functional.py', '--binary', '/home/worker/workspace/build/application/firefox/firefox', '--address', 'localhost:2828', '--server-root', '/home/worker/workspace/build/tests/firefox-ui/resources', '--workspace', '/home/worker/workspace/build', '--gecko-log=-', '--log-raw=-', '--log-html', '/home/worker/workspace/reports/report.html', '--log-xunit', '/home/worker/workspace/reports/report.xml', '--symbols-path', 'https://queue.taskcluster.net/v1/task/T-IhELmrShGIb0HPJ0HjIQ/artifacts/public/build/target.crashreporter-symbols.zip', '--tag', 'local', '/home/worker/workspace/build/tests/firefox-ui/tests/puppeteer/manifest.ini', '/home/worker/workspace/build/tests/firefox-ui/tests/functional/manifest.ini'] > 13:07:19 ERROR - timed out after 300 seconds of no output > 13:07:19 ERROR - Return code: -9

So given by Orange Factor this test failure is only happening on Linux so far with e10s enabled. Jobs for debug builds are rare but here can be found one: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-aurora&job_id=3171935 The interesting line is: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-aurora&job_id=3171935#L44387 > 13:03:03 INFO - 1470056583194 Marionette TRACE conn155 -> [0,743,"switchToWindow",{"name":"303"}] As you can see we send a request to switch the window but then we never got a reply back from Marionette server. The last time the failure happened was on Sep 7th and it failed somewhere in test_security.py TestSecurity.test_get_address_from_certificate. Interestingly this is also the first test in the suite. I didn't know that we randomize the tests that much. Maybe we should have a look at this.

Just found one more instance which has a Pipe error for the same test: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=35500125#L983

Hm, with bug 1301661 I completely reduced the socket timeout to 60s now. So actually we should never reach this 300 second timeout anymore. I will leave this bug open for a while to check if there are still reports.

I think we can close as WFM, and reopen if it should happen again. But so far it looks fine.

Spiking like crazy today it appears.

Ryan, this is a regression from something as landed by Wes in this push: https://treeherder.mozilla.org/#/jobs?repo=mozilla-central&revision=d712c82c59ec5a277047a75d09bec48be4a64b87&filter-searchStr=Firefox+&filter-tier=1&filter-tier=2&filter-tier=3 It most likely looks related to the location bar test failure in bug 1303346. I'm struggling to see where all this code is coming from. Was this a merge from some other branch? Maybe it makes it easier for us there to spot the actual commit which regressed this.

This was an autoland merge. And indeed, here's a narrower regression range: https://treeherder.mozilla.org/#/jobs?repo=autoland&filter-searchStr=Firefox%20&filter-tier=1&filter-tier=2&filter-tier=3&fromchange=30179c5551744b880f563b5382da8f256385fdc3&tochange=40eb2f2b645f3138b09deb69b90bf104da426f64

Retriggers on the range in comment 16 (thanks Ryan!) suggest this started with https://treeherder.mozilla.org/#/jobs?repo=autoland&revision=68fd11cad65584a41a799aa11c14981e02a00761&filter-searchStr=Firefox+&filter-tier=1&filter-tier=2&filter-tier=3 -- bug 1303781. :adw -- Can you have a look?

See also bug 1303346 which is a different test failure but maybe the same underlying issue. As Marco mentioned the search suggestions have been enabled by default now.

This will be fixed with my patch on bug 1368101 which already landed on autoland and made the tests green again.

Also morphing the bug to the latest problem which is in the test named test_load_url.

This specific test failure is fixed now, and only existed on central for 55.0.