1780399 - Intermittent browser/components/extensions/test/browser/browser_unified_extensions.js | Test timed out - | Uncaught exception in test - at chrome://mochitests/content

Status: RESOLVED DUPLICATE of bug 1780654

(WebExtensions :: General, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: bszekely [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=384874833&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/G98ibgOSSsKjWHUlBPH5dA/runs/0/artifacts/public/logs/live_backing.log

---

[task 2022-07-20T12:23:55.134Z] 12:23:55     INFO - TEST-START | browser/components/extensions/test/browser/browser_unified_extensions.js
[task 2022-07-20T12:23:55.338Z] 12:23:55     INFO - GECKO(1922) | 1658319835337	Marionette	TRACE	Received observer notification browser-delayed-startup-finished
[task 2022-07-20T12:23:55.862Z] 12:23:55     INFO - GECKO(1922) | 1658319835861	Marionette	TRACE	Received observer notification browser-delayed-startup-finished
[task 2022-07-20T12:23:56.579Z] 12:23:56     INFO - GECKO(1922) | 1658319836578	Marionette	TRACE	Received observer notification browser-delayed-startup-finished
[task 2022-07-20T12:23:57.170Z] 12:23:57     INFO - GECKO(1922) | 1658319837169	Marionette	TRACE	Received observer notification browser-delayed-startup-finished
[task 2022-07-20T12:23:57.469Z] 12:23:57     INFO - GECKO(1922) | JavaScript error: resource://gre/modules/URIFixup.jsm, line 292: NS_ERROR_FAILURE: Should pass a non-null uri
[task 2022-07-20T12:23:57.964Z] 12:23:57     INFO - GECKO(1922) | 1658319837963	Marionette	TRACE	Received observer notification browser-delayed-startup-finished
[task 2022-07-20T12:24:40.245Z] 12:24:40     INFO - TEST-INFO | started process screencapture
[task 2022-07-20T12:24:40.359Z] 12:24:40     INFO - TEST-INFO | screencapture: exit 0
[task 2022-07-20T12:24:40.359Z] 12:24:40     INFO - Buffered messages logged at 12:23:55
[task 2022-07-20T12:24:40.360Z] 12:24:40     INFO - Entering test bound test_button_enabled_by_pref
[task 2022-07-20T12:24:40.360Z] 12:24:40     INFO - TEST-PASS | browser/components/extensions/test/browser/browser_unified_extensions.js | expected button to be visible - 
[task 2022-07-20T12:24:40.361Z] 12:24:40     INFO - Leaving test bound test_button_enabled_by_pref
[task 2022-07-20T12:24:40.361Z] 12:24:40     INFO - Entering test bound test_button_disabled_by_pref
[task 2022-07-20T12:24:40.361Z] 12:24:40     INFO - Buffered messages logged at 12:23:56
[task 2022-07-20T12:24:40.362Z] 12:24:40     INFO - TEST-PASS | browser/components/extensions/test/browser/browser_unified_extensions.js | expected button to be hidden - 
[task 2022-07-20T12:24:40.362Z] 12:24:40     INFO - Leaving test bound test_button_disabled_by_pref
[task 2022-07-20T12:24:40.362Z] 12:24:40     INFO - Entering test bound test_open_panel_on_button_click
[task 2022-07-20T12:24:40.363Z] 12:24:40     INFO - Extension loaded
[task 2022-07-20T12:24:40.363Z] 12:24:40     INFO - Extension loaded
[task 2022-07-20T12:24:40.363Z] 12:24:40     INFO - Extension loaded
[task 2022-07-20T12:24:40.364Z] 12:24:40     INFO - Console message: Warning: attempting to write 46463 bytes to preference extensions.webextensions.uuids. This is bad for general performance and memory usage. Such an amount of data should rather be written to an external file. This preference will not be sent to any content processes.
[task 2022-07-20T12:24:40.364Z] 12:24:40     INFO - Console message: Warning: attempting to write 46511 bytes to preference extensions.webextensions.uuids. This is bad for general performance and memory usage. Such an amount of data should rather be written to an external file. This preference will not be sent to any content processes.
[task 2022-07-20T12:24:40.364Z] 12:24:40     INFO - Console message: Warning: attempting to write 46559 bytes to preference extensions.webextensions.uuids. This is bad for general performance and memory usage. Such an amount of data should rather be written to an external file. This preference will not be sent to any content processes.
[task 2022-07-20T12:24:40.365Z] 12:24:40     INFO - Console message: 1658319836649	addons.xpi-utils	DEBUG	Make addon app-temporary:@ext-0 visible
[task 2022-07-20T12:24:40.365Z] 12:24:40     INFO - Console message: 1658319836649	addons.xpi	DEBUG	XPIStates adding add-on @ext-0 in {}: /var/folders/w1/j59dbgks1jsfshgv0w6ybx34000014/T/generated-extension-17.xpi
[task 2022-07-20T12:24:40.367Z] 12:24:40     INFO - Console message: 1658319836649	addons.xpi	DEBUG	Updating XPIState for {"id":"@ext-0","syncGUID":"{0c6ce0c3-8a19-4a1a-b4e6-c260e3834de3}","version":"1.0","type":"extension","loader":null,"updateURL":null,"installOrigins":null,"manifestVersion":2,"optionsURL":null,"optionsType":null,"optionsBrowserStyle":true,"aboutURL":null,"defaultLocale":{"name":"Extension #1","creator":null,"developers":null,"translators":null,"contributors":null},"visible":true,"active":true,"userDisabled":false,"appDisabled":false,"embedderDisabled":false,"installDate":1658319836648,"applyBackgroundUpdates":1,"path":"/var/folders/w1/j59dbgks1jsfshgv0w6ybx34000014/T/generated-extension-17.xpi","skinnable":false,"sourceURI":null,"releaseNotesURI":null,"softDisabled":false,"foreignInstall":false,"strictCompatibility":true,"locales":[],"targetApplications":[{"id":"[e-mail]","minVersion":null,"maxVersion":null}],"targetPlatforms":[],"signedState":0,"signedDate":null,"seen":true,"dependencies":[],"incognito":"spanning","userPermissions":{"permissions":[],"origins":[]},"optionalPermissions":{"permissions":[],"origins":[]},"icons":{},"iconURL":null,"blocklistState":0,"blocklistURL":null,"startupData":null,"hidden":false,"installTelemetryInfo":null,"recommendationState":null,"rootURI":"jar:file:///var/folders/w1/j59dbgks1jsfshgv0w6ybx34000014/T/generated-extension-17.xpi!/","location":"app-temporary"}
[task 2022-07-20T12:24:40.367Z] 12:24:40     INFO - Console message: 1658319836649	addons.xpi	DEBUG	Loading bootstrap scope from jar:file:///var/folders/w1/j59dbgks1jsfshgv0w6ybx34000014/T/generated-extension-17.xpi!/
[task 2022-07-20T12:24:40.367Z] 12:24:40     INFO - Console message: 1658319836649	addons.xpi	DEBUG	Calling bootstrap method install on @ext-0 version 1.0
[task 2022-07-20T12:24:40.368Z] 12:24:40     INFO - Console message: 1658319836650	addons.xpi	DEBUG	Calling bootstrap method startup on @ext-0 version 1.0
[task 2022-07-20T12:24:40.368Z] 12:24:40     INFO - Console message: 1658319836652	addons.xpi-utils	DEBUG	Make addon app-temporary:@ext-1 visible
<...>
[task 2022-07-20T12:24:40.390Z] 12:24:40     INFO - _on_resize/this._resizeThrottleTimeout<@resource:///modules/UrlbarValueFormatter.sys.mjs:495:12
[task 2022-07-20T12:24:40.391Z] 12:24:40     INFO - setTimeout handler*_on_resize@resource:///modules/UrlbarValueFormatter.sys.mjs:493:47
[task 2022-07-20T12:24:40.391Z] 12:24:40     INFO - handleEvent@resource:///modules/UrlbarValueFormatter.sys.mjs:477:23
[task 2022-07-20T12:24:40.391Z] 12:24:40     INFO - EventListener.handleEvent*UrlbarValueFormatter@resource:///modules/UrlbarValueFormatter.sys.mjs:37:17
[task 2022-07-20T12:24:40.391Z] 12:24:40     INFO - UrlbarInput/<@resource:///modules/UrlbarInput.sys.mjs:204:14
[task 2022-07-20T12:24:40.391Z] 12:24:40     INFO - get@resource://gre/modules/XPCOMUtils.sys.mjs:57:51
[task 2022-07-20T12:24:40.391Z] 12:24:40     INFO - formatValue@resource:///modules/UrlbarInput.sys.mjs:286:7
[task 2022-07-20T12:24:40.391Z] 12:24:40     INFO - _on_focus@resource:///modules/UrlbarInput.sys.mjs:3035:10
[task 2022-07-20T12:24:40.391Z] 12:24:40     INFO - handleEvent@resource:///modules/UrlbarInput.sys.mjs:471:23
[task 2022-07-20T12:24:40.391Z] 12:24:40     INFO - EventListener.handleEvent*UrlbarInput/this[method]@resource:///modules/UrlbarInput.sys.mjs:172:39
[task 2022-07-20T12:24:40.391Z] 12:24:40     INFO - UrlbarInput@resource:///modules/UrlbarInput.sys.mjs:245:12
[task 2022-07-20T12:24:40.391Z] 12:24:40     INFO - @chrome://browser/content/browser.js:353:16
[task 2022-07-20T12:24:40.391Z] 12:24:40     INFO - get@resource://gre/modules/XPCOMUtils.sys.mjs:57:51
[task 2022-07-20T12:24:40.391Z] 12:24:40     INFO - _setURLBarPlaceholder@chrome://browser/content/browser.js:3958:1
[task 2022-07-20T12:24:40.391Z] 12:24:40     INFO - initPlaceHolder@chrome://browser/content/browser.js:3862:12
[task 2022-07-20T12:24:40.391Z] 12:24:40     INFO - onDOMContentLoaded@chrome://browser/content/browser.js:1685:19
[task 2022-07-20T12:24:40.391Z] 12:24:40     INFO - EventListener.handleEvent*@chrome://browser/content/browser.xhtml:119:10
[task 2022-07-20T12:24:40.391Z] 12:24:40     INFO - 
[task 2022-07-20T12:24:40.392Z] 12:24:40     INFO - TEST-PASS | browser/components/extensions/test/browser/browser_unified_extensions.js | expected test-icon-64.png, got: jar:file:///var/folders/w1/j59dbgks1jsfshgv0w6ybx34000014/T/generated-extension-17.xpi!/test-icon-64.png - 
[task 2022-07-20T12:24:40.393Z] 12:24:40     INFO - TEST-PASS | browser/components/extensions/test/browser/browser_unified_extensions.js | expected list view - 
[task 2022-07-20T12:24:40.393Z] 12:24:40     INFO - TEST-PASS | browser/components/extensions/test/browser/browser_unified_extensions.js | window has the required resolution - 
[task 2022-07-20T12:24:40.393Z] 12:24:40     INFO - TEST-PASS | browser/components/extensions/test/browser/browser_unified_extensions.js | expected button - 
[task 2022-07-20T12:24:40.394Z] 12:24:40     INFO - TEST-PASS | browser/components/extensions/test/browser/browser_unified_extensions.js | expected list view - 
[task 2022-07-20T12:24:40.394Z] 12:24:40     INFO - TEST-PASS | browser/components/extensions/test/browser/browser_unified_extensions.js | expected test-icon-32.png, got: jar:file:///var/folders/w1/j59dbgks1jsfshgv0w6ybx34000014/T/generated-extension-17.xpi!/test-icon-32.png - 
[task 2022-07-20T12:24:40.395Z] 12:24:40     INFO - TEST-PASS | browser/components/extensions/test/browser/browser_unified_extensions.js | expected list view - 
[task 2022-07-20T12:24:40.395Z] 12:24:40     INFO - Console message: 1658319837756	addons.xpi	DEBUG	Calling bootstrap method shutdown on @ext-3 version 1.0
[task 2022-07-20T12:24:40.396Z] 12:24:40     INFO - Console message: 1658319837767	addons.xpi	DEBUG	Calling bootstrap method uninstall on @ext-3 version 1.0
[task 2022-07-20T12:24:40.396Z] 12:24:40     INFO - Console message: 1658319837768	addons.xpi	DEBUG	Disabling XPIState for @ext-3
[task 2022-07-20T12:24:40.397Z] 12:24:40     INFO - Console message: Warning: attempting to write 46415 bytes to preference extensions.webextensions.uuids. This is bad for general performance and memory usage. Such an amount of data should rather be written to an external file. This preference will not be sent to any content processes.
[task 2022-07-20T12:24:40.397Z] 12:24:40     INFO - Leaving test bound test_item_shows_the_best_addon_icon
[task 2022-07-20T12:24:40.398Z] 12:24:40     INFO - Entering test bound test_panel_has_a_manage_extensions_button
[task 2022-07-20T12:24:40.398Z] 12:24:40     INFO - Buffered messages logged at 12:23:58
[task 2022-07-20T12:24:40.398Z] 12:24:40     INFO - TEST-PASS | browser/components/extensions/test/browser/browser_unified_extensions.js | expected button - 
[task 2022-07-20T12:24:40.399Z] 12:24:40     INFO - TEST-PASS | browser/components/extensions/test/browser/browser_unified_extensions.js | expected list view - 
[task 2022-07-20T12:24:40.399Z] 12:24:40     INFO - TEST-PASS | browser/components/extensions/test/browser/browser_unified_extensions.js | expected a 'manage extensions' button - 
[task 2022-07-20T12:24:40.400Z] 12:24:40     INFO - Buffered messages finished
[task 2022-07-20T12:24:40.400Z] 12:24:40     INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_unified_extensions.js | Test timed out - 
[task 2022-07-20T12:24:40.400Z] 12:24:40     INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-07-20T12:24:40.401Z] 12:24:40     INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_unified_extensions.js | Uncaught exception received from previously timed out test - popuphidden listener not removed before the end of test
[task 2022-07-20T12:24:40.401Z] 12:24:40     INFO - Entering test bound test_list_active_extensions_only
[task 2022-07-20T12:24:40.402Z] 12:24:40     INFO - GECKO(1922) | MEMORY STAT | vsize 8962MB | residentFast 929MB | heapAllocated 263MB
[task 2022-07-20T12:24:40.402Z] 12:24:40     INFO - TEST-OK | browser/components/extensions/test/browser/browser_unified_extensions.js | took 45125ms
[task 2022-07-20T12:24:40.403Z] 12:24:40     INFO - checking window state
[task 2022-07-20T12:24:40.403Z] 12:24:40     INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-07-20T12:24:40.403Z] 12:24:40     INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_unified_extensions.js | Found a browser window after previous test timed out - 
[task 2022-07-20T12:24:40.404Z] 12:24:40     INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-07-20T12:24:40.404Z] 12:24:40     INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_unified_extensions.js | Found a unknown window with document URI: about:blank and title:  after previous test timed out - 
[task 2022-07-20T12:24:40.404Z] 12:24:40     INFO - GECKO(1922) | must wait for focus
[task 2022-07-20T12:24:40.405Z] 12:24:40     INFO - GECKO(1922) | Completed ShutdownLeaks collections in process 1922
[task 2022-07-20T12:24:40.405Z] 12:24:40     INFO - TEST-START | Shutdown

Comment 1

[bszekely]

Hi William, could this bug be regressed by Bug 1777481?

Comment 2

[William Durand [:willdurand]]

It's very likely, indeed. I am going to investigate.. Thanks!

Comment 3

[BugBot [:suhaib / :marco/ :calixte]]

Set release status flags based on info from the regressing bug 1777481

Comment 4

[Intermittent Failures Robot]

18 failures in 3497 pushes (0.005 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 16
• mozilla-central: 2

Platform and build breakdown:

• macosx1015-64-qr: 13
  • opt: 9
  • debug: 4
• macosx1015-64-shippable-qr: 5
  • opt: 5

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1780399&startday=2022-07-18&endday=2022-07-24&tree=all