Closed Bug 1527909 Opened 6 years ago Closed 6 years ago

Intermittent Test Verify browser/components/extensions/test/browser/browser_ext_url_overrides_newtab.js | Test timed out -

Categories

(WebExtensions :: Untriaged, defect, P5)

Product:
WebExtensions
Component:
Untriaged
Type:
defect

Tracking

(firefox-esr60 unaffected, firefox65 unaffected, firefox66 unaffected, firefox67 fixed)

Status:
RESOLVED FIXED
Milestone:
mozilla67
Tracking Flags:
Tracking Status
firefox-esr60 --- unaffected
firefox65 --- unaffected
firefox66 --- unaffected
firefox67 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: mixedpuppy)

References

Details

(Keywords: intermittent-failure, regression)

#[markdown(off)]
Filed by: btara [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=228404006&repo=autoland

https://queue.taskcluster.net/v1/task/Gsi3jcHNQ2mFfXW22LoiUA/runs/0/artifacts/public/logs/live_backing.log

[task 2019-02-14T14:35:26.294Z] 14:35:26 INFO - TEST-PASS | browser/components/extensions/test/browser/browser_ext_url_overrides_newtab.js | The notification panel is open after opening New Tab -
[task 2019-02-14T14:35:26.295Z] 14:35:26 INFO - TEST-PASS | browser/components/extensions/test/browser/browser_ext_url_overrides_newtab.js | The New Tab notification is not set for this extension -
[task 2019-02-14T14:35:26.295Z] 14:35:26 INFO - Console message: [JavaScript Error: "NS_ERROR_NOT_AVAILABLE: Component returned failure code: 0x80040111 (NS_ERROR_NOT_AVAILABLE) [nsIWebNavigation.loadURI]" {file: "chrome://browser/content/browser.js" line: 1101}]
[task 2019-02-14T14:35:26.296Z] 14:35:26 INFO - Buffered messages finished
[task 2019-02-14T14:35:26.297Z] 14:35:26 INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_ext_url_overrides_newtab.js | Test timed out -
[task 2019-02-14T14:35:26.298Z] 14:35:26 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-02-14T14:35:26.298Z] 14:35:26 INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_ext_url_overrides_newtab.js | Extension left running at test shutdown -
[task 2019-02-14T14:35:26.299Z] 14:35:26 INFO - Stack trace:
[task 2019-02-14T14:35:26.300Z] 14:35:26 INFO - chrome://mochikit/content/browser-test.js:test_ok:1304
[task 2019-02-14T14:35:26.300Z] 14:35:26 INFO - chrome://mochikit/content/tests/SimpleTest/ExtensionTestUtils.js:ExtensionTestUtils.loadExtension/<:109
[task 2019-02-14T14:35:26.300Z] 14:35:26 INFO - chrome://mochikit/content/browser-test.js:nextTest:705
[task 2019-02-14T14:35:26.301Z] 14:35:26 INFO - chrome://mochikit/content/browser-test.js:timeoutFn:1202
[task 2019-02-14T14:35:26.302Z] 14:35:26 INFO - setTimeout handler*chrome://mochikit/content/browser-test.js:Tester_execTest:1164
[task 2019-02-14T14:35:26.302Z] 14:35:26 INFO - chrome://mochikit/content/browser-test.js:nextTest/<:990
[task 2019-02-14T14:35:26.303Z] 14:35:26 INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:803
[task 2019-02-14T14:35:26.305Z] 14:35:26 INFO - GECKO(1090) | [Parent 1090, QuotaManager IO] WARNING: 'NS_FAILED(directory->GetDirectoryEntries(getter_AddRefs(entries)))', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 7235
[task 2019-02-14T14:35:26.307Z] 14:35:26 INFO - GECKO(1090) | [Parent 1090, QuotaManager IO] WARNING: 'NS_FAILED(directory->GetDirectoryEntries(getter_AddRefs(entries)))', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 7235
[task 2019-02-14T14:35:26.308Z] 14:35:26 INFO - GECKO(1090) | [Parent 1090, QuotaManager IO] WARNING: 'NS_FAILED(directory->GetDirectoryEntries(getter_AddRefs(entries)))', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 7235
[task 2019-02-14T14:35:26.309Z] 14:35:26 INFO - GECKO(1090) | [Parent 1090, QuotaManager IO] WARNING: 'NS_FAILED(directory->GetDirectoryEntries(getter_AddRefs(entries)))', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 7235
[task 2019-02-14T14:35:26.310Z] 14:35:26 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-02-14T14:35:26.311Z] 14:35:26 INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_ext_url_overrides_newtab.js | A promise chain failed to handle a rejection: Component returned failure code: 0x80040111 (NS_ERROR_NOT_AVAILABLE) [nsIWebNavigation.loadURI] - stack: _loadURI@chrome://browser/content/browser.js:1101:29
[task 2019-02-14T14:35:26.317Z] 14:35:26 INFO - loadURI@chrome://browser/content/tabbrowser.js:422:33
[task 2019-02-14T14:35:26.318Z] 14:35:26 INFO - global.replaceUrlInTab@chrome://browser/content/parent/ext-browser.js:133:12
[task 2019-02-14T14:35:26.319Z] 14:35:26 INFO - observe@chrome://browser/content/parent/ext-url-overrides.js:49:17
[task 2019-02-14T14:35:26.320Z] 14:35:26 INFO - async*notifyChange@jar:file:///builds/worker/workspace/build/application/firefox/browser/omni.ja!/components/aboutNewTabService.js:197:18
[task 2019-02-14T14:35:26.321Z] 14:35:26 INFO - set newTabURL@jar:file:///builds/worker/workspace/build/application/firefox/browser/omni.ja!/components/aboutNewTabService.js:294:10
[task 2019-02-14T14:35:26.321Z] 14:35:26 INFO - setNewTabURL@chrome://browser/content/parent/ext-url-overrides.js:66:3
[task 2019-02-14T14:35:26.322Z] 14:35:26 INFO - processNewTabSetting@chrome://browser/content/parent/ext-url-overrides.js:79:7
[task 2019-02-14T14:35:26.323Z] 14:35:26 INFO - close@chrome://browser/content/parent/ext-url-overrides.js:95:20
[task 2019-02-14T14:35:26.324Z] 14:35:26 INFO - shutdown@resource://gre/modules/Extension.jsm:2032:11
[task 2019-02-14T14:35:26.325Z] 14:35:26 INFO - async*shutdown@resource://gre/modules/Extension.jsm:1314:39
[task 2019-02-14T14:35:26.326Z] 14:35:26 INFO - async*callBootstrapMethod@resource://gre/modules/addons/XPIProvider.jsm:1709:33
[task 2019-02-14T14:35:26.327Z] 14:35:26 INFO - async*_shutdown@resource://gre/modules/addons/XPIProvider.jsm:1829:17
[task 2019-02-14T14:35:26.328Z] 14:35:26 INFO - async*shutdown@resource://gre/modules/addons/XPIProvider.jsm:1822:33
[task 2019-02-14T14:35:26.329Z] 14:35:26 INFO - async*disable@resource://gre/modules/addons/XPIProvider.jsm:1843:18
[task 2019-02-14T14:35:26.330Z] 14:35:26 INFO - async*updateAddonDisabledState@resource://gre/modules/addons/XPIDatabase.jsm:2176:25
[task 2019-02-14T14:35:26.333Z] 14:35:26 INFO - async*setUserDisabled@resource://gre/modules/addons/XPIDatabase.jsm:532:25
[task 2019-02-14T14:35:26.334Z] 14:35:26 INFO - async*disable@resource://gre/modules/addons/XPIDatabase.jsm:921:27
[task 2019-02-14T14:35:26.335Z] 14:35:26 INFO - handleCommand@resource:///modules/ExtensionControlledPopup.jsm:246:21
[task 2019-02-14T14:35:26.336Z] 14:35:26 INFO - async*clickRestoreSettings@chrome://mochitests/content/browser/browser/components/extensions/test/browser/browser_ext_url_overrides_newtab.js:27:32
[task 2019-02-14T14:35:26.337Z] 14:35:26 INFO - test_new_tab_restore_settings@chrome://mochitests/content/browser/browser/components/extensions/test/browser/browser_ext_url_overrides_newtab.js:312:3
[task 2019-02-14T14:35:26.338Z] 14:35:26 INFO - Async*Tester_execTest/<@chrome://mochikit/content/browser-test.js:1106:34
[task 2019-02-14T14:35:26.343Z] 14:35:26 INFO - async*Tester_execTest@chrome://mochikit/content/browser-test.js:1134:12
[task 2019-02-14T14:35:26.345Z] 14:35:26 INFO - nextTest/<@chrome://mochikit/content/browser-test.js:990:14
[task 2019-02-14T14:35:26.346Z] 14:35:26 INFO - SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:803:59
[task 2019-02-14T14:35:26.347Z] 14:35:26 INFO - Rejection date: Thu Feb 14 2019 14:34:01 GMT+0000 (Coordinated Universal Time) - false == true - JS frame :: resource://testing-common/PromiseTestUtils.jsm :: assertNoUncaughtRejections :: line 257
[task 2019-02-14T14:35:26.348Z] 14:35:26 INFO - Stack trace:
[task 2019-02-14T14:35:26.349Z] 14:35:26 INFO - resource://testing-common/PromiseTestUtils.jsm:assertNoUncaughtRejections:257
[task 2019-02-14T14:35:26.350Z] 14:35:26 INFO - chrome://mochikit/content/browser-test.js:nextTest:745
[task 2019-02-14T14:35:26.351Z] 14:35:26 INFO - chrome://mochikit/content/browser-test.js:timeoutFn:1202
[task 2019-02-14T14:35:26.352Z] 14:35:26 INFO - setTimeout handler*chrome://mochikit/content/browser-test.js:Tester_execTest:1164
[task 2019-02-14T14:35:26.353Z] 14:35:26 INFO - chrome://mochikit/content/browser-test.js:nextTest/<:990
[task 2019-02-14T14:35:26.354Z] 14:35:26 INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:803
[task 2019-02-14T14:35:26.355Z] 14:35:26 INFO - GECKO(1090) | MEMORY STAT | vsize 1920MB | residentFast 303MB | heapAllocated 83MB
[task 2019-02-14T14:35:26.356Z] 14:35:26 INFO - TEST-OK | browser/components/extensions/test/browser/browser_ext_url_overrides_newtab.js | took 90404ms
[task 2019-02-14T14:35:26.357Z] 14:35:26 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-02-14T14:35:26.362Z] 14:35:26 INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_ext_url_overrides_newtab.js | Found a tab after previous test timed out: about:blank -
[task 2019-02-14T14:35:26.363Z] 14:35:26 INFO - GECKO(1090) | ++DOCSHELL 0x7fd982bb2800 == 1 [pid = 1257] [id = {3833d47c-c85c-4f15-9f1e-9a7dc76dd3d0}]
[task 2019-02-14T14:35:26.364Z] 14:35:26 INFO - GECKO(1090) | ++DOMWINDOW == 1 (0x7fd982854c00) [pid = 1257] [serial = 3] [outer = (nil)]
[task 2019-02-14T14:35:26.387Z] 14:35:26 INFO - GECKO(1090) | ++DOMWINDOW == 2 (0x7fd982c81c00) [pid = 1257] [serial = 4] [outer = 0x7fd982854c00]
[task 2019-02-14T14:35:26.425Z] 14:35:26 INFO - checking window state
[task 2019-02-14T14:35:26.487Z] 14:35:26 INFO - GECKO(1090) | ++DOMWINDOW == 15 (0x7f42f856c000) [pid = 1090] [serial = 88] [outer = 0x7f4301bee800]
[task 2019-02-14T14:35:28.636Z] 14:35:28 INFO - GECKO(1090) | ++DOMWINDOW == 16 (0x7f42f856b800) [pid = 1090] [serial = 89] [outer = 0x7f4301bee800]
[task 2019-02-14T14:35:28.942Z] 14:35:28 INFO - GECKO(1090) | --DOMWINDOW == 15 (0x7f4300a78800) [pid = 1090] [serial = 87] [outer = (nil)] [url = about:blank]
[task 2019-02-14T14:35:28.943Z] 14:35:28 INFO - GECKO(1090) | --DOMWINDOW == 14 (0x7f42fc2ec000) [pid = 1090] [serial = 84] [outer = (nil)] [url = about:blank]
[task 2019-02-14T14:35:28.944Z] 14:35:28 INFO - GECKO(1090) | --DOCSHELL 0x7f42ff696000 == 6 [pid = 1090] [id = {d7f3c51b-e9e4-4800-9f83-48b464d7885b}]
[task 2019-02-14T14:35:29.975Z] 14:35:29 INFO - GECKO(1090) | --DOCSHELL 0x7f99dbd2e000 == 0 [pid = 1200] [id = {819c5c49-27c9-4e9e-9986-3afbc3831fe0}]
[task 2019-02-14T14:35:29.977Z] 14:35:29 INFO - GECKO(1090) | --DOMWINDOW == 1 (0x7f99dbd5d000) [pid = 1200] [serial = 8] [outer = (nil)] [url = about:blank]
[task 2019-02-14T14:35:29.979Z] 14:35:29 INFO - GECKO(1090) | --DOMWINDOW == 0 (0x7f99dbd5f800) [pid = 1200] [serial = 10] [outer = (nil)] [url = about:blank]
[task 2019-02-14T14:35:30.842Z] 14:35:30 INFO - GECKO(1090) | Completed ShutdownLeaks collections in process 1312
[task 2019-02-14T14:35:31.108Z] 14:35:31 INFO - GECKO(1090) | Completed ShutdownLeaks collections in process 1405
[task 2019-02-14T14:35:31.125Z] 14:35:31 INFO - GECKO(1090) | Completed ShutdownLeaks collections in process 1348
[task 2019-02-14T14:35:31.222Z] 14:35:31 INFO - GECKO(1090) | Completed ShutdownLeaks collections in process 1362
[task 2019-02-14T14:35:31.263Z] 14:35:31 INFO - GECKO(1090) | Completed ShutdownLeaks collections in process 1424
[task 2019-02-14T14:35:31.303Z] 14:35:31 INFO - GECKO(1090) | Completed ShutdownLeaks collections in process 1257
[task 2019-02-14T14:35:31.320Z] 14:35:31 INFO - GECKO(1090) | Completed ShutdownLeaks collections in process 1456
[task 2019-02-14T14:35:31.550Z] 14:35:31 INFO - GECKO(1090) | Completed ShutdownLeaks collections in process 1285
[task 2019-02-14T14:35:31.567Z] 14:35:31 INFO - GECKO(1090) | Completed ShutdownLeaks collections in process 1200
[task 2019-02-14T14:35:31.769Z] 14:35:31 INFO - GECKO(1090) | Completed ShutdownLeaks collections in process 1180
[task 2019-02-14T14:35:35.453Z] 14:35:35 INFO - GECKO(1090) | --DOMWINDOW == 13 (0x7f42ff78fc00) [pid = 1090] [serial = 10] [outer = (nil)] [url = about:blank]
[task 2019-02-14T14:35:35.455Z] 14:35:35 INFO - GECKO(1090) | --DOMWINDOW == 12 (0x7f42f856c000) [pid = 1090] [serial = 88] [outer = (nil)] [url = about:blank]
[task 2019-02-14T14:35:36.120Z] 14:35:36 INFO - GECKO(1090) | Completed ShutdownLeaks collections in process 1090
[task 2019-02-14T14:35:36.123Z] 14:35:36 INFO - TEST-START | Shutdown
[task 2019-02-14T14:35:36.125Z] 14:35:36 INFO - Browser Chrome Test Summary
[task 2019-02-14T14:35:36.127Z] 14:35:36 INFO - Passed: 82
[task 2019-02-14T14:35:36.130Z] 14:35:36 INFO - Failed: 4
[task 2019-02-14T14:35:36.132Z] 14:35:36 INFO - Todo: 0
[task 2019-02-14T14:35:36.135Z] 14:35:36 INFO - Mode: e10s
[task 2019-02-14T14:35:36.137Z] 14:35:36 INFO - *** End BrowserChrome Test Results ***

I think this is related to bug 1465508.

Looks fixed by backout of bug 1525125, reland didn't have the issue. Bug 1465508 is unrelated.

Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
Assignee: nobody → mixedpuppy
Blocks: 1525125
status-firefox65: --- → unaffected
status-firefox66: --- → unaffected
status-firefox67: --- → fixed
status-firefox-esr60: --- → unaffected
Target Milestone: --- → mozilla67

From my understanding this issue is related to the addon tests. Is there any need of manual QA here? If not can you please mark it as "qe-verify- "

Flags: needinfo?(mixedpuppy)
Flags: needinfo?(mixedpuppy) → qe-verify-
You need to log in before you can comment on or make changes to this bug.