Filed by: philringnalda [at] gmail.com https://treeherder.mozilla.org/logviewer.html#?job_id=39140776&repo=mozilla-inbound https://archive.mozilla.org/pub/firefox/tinderbox-builds/mozilla-inbound-win32/1479116840/mozilla-inbound_win7_vm_test-mochitest-5-bm138-tests1-windows-build125.txt.gz

Shane, any chance you can look into this? It looks like the type is correct for every listener up to onCompleted, which seems to suggest that the channel's loadInfo is sometimes being cleared before that listener is called. That's a bit odd...

The initial report on this doesn't seem to have repeated. The rest of the reports in comment 1, aside from the first on Jan 9, are all caused from bug 1329288 resulting in the back-out that happened on those patches. So, one report on 11-14 failing in onCompleted, and one report on 1-9 failing in onResponseStarted. I'm inclined to see if either of those ever repeat.

I see 2 out of 40 failures on android on a try push where we run tests on 16.04 as a base operating system: https://treeherder.mozilla.org/#/jobs?repo=try&revision=8d191df67e0a14bbde01312a28d827587fa9e8fb&selectedJob=103239055&filter-searchStr=mochitest-48 Extrapolating that out, we could be seeing 40-45 failures/week at scale. from a log file: https://public-artifacts.taskcluster.net/NjhpDuwPSW-aAq4Jr8hpHA/0/public/logs/live_backing.log I see this: [task 2017-05-31T03:32:02.442716Z] 03:32:02 INFO - 173 INFO TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html | correct requestId - Expected: 15, Actual: 15 [task 2017-05-31T03:32:02.443259Z] 03:32:02 INFO - 174 INFO TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html | correct tabId - Expected: 0, Actual: 0 [task 2017-05-31T03:32:02.444006Z] 03:32:02 INFO - 175 INFO TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html | expected HTTP status received for http://mochi.test:8888/tests/toolkit/components/extensions/test/mochitest/nonexistent_script_url.js HTTP/1.1 404 Not Found - Expected: 404, Actual: 404 [task 2017-05-31T03:32:02.444441Z] 03:32:02 INFO - Buffered messages logged at 03:31:55 [task 2017-05-31T03:32:02.444944Z] 03:32:02 INFO - 176 INFO onResponseStarted 12 http://mochi.test:8888/tests/toolkit/components/extensions/test/mochitest/file_image_good.png [task 2017-05-31T03:32:02.445460Z] 03:32:02 INFO - 177 INFO TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html | received onResponseStarted [task 2017-05-31T03:32:02.445902Z] 03:32:02 INFO - Buffered messages finished [task 2017-05-31T03:32:02.446429Z] 03:32:02 INFO - 178 INFO TEST-UNEXPECTED-FAIL | toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html | resource type is correct - Expected: image, Actual: other [task 2017-05-31T03:32:02.446934Z] 03:32:02 INFO - getListener/<@moz-extension://070c2998-b7cf-4223-9681-da82ab6e7f03/%7B091f6e22-5f93-41e2-b6bd-d69451e84ee9%7D.js:239:7 [task 2017-05-31T03:32:02.447787Z] 03:32:02 INFO - 179 INFO TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html | origin is correct - Expected: http://mochi.test:8888/tests/toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html, Actual: http://mochi.test:8888/tests/toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html [task 2017-05-31T03:32:02.448557Z] 03:32:02 INFO - 180 INFO TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html | origin is correct - Expected: http://mochi.test:8888/tests/toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html, Actual: http://mochi.test:8888/tests/toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html [task 2017-05-31T03:32:02.449197Z] 03:32:02 INFO - 181 INFO TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html | correct requestId - Expected: 12, Actual: 12 [task 2017-05-31T03:32:02.449723Z] 03:32:02 INFO - 182 INFO TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html | correct tabId - Expected: 0, Actual: 0 I am not sure where in the test case we are failing, but ideally with a bit more time I could figure this out: https://dxr.mozilla.org/mozilla-central/source/toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html?q=path%3Atest_ext_webrequest_basic.htm&redirect_type=single

There's two things that I see as possible causes. The first is the cache clearing that this test does and I am running some tests right now to see if this is true [1]. The other possibility is the test "test_ext_cookies.html". I've noticed that this test is preventing us from restoring focus to the open window after it is run. But, it is likely that this test has nothing to do with the problem. [1]: https://treeherder.mozilla.org/#/jobs?repo=try&revision=d902c1c5980d45f2b7ac1fd576ba0e2c935679d4 I also ran another test on the cache yesterday but there were a few problems that popped up so I'm trying it on a more recent m-c changeset. You can see the last test run at [2] and note that none of those failures have 'test_ext_webrequest_basic.html' as failing. [2]: https://treeherder.mozilla.org/#/jobs?repo=try&revision=f3c3f5d5f3421929c3d399850edfa85d61d810c1

After 120+ test runs, either I am very unlucky (since the error hasn't shown up) or I think I've started to narrow down where this bug is coming from: https://treeherder.mozilla.org/#/jobs?repo=try&revision=367a6f0660cf156d6c06cd060f17c8e589d7e508 I think we get this error because of one of these tests: - test_ext_contentscript_about_blank.html - test_ext_cookies.html **(The most likely candidate as it prevents the browser from gaining focus again)** - test_basic_form_pwonly.html - test_input_events_for_identical_values.html - test_nsFind.html - test_mousecapture_area.html - test_bug898940.html The changes that were made in the test itself were only for debugging information.

Bulk priority update of open intermittent test failure bugs. P3 => P5 https://bugzilla.mozilla.org/show_bug.cgi?id=1381960