1486305 - Intermittent dom/tests/browser/browser_localStorage_e10s.js | uncaught exception - ReferenceError: ok is not defined at observer@chrome://mochitests/content/browser/dom/tests/browser/helper_largeAllocation.js:15:7

Status: RESOLVED INCOMPLETE

(Core :: DOM: Core & HTML, defect, P3)

Description

[Treeherder Bug Filer]

Filed by: apavel [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=195997775&repo=mozilla-beta

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

[task 2018-08-26T19:13:55.648Z] 19:13:55     INFO - Console message: [JavaScript Error: "Polling for changes failed: Server error 404 Not Found: "JSON.parse: unexpected character at line 1 column 1 of the JSON data"." {file: "resource://services-settings/remote-settings.js" line: 721}]
[task 2018-08-26T19:13:55.648Z] 19:13:55     INFO - remoteSettingsFunction/remoteSettings.pollChanges@resource://services-settings/remote-settings.js:721:13
[task 2018-08-26T19:13:55.649Z] 19:13:55     INFO - 
[task 2018-08-26T19:13:55.650Z] 19:13:55     INFO - Buffered messages finished
[task 2018-08-26T19:13:55.650Z] 19:13:55     INFO - TEST-UNEXPECTED-FAIL | dom/tests/browser/browser_largeAllocation_non_win32.js | Test timed out - 
[task 2018-08-26T19:13:55.651Z] 19:13:55     INFO - GECKO(1061) | MEMORY STAT | vsize 2296MB | residentFast 331MB | heapAllocated 94MB
[task 2018-08-26T19:13:55.652Z] 19:13:55     INFO - TEST-OK | dom/tests/browser/browser_largeAllocation_non_win32.js | took 360061ms
[task 2018-08-26T19:13:55.652Z] 19:13:55     INFO - Not taking screenshot here: see the one that was previously logged
[task 2018-08-26T19:13:55.653Z] 19:13:55     INFO - TEST-UNEXPECTED-FAIL | dom/tests/browser/browser_largeAllocation_non_win32.js | Found a tab after previous test timed out: about:blank - 
[task 2018-08-26T19:13:55.654Z] 19:13:55     INFO - GECKO(1061) | ++DOCSHELL 0x7f20bf803800 == 1 [pid = 1241] [id = {6d4d6abd-757d-4340-a331-6beec3a418ca}]
[task 2018-08-26T19:13:55.654Z] 19:13:55     INFO - GECKO(1061) | ++DOMWINDOW == 1 (0x7f20bfe3f400) [pid = 1241] [serial = 172] [outer = (nil)]
[task 2018-08-26T19:13:55.655Z] 19:13:55     INFO - GECKO(1061) | ++DOMWINDOW == 2 (0x7f20bf183400) [pid = 1241] [serial = 173] [outer = 0x7f20bfe3f400]
[task 2018-08-26T19:13:55.656Z] 19:13:55     INFO - GECKO(1061) | ++DOMWINDOW == 3 (0x7f20bf187c00) [pid = 1241] [serial = 174] [outer = 0x7f20bfe3f400]
[task 2018-08-26T19:13:55.657Z] 19:13:55     INFO - checking window state
[task 2018-08-26T19:13:55.657Z] 19:13:55     INFO - TEST-START | dom/tests/browser/browser_localStorage_e10s.js
[task 2018-08-26T19:13:55.658Z] 19:13:55     INFO - GECKO(1061) | Chrome file doesn't exist: /builds/worker/workspace/build/tests/mochitest/browser/dom/tests/browser/head.js
[task 2018-08-26T19:13:55.707Z] 19:13:55     INFO - GECKO(1061) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpL2lY6r.mozrunner/runtests_leaks_tab_pid1398.log
[task 2018-08-26T19:13:55.789Z] 19:13:55     INFO - Not taking screenshot here: see the one that was previously logged
[task 2018-08-26T19:13:55.790Z] 19:13:55     INFO - Buffered messages logged at 19:13:55
[task 2018-08-26T19:13:55.791Z] 19:13:55     INFO - Entering test bound 
[task 2018-08-26T19:13:55.792Z] 19:13:55     INFO - Buffered messages finished
[task 2018-08-26T19:13:55.793Z] 19:13:55     INFO - TEST-UNEXPECTED-FAIL | dom/tests/browser/browser_localStorage_e10s.js | uncaught exception - ReferenceError: ok is not defined at observer@chrome://mochitests/content/browser/dom/tests/browser/helper_largeAllocation.js:15:7
[task 2018-08-26T19:13:55.794Z] 19:13:55     INFO - _insertBrowser@chrome://browser/content/tabbrowser.js:2040:7
[task 2018-08-26T19:13:55.795Z] 19:13:55     INFO - addTab@chrome://browser/content/tabbrowser.js:2449:9
[task 2018-08-26T19:13:55.796Z] 19:13:55     INFO - addTab@resource://testing-common/BrowserTestUtils.jsm:1797:12
[task 2018-08-26T19:13:55.797Z] 19:13:55     INFO - openNewForegroundTab/promises<@resource://testing-common/BrowserTestUtils.jsm:199:44
[task 2018-08-26T19:13:55.798Z] 19:13:55     INFO - switchTab@resource://testing-common/BrowserTestUtils.jsm:288:7
[task 2018-08-26T19:13:55.799Z] 19:13:55     INFO - openNewForegroundTab@resource://testing-common/BrowserTestUtils.jsm:194:9
[task 2018-08-26T19:13:55.800Z] 19:13:55     INFO - openTestTabInOwnProcess@chrome://mochitests/content/browser/dom/tests/browser/browser_localStorage_e10s.js:45:19
[task 2018-08-26T19:13:55.801Z] 19:13:55     INFO - @chrome://mochitests/content/browser/dom/tests/browser/browser_localStorage_e10s.js:320:27
[task 2018-08-26T19:13:55.802Z] 19:13:55     INFO - 
[task 2018-08-26T19:13:55.803Z] 19:13:55     INFO - Stack trace:
[task 2018-08-26T19:13:55.804Z] 19:13:55     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:simpletestOnerror:1655
[task 2018-08-26T19:13:55.805Z] 19:13:55     INFO - chrome://browser/content/tabbrowser.js:_insertBrowser:2040
[task 2018-08-26T19:13:55.806Z] 19:13:55     INFO - chrome://browser/content/tabbrowser.js:addTab:2449
[task 2018-08-26T19:13:55.807Z] 19:13:55     INFO - resource://testing-common/BrowserTestUtils.jsm:addTab:1797
[task 2018-08-26T19:13:55.809Z] 19:13:55     INFO - resource://testing-common/BrowserTestUtils.jsm:openNewForegroundTab/promises<:199
[task 2018-08-26T19:13:55.812Z] 19:13:55     INFO - resource://testing-common/BrowserTestUtils.jsm:switchTab:288
[task 2018-08-26T19:13:55.813Z] 19:13:55     INFO - resource://testing-common/BrowserTestUtils.jsm:openNewForegroundTab:194
[task 2018-08-26T19:13:55.814Z] 19:13:55     INFO - chrome://mochitests/content/browser/dom/tests/browser/browser_localStorage_e10s.js:openTestTabInOwnProcess:45
[task 2018-08-26T19:13:55.815Z] 19:13:55     INFO - chrome://mochitests/content/browser/dom/tests/browser/browser_localStorage_e10s.js:null:320
[task 2018-08-26T19:13:55.816Z] 19:13:55     INFO - GECKO(1061) | JavaScript error: chrome://mochitests/content/browser/dom/tests/browser/helper_largeAllocation.js, line 15: ReferenceError: ok is not defined
[task 2018-08-26T19:13:55.987Z] 19:13:55     INFO - GECKO(1061) | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2018-08-26T19:13:56.009Z] 19:13:56     INFO - Console message: [JavaScript Error: "ReferenceError: ok is not defined" {file: "chrome://mochitests/content/browser/dom/tests/browser/helper_largeAllocation.js" line: 15}]

Comment 1

[Intermittent Failures Robot]

3 failures in 2568 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-beta: 2
* mozilla-inbound: 1

Platform breakdown:
* linux64: 1
* osx-10-10: 1
* linux32: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1486305&startday=2018-08-20&endday=2018-08-26&tree=all

Comment 2

[Intermittent Failures Robot]

21 failures in 2545 pushes (0.008 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* try: 1
* mozilla-central: 3
* mozilla-inbound: 7
* autoland: 10

Platform breakdown:
* windows7-32: 1
* linux32: 6
* osx-10-10: 8
* linux64: 6

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1486305&startday=2018-08-27&endday=2018-09-02&tree=all

Comment 3

[Dorel Luca [:dluca]]

This bug has failed 31 times in the last 7 days. Failures occur on osx, linux32 and 64 on opt, debug and pgo.

Log:
https://treeherder.mozilla.org/logviewer.html#?job_id=197578756&repo=mozilla-central&lineNumber=19492

Console message: [JavaScript Error: "NetworkError when attempting to fetch resource."]
04:23:30     INFO - get@resource://services-settings/remote-settings.js:332:9
04:23:30     INFO - async*getSite@resource://activity-stream/lib/FaviconFeed.jsm:158:25
04:23:30     INFO - async*fetchIcon@resource://activity-stream/lib/FaviconFeed.jsm:132:24
04:23:30     INFO - async*onAction@resource://activity-stream/lib/FaviconFeed.jsm:182:9
04:23:30     INFO - _middleware/</<@resource://activity-stream/lib/Store.jsm:51:11
04:23:30     INFO - Store/this[method]@resource://activity-stream/lib/Store.jsm:29:54
04:23:30     INFO - _requestRichIcon@resource://activity-stream/lib/TopSitesFeed.jsm:461:5
04:23:30     INFO - _fetchIcon@resource://activity-stream/lib/TopSitesFeed.jsm:425:5
04:23:30     INFO - async*getLinksWithDefaults@resource://activity-stream/lib/TopSitesFeed.jsm:330:11
04:23:30     INFO - async*refresh@resource://activity-stream/lib/TopSitesFeed.jsm:353:25
04:23:30     INFO - async*onAction@resource://activity-stream/lib/TopSitesFeed.jsm:653:9
04:23:30     INFO - _middleware/</<@resource://activity-stream/lib/Store.jsm:51:11
04:23:30     INFO - Store/this[method]@resource://activity-stream/lib/Store.jsm:29:54
04:23:30     INFO - init/this.intervalId<@resource://activity-stream/lib/SystemTickFeed.jsm:18:41
04:23:30     INFO - notify@resource://gre/modules/Timer.jsm:42:7
04:23:30     INFO - 
04:23:30     INFO - Buffered messages logged at 04:22:00
04:23:30     INFO - Longer timeout required, waiting longer...  Remaining timeouts: 1
04:23:30     INFO - Buffered messages finished
04:23:30     INFO - TEST-UNEXPECTED-FAIL | dom/tests/browser/browser_largeAllocation_non_win32.js | Test timed out - 
04:23:30     INFO - GECKO(1036) | MEMORY STAT | vsize 4405MB | residentFast 408MB | heapAllocated 77MB
04:23:30     INFO - TEST-OK | dom/tests/browser/browser_largeAllocation_non_win32.js | took 360071ms
04:23:30     INFO - Not taking screenshot here: see the one that was previously logged
04:23:30     INFO - TEST-UNEXPECTED-FAIL | dom/tests/browser/browser_largeAllocation_non_win32.js | Found a tab after previous test timed out: about:blank - 
04:23:30     INFO - GECKO(1036) | ++DOCSHELL 0x111d22800 == 1 [pid = 1041] [id = {6443f495-b1e7-5640-897d-e4a4b8e5c358}]
04:23:30     INFO - GECKO(1036) | ++DOMWINDOW == 1 (0x121802600) [pid = 1041] [serial = 172] [outer = 0x0]
04:23:30     INFO - GECKO(1036) | ++DOMWINDOW == 2 (0x119bca400) [pid = 1041] [serial = 173] [outer = 0x121802600]
04:23:30     INFO - GECKO(1036) | ++DOMWINDOW == 3 (0x1210e6000) [pid = 1041] [serial = 174] [outer = 0x121802600]
04:23:30     INFO - checking window state
04:23:30     INFO - TEST-START | dom/tests/browser/browser_localStorage_e10s.js
04:23:30     INFO - GECKO(1036) | Chrome file doesn't exist: /Users/cltbld/tasks/task_1536144883/build/tests/mochitest/browser/dom/tests/browser/head.js
04:23:30     INFO - GECKO(1036) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /var/folders/kx/qw_3r3sx5b91qxl9wlkqr37000000x/T/tmpKfZ3_S.mozrunner/runtests_leaks_tab_pid1050.log
04:23:30     INFO - Not taking screenshot here: see the one that was previously logged
04:23:30     INFO - Buffered messages logged at 04:23:30
04:23:30     INFO - Entering test bound 
04:23:30     INFO - Buffered messages finished
04:23:30     INFO - TEST-UNEXPECTED-FAIL | dom/tests/browser/browser_localStorage_e10s.js | uncaught exception - ReferenceError: ok is not defined at observer@chrome://mochitests/content/browser/dom/tests/browser/helper_largeAllocation.js:15:7
04:23:30     INFO - _insertBrowser@chrome://browser/content/tabbrowser.js:2049:7
04:23:30     INFO - addTab@chrome://browser/content/tabbrowser.js:2458:9
04:23:30     INFO - addTab@resource://testing-common/BrowserTestUtils.jsm:1767:12
04:23:30     INFO - openNewForegroundTab/promises<@resource://testing-common/BrowserTestUtils.jsm:203:44
04:23:30     INFO - switchTab@resource://testing-common/BrowserTestUtils.jsm:292:7
04:23:30     INFO - openNewForegroundTab@resource://testing-common/BrowserTestUtils.jsm:198:9
04:23:30     INFO - openTestTabInOwnProcess@chrome://mochitests/content/browser/dom/tests/browser/browser_localStorage_e10s.js:45:19
04:23:30     INFO - async*@chrome://mochitests/content/browser/dom/tests/browser/browser_localStorage_e10s.js:320:27
04:23:30     INFO - Async*Tester_execTest/<@chrome://mochikit/content/browser-test.js:1102:34
04:23:30     INFO - async*Tester_execTest@chrome://mochikit/content/browser-test.js:1093:16
04:23:30     INFO - nextTest/<@chrome://mochikit/content/browser-test.js:995:9
04:23:30     INFO - SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:795:59
04:23:30     INFO - 
04:23:30     INFO - Stack trace:

:overholt: Can you please take a look at this bug?

Comment 4

[Andrew Overholt [:overholt]]

Nika, do you know why this would be intermittently failing?

Comment 5

[Nika Layzell [:nika] (ni? for response)]

(In reply to Andrew Overholt [:overholt] from comment #4)
> Nika, do you know why this would be intermittently failing?

The exception is caused by an observer not being cleaned up after leaving the test. The root problem is that the largeAllocation test is timing out. 

That test is timing out waiting for a new process to spawn after calling history.back(). That backwards history navigation should return to the original page, but it appears from the screenshot (https://taskcluster-artifacts.net/XIdR71C-T3mehMb0hqxYZw/0/public/test_info/mozilla-test-fail-screenshot_5TgYXn.png) that we're instead ending up either with a broken xul:browser or about:blank.

There is an error in the log referencing Activity Stream failing to get a screenshot during the wait. I'm not sure whether or not that would have anything to do with the test failure...

Comment 6

[Nika Layzell [:nika] (ni? for response)]

I think this might have the same root cause as bug 1336075 - not sure though.

Comment 7

[Intermittent Failures Robot]

25 failures in 2667 pushes (0.009 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-central: 4
* try: 1
* mozilla-inbound: 2
* mozilla-beta: 3
* autoland: 15

Platform breakdown:
* linux64: 4
* osx-10-10: 12
* linux32: 9

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1486305&startday=2018-09-03&endday=2018-09-09&tree=all

Comment 8

[Intermittent Failures Robot]

5 failures in 2684 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-beta: 3
* mozilla-inbound: 1
* mozilla-central: 1

Platform breakdown:
* linux32-nightly: 1
* windows7-32: 1
* windows10-64: 1
* linux64-devedition: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1486305&startday=2018-09-10&endday=2018-09-16&tree=all

Comment 9

[Intermittent Failures Robot]

6 failures in 2902 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* autoland: 1
* mozilla-inbound: 1
* mozilla-beta: 4

Platform breakdown:
* windows10-64: 1
* osx-10-10: 2
* linux32-devedition: 1
* linux64-devedition: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1486305&startday=2018-09-17&endday=2018-09-23&tree=all

Comment 10

[Intermittent Failures Robot]

7 failures in 2773 pushes (0.003 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-beta: 7

Platform breakdown:
* linux32: 1
* linux32-nightly: 1
* linux32-devedition: 3
* linux64-devedition: 1
* linux64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1486305&startday=2018-09-24&endday=2018-09-30&tree=all

Comment 11

[Intermittent Failures Robot]

3 failures in 2708 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-beta: 2
* try: 1

Platform breakdown:
* windows10-64: 1
* linux32-nightly: 1
* osx-10-10: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1486305&startday=2018-10-01&endday=2018-10-07&tree=all

Comment 12

[Intermittent Failures Robot]

3 failures in 2740 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* autoland: 2
* mozilla-beta: 1

Platform breakdown:
* osx-10-10: 2
* linux64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1486305&startday=2018-10-08&endday=2018-10-14&tree=all

Comment 13

[Intermittent Failures Robot]

1 failures in 2759 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* autoland: 1

Platform breakdown:
* osx-10-10: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1486305&startday=2018-10-15&endday=2018-10-21&tree=all

Comment 14

[Intermittent Failures Robot]

1 failures in 2978 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 1

Platform breakdown:
* osx-10-10: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1486305&startday=2018-10-29&endday=2018-11-04&tree=all

Comment 15

[Intermittent Failures Robot]

2 failures in 3007 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-release: 2

Platform breakdown:
* linux64-nightly: 1
* linux32-nightly: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1486305&startday=2018-11-05&endday=2018-11-11&tree=all

Comment 16

[Intermittent Failures Robot]

1 failures in 2917 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-release: 1

Platform breakdown:
* linux64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1486305&startday=2018-11-12&endday=2018-11-18&tree=all

Comment 17

[Intermittent Failures Robot]

1 failures in 2808 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* autoland: 1

Platform breakdown:
* osx-10-10: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1486305&startday=2018-11-26&endday=2018-12-02&tree=all

Comment 18

[Intermittent Failures Robot]

1 failures in 1862 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 1

Platform breakdown:
* osx-10-10: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1486305&startday=2018-12-03&endday=2018-12-09&tree=all

Comment 19

[Intermittent Failures Robot]

1 failures in 2485 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* try: 1

Platform breakdown:
* windows7-32: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1486305&startday=2018-12-10&endday=2018-12-16&tree=all

Comment 20

[Firefox Bug Husbandry Bot]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup