Intermittent browser/components/extensions/test/browser/browser_ext_optionsPage_browser_style.js | This test exceeded the timeout threshold. It should be rewritten or split up. If that's not possible, use requestLongerTimeout(N), but only as a last resort

RESOLVED FIXED in Firefox 55

Status

()

Toolkit
WebExtensions: Untriaged
RESOLVED FIXED
11 months ago
9 months ago

People

(Reporter: aryx, Assigned: gbrown)

Tracking

({intermittent-failure})

unspecified
mozilla55
intermittent-failure
Points:
---

Firefox Tracking Flags

(firefox55 fixed)

Details

(Whiteboard: [stockwell fixed])

Attachments

(1 attachment)

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

[task 2017-03-18T22:11:13.094788Z] 22:11:13     INFO - TEST-PASS | browser/components/extensions/test/browser/browser_ext_optionsPage_browser_style.js | test result correct - 
[task 2017-03-18T22:11:13.100754Z] 22:11:13     INFO - Buffered messages logged at 22:11:02
[task 2017-03-18T22:11:13.105361Z] 22:11:13     INFO - Console message: Warning: attempting to write 4322 bytes to preference extensions.bootstrappedAddons. 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 2017-03-18T22:11:13.114373Z] 22:11:13     INFO - Console message: Warning: attempting to write 6081 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 2017-03-18T22:11:13.117958Z] 22:11:13     INFO - Leaving test bound test_options_with_browser_style_set_to_false
[task 2017-03-18T22:11:13.136785Z] 22:11:13     INFO - Console message: [JavaScript Error: "Called getURLForExtension on unmapped extension 4e772a5e9da395b748c4c65bac3a6c6f7c243d73@temporary-addon" {file: "resource://gre/modules/ExtensionManagement.jsm" line: 125}]
[task 2017-03-18T22:11:13.139915Z] 22:11:13     INFO - getURLForExtension@resource://gre/modules/ExtensionManagement.jsm:125:5
[task 2017-03-18T22:11:13.142241Z] 22:11:13     INFO - get optionsURL@resource://gre/modules/addons/XPIProvider.jsm:7296:20
[task 2017-03-18T22:11:13.144363Z] 22:11:13     INFO - get optionsType@resource://gre/modules/addons/XPIProvider.jsm:7317:26
[task 2017-03-18T22:11:13.146438Z] 22:11:13     INFO - hasInlineOptions@chrome://mozapps/content/extensions/extensions.js:1614:3
[task 2017-03-18T22:11:13.148152Z] 22:11:13     INFO - hide@chrome://mozapps/content/extensions/extensions.js:3310:11
[task 2017-03-18T22:11:13.150600Z] 22:11:13     INFO - shutdown@chrome://mozapps/content/extensions/extensions.js:786:7
[task 2017-03-18T22:11:13.152661Z] 22:11:13     INFO - shutdown@chrome://mozapps/content/extensions/extensions.js:285:3
[task 2017-03-18T22:11:13.157138Z] 22:11:13     INFO - _endRemoveTab@chrome://browser/content/tabbrowser.xml:2842:13
[task 2017-03-18T22:11:13.162663Z] 22:11:13     INFO - removeTab@chrome://browser/content/tabbrowser.xml:2593:15
[task 2017-03-18T22:11:13.165364Z] 22:11:13     INFO - removeTab/<@resource://testing-common/BrowserTestUtils.jsm:839:9
[task 2017-03-18T22:11:13.167974Z] 22:11:13     INFO - removeTab@resource://testing-common/BrowserTestUtils.jsm:829:12
[task 2017-03-18T22:11:13.171545Z] 22:11:13     INFO - testOptionsBrowserStyle@chrome://mochitests/content/browser/browser/components/extensions/test/browser/browser_ext_optionsPage_browser_style.js:57:9
[task 2017-03-18T22:11:13.177308Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:319:42
[task 2017-03-18T22:11:13.180088Z] 22:11:13     INFO - promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-03-18T22:11:13.183828Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.186503Z] 22:11:13     INFO - promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-03-18T22:11:13.189012Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.191787Z] 22:11:13     INFO - promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-03-18T22:11:13.194721Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.198492Z] 22:11:13     INFO - promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-03-18T22:11:13.201141Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.203873Z] 22:11:13     INFO - promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-03-18T22:11:13.207965Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.210287Z] 22:11:13     INFO - TaskImpl@resource://gre/modules/Task.jsm:277:3
[task 2017-03-18T22:11:13.212839Z] 22:11:13     INFO - asyncFunction@resource://gre/modules/Task.jsm:252:14
[task 2017-03-18T22:11:13.217138Z] 22:11:13     INFO - Task_spawn@resource://gre/modules/Task.jsm:166:12
[task 2017-03-18T22:11:13.220122Z] 22:11:13     INFO - TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:389:16
[task 2017-03-18T22:11:13.221975Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.224286Z] 22:11:13     INFO - TaskImpl@resource://gre/modules/Task.jsm:277:3
[task 2017-03-18T22:11:13.226923Z] 22:11:13     INFO - asyncFunction@resource://gre/modules/Task.jsm:252:14
[task 2017-03-18T22:11:13.229368Z] 22:11:13     INFO - Task_spawn@resource://gre/modules/Task.jsm:166:12
[task 2017-03-18T22:11:13.231723Z] 22:11:13     INFO - TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:389:16
[task 2017-03-18T22:11:13.236417Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.239699Z] 22:11:13     INFO - process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:922:23
[task 2017-03-18T22:11:13.245420Z] 22:11:13     INFO - walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:806:7
[task 2017-03-18T22:11:13.252470Z] 22:11:13     INFO - Promise*scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:739:11
[task 2017-03-18T22:11:13.255639Z] 22:11:13     INFO - schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:770:7
[task 2017-03-18T22:11:13.259923Z] 22:11:13     INFO - completePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:707:7
[task 2017-03-18T22:11:13.262952Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:324:15
[task 2017-03-18T22:11:13.266509Z] 22:11:13     INFO - promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-03-18T22:11:13.269656Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.272696Z] 22:11:13     INFO - promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-03-18T22:11:13.277137Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.283836Z] 22:11:13     INFO - promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-03-18T22:11:13.287085Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.291100Z] 22:11:13     INFO - promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-03-18T22:11:13.294425Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.300100Z] 22:11:13     INFO - promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-03-18T22:11:13.303167Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.307371Z] 22:11:13     INFO - promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-03-18T22:11:13.311857Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.318183Z] 22:11:13     INFO - TaskImpl@resource://gre/modules/Task.jsm:277:3
[task 2017-03-18T22:11:13.323300Z] 22:11:13     INFO - asyncFunction@resource://gre/modules/Task.jsm:252:14
[task 2017-03-18T22:11:13.326366Z] 22:11:13     INFO - Task_spawn@resource://gre/modules/Task.jsm:166:12
[task 2017-03-18T22:11:13.329485Z] 22:11:13     INFO - TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:389:16
[task 2017-03-18T22:11:13.333879Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.338147Z] 22:11:13     INFO - TaskImpl@resource://gre/modules/Task.jsm:277:3
[task 2017-03-18T22:11:13.344997Z] 22:11:13     INFO - asyncFunction@resource://gre/modules/Task.jsm:252:14
[task 2017-03-18T22:11:13.349425Z] 22:11:13     INFO - Task_spawn@resource://gre/modules/Task.jsm:166:12
[task 2017-03-18T22:11:13.355044Z] 22:11:13     INFO - TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:389:16
[task 2017-03-18T22:11:13.358718Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.362595Z] 22:11:13     INFO - process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:922:23
[task 2017-03-18T22:11:13.368182Z] 22:11:13     INFO - walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:806:7
[task 2017-03-18T22:11:13.374341Z] 22:11:13     INFO - 
[task 2017-03-18T22:11:13.379088Z] 22:11:13     INFO - Console message: [JavaScript Error: "Called getURLForExtension on unmapped extension 4e772a5e9da395b748c4c65bac3a6c6f7c243d73@temporary-addon" {file: "resource://gre/modules/ExtensionManagement.jsm" line: 125}]
[task 2017-03-18T22:11:13.383809Z] 22:11:13     INFO - getURLForExtension@resource://gre/modules/ExtensionManagement.jsm:125:5
[task 2017-03-18T22:11:13.387954Z] 22:11:13     INFO - get optionsURL@resource://gre/modules/addons/XPIProvider.jsm:7296:20
[task 2017-03-18T22:11:13.392355Z] 22:11:13     INFO - get optionsType@resource://gre/modules/addons/XPIProvider.jsm:7317:26
[task 2017-03-18T22:11:13.395127Z] 22:11:13     INFO - hasInlineOptions@chrome://mozapps/content/extensions/extensions.js:1615:1
[task 2017-03-18T22:11:13.397596Z] 22:11:13     INFO - hide@chrome://mozapps/content/extensions/extensions.js:3310:11
[task 2017-03-18T22:11:13.402740Z] 22:11:13     INFO - shutdown@chrome://mozapps/content/extensions/extensions.js:786:7
[task 2017-03-18T22:11:13.405330Z] 22:11:13     INFO - shutdown@chrome://mozapps/content/extensions/extensions.js:285:3
[task 2017-03-18T22:11:13.408094Z] 22:11:13     INFO - _endRemoveTab@chrome://browser/content/tabbrowser.xml:2842:13
[task 2017-03-18T22:11:13.410766Z] 22:11:13     INFO - removeTab@chrome://browser/content/tabbrowser.xml:2593:15
[task 2017-03-18T22:11:13.413512Z] 22:11:13     INFO - removeTab/<@resource://testing-common/BrowserTestUtils.jsm:839:9
[task 2017-03-18T22:11:13.417951Z] 22:11:13     INFO - removeTab@resource://testing-common/BrowserTestUtils.jsm:829:12
[task 2017-03-18T22:11:13.422395Z] 22:11:13     INFO - testOptionsBrowserStyle@chrome://mochitests/content/browser/browser/components/extensions/test/browser/browser_ext_optionsPage_browser_style.js:57:9
[task 2017-03-18T22:11:13.431545Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:319:42
[task 2017-03-18T22:11:13.439564Z] 22:11:13     INFO - promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-03-18T22:11:13.447290Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.454789Z] 22:11:13     INFO - promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-03-18T22:11:13.462997Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.468755Z] 22:11:13     INFO - promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-03-18T22:11:13.474177Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.480527Z] 22:11:13     INFO - promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-03-18T22:11:13.486194Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.492793Z] 22:11:13     INFO - promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-03-18T22:11:13.495881Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.499164Z] 22:11:13     INFO - TaskImpl@resource://gre/modules/Task.jsm:277:3
[task 2017-03-18T22:11:13.502370Z] 22:11:13     INFO - asyncFunction@resource://gre/modules/Task.jsm:252:14
[task 2017-03-18T22:11:13.505604Z] 22:11:13     INFO - Task_spawn@resource://gre/modules/Task.jsm:166:12
[task 2017-03-18T22:11:13.513677Z] 22:11:13     INFO - TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:389:16
[task 2017-03-18T22:11:13.516908Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.522687Z] 22:11:13     INFO - TaskImpl@resource://gre/modules/Task.jsm:277:3
[task 2017-03-18T22:11:13.527581Z] 22:11:13     INFO - asyncFunction@resource://gre/modules/Task.jsm:252:14
[task 2017-03-18T22:11:13.530847Z] 22:11:13     INFO - Task_spawn@resource://gre/modules/Task.jsm:166:12
[task 2017-03-18T22:11:13.533869Z] 22:11:13     INFO - TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:389:16
[task 2017-03-18T22:11:13.538091Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.542863Z] 22:11:13     INFO - process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:922:23
[task 2017-03-18T22:11:13.546325Z] 22:11:13     INFO - walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:806:7
[task 2017-03-18T22:11:13.550232Z] 22:11:13     INFO - Promise*scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:739:11
[task 2017-03-18T22:11:13.554674Z] 22:11:13     INFO - schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:770:7
[task 2017-03-18T22:11:13.560879Z] 22:11:13     INFO - completePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:707:7
[task 2017-03-18T22:11:13.563760Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:324:15
[task 2017-03-18T22:11:13.566911Z] 22:11:13     INFO - promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-03-18T22:11:13.570239Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.572666Z] 22:11:13     INFO - promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-03-18T22:11:13.578520Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.581721Z] 22:11:13     INFO - promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-03-18T22:11:13.585091Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.588124Z] 22:11:13     INFO - promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-03-18T22:11:13.592922Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.597752Z] 22:11:13     INFO - promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-03-18T22:11:13.602284Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.605431Z] 22:11:13     INFO - promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-03-18T22:11:13.608612Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.614747Z] 22:11:13     INFO - TaskImpl@resource://gre/modules/Task.jsm:277:3
[task 2017-03-18T22:11:13.623126Z] 22:11:13     INFO - asyncFunction@resource://gre/modules/Task.jsm:252:14
[task 2017-03-18T22:11:13.631416Z] 22:11:13     INFO - Task_spawn@resource://gre/modules/Task.jsm:166:12
[task 2017-03-18T22:11:13.639285Z] 22:11:13     INFO - TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:389:16
[task 2017-03-18T22:11:13.648536Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.652276Z] 22:11:13     INFO - TaskImpl@resource://gre/modules/Task.jsm:277:3
[task 2017-03-18T22:11:13.658059Z] 22:11:13     INFO - asyncFunction@resource://gre/modules/Task.jsm:252:14
[task 2017-03-18T22:11:13.664648Z] 22:11:13     INFO - Task_spawn@resource://gre/modules/Task.jsm:166:12
[task 2017-03-18T22:11:13.669986Z] 22:11:13     INFO - TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:389:16
[task 2017-03-18T22:11:13.677437Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.681292Z] 22:11:13     INFO - process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:922:23
[task 2017-03-18T22:11:13.688641Z] 22:11:13     INFO - walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:806:7
[task 2017-03-18T22:11:13.691937Z] 22:11:13     INFO - 
[task 2017-03-18T22:11:13.698086Z] 22:11:13     INFO - Console message: [JavaScript Error: "Called getURLForExtension on unmapped extension 4e772a5e9da395b748c4c65bac3a6c6f7c243d73@temporary-addon" {file: "resource://gre/modules/ExtensionManagement.jsm" line: 125}]
[task 2017-03-18T22:11:13.701624Z] 22:11:13     INFO - getURLForExtension@resource://gre/modules/ExtensionManagement.jsm:125:5
[task 2017-03-18T22:11:13.705214Z] 22:11:13     INFO - get optionsURL@resource://gre/modules/addons/XPIProvider.jsm:7296:20
[task 2017-03-18T22:11:13.710097Z] 22:11:13     INFO - get optionsType@resource://gre/modules/addons/XPIProvider.jsm:7317:26
[task 2017-03-18T22:11:13.713365Z] 22:11:13     INFO - hasInlineOptions@chrome://mozapps/content/extensions/extensions.js:1616:1
[task 2017-03-18T22:11:13.716646Z] 22:11:13     INFO - hide@chrome://mozapps/content/extensions/extensions.js:3310:11
[task 2017-03-18T22:11:13.721766Z] 22:11:13     INFO - shutdown@chrome://mozapps/content/extensions/extensions.js:786:7
[task 2017-03-18T22:11:13.726149Z] 22:11:13     INFO - shutdown@chrome://mozapps/content/extensions/extensions.js:285:3
[task 2017-03-18T22:11:13.729376Z] 22:11:13     INFO - _endRemoveTab@chrome://browser/content/tabbrowser.xml:2842:13
[task 2017-03-18T22:11:13.735209Z] 22:11:13     INFO - removeTab@chrome://browser/content/tabbrowser.xml:2593:15
[task 2017-03-18T22:11:13.737786Z] 22:11:13     INFO - removeTab/<@resource://testing-common/BrowserTestUtils.jsm:839:9
[task 2017-03-18T22:11:13.740668Z] 22:11:13     INFO - removeTab@resource://testing-common/BrowserTestUtils.jsm:829:12
[task 2017-03-18T22:11:13.744648Z] 22:11:13     INFO - testOptionsBrowserStyle@chrome://mochitests/content/browser/browser/components/extensions/test/browser/browser_ext_optionsPage_browser_style.js:57:9
[task 2017-03-18T22:11:13.749322Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:319:42
[task 2017-03-18T22:11:13.753694Z] 22:11:13     INFO - promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-03-18T22:11:13.755951Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.758322Z] 22:11:13     INFO - promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-03-18T22:11:13.762576Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.764922Z] 22:11:13     INFO - promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-03-18T22:11:13.767296Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.770689Z] 22:11:13     INFO - promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-03-18T22:11:13.774349Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.777165Z] 22:11:13     INFO - promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-03-18T22:11:13.779591Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.783715Z] 22:11:13     INFO - TaskImpl@resource://gre/modules/Task.jsm:277:3
[task 2017-03-18T22:11:13.786112Z] 22:11:13     INFO - asyncFunction@resource://gre/modules/Task.jsm:252:14
[task 2017-03-18T22:11:13.789795Z] 22:11:13     INFO - Task_spawn@resource://gre/modules/Task.jsm:166:12
[task 2017-03-18T22:11:13.792188Z] 22:11:13     INFO - TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:389:16
[task 2017-03-18T22:11:13.794641Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.800074Z] 22:11:13     INFO - TaskImpl@resource://gre/modules/Task.jsm:277:3
[task 2017-03-18T22:11:13.808393Z] 22:11:13     INFO - asyncFunction@resource://gre/modules/Task.jsm:252:14
[task 2017-03-18T22:11:13.818347Z] 22:11:13     INFO - Task_spawn@resource://gre/modules/Task.jsm:166:12
[task 2017-03-18T22:11:13.821954Z] 22:11:13     INFO - TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:389:16
[task 2017-03-18T22:11:13.826744Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.834707Z] 22:11:13     INFO - process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:922:23
[task 2017-03-18T22:11:13.842361Z] 22:11:13     INFO - walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:806:7
[task 2017-03-18T22:11:13.847579Z] 22:11:13     INFO - Promise*scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:739:11
[task 2017-03-18T22:11:13.850911Z] 22:11:13     INFO - schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:770:7
[task 2017-03-18T22:11:13.855716Z] 22:11:13     INFO - completePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:707:7
[task 2017-03-18T22:11:13.862666Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:324:15
[task 2017-03-18T22:11:13.866533Z] 22:11:13     INFO - promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-03-18T22:11:13.870608Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.875460Z] 22:11:13     INFO - promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-03-18T22:11:13.878316Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.882057Z] 22:11:13     INFO - promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-03-18T22:11:13.886571Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.892567Z] 22:11:13     INFO - promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-03-18T22:11:13.895841Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.901153Z] 22:11:13     INFO - promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-03-18T22:11:13.904469Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.907648Z] 22:11:13     INFO - promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-03-18T22:11:13.910619Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.914100Z] 22:11:13     INFO - TaskImpl@resource://gre/modules/Task.jsm:277:3
[task 2017-03-18T22:11:13.916893Z] 22:11:13     INFO - asyncFunction@resource://gre/modules/Task.jsm:252:14
[task 2017-03-18T22:11:13.921367Z] 22:11:13     INFO - Task_spawn@resource://gre/modules/Task.jsm:166:12
[task 2017-03-18T22:11:13.924242Z] 22:11:13     INFO - TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:389:16
[task 2017-03-18T22:11:13.926594Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.929029Z] 22:11:13     INFO - TaskImpl@resource://gre/modules/Task.jsm:277:3
[task 2017-03-18T22:11:13.931448Z] 22:11:13     INFO - asyncFunction@resource://gre/modules/Task.jsm:252:14
[task 2017-03-18T22:11:13.934688Z] 22:11:13     INFO - Task_spawn@resource://gre/modules/Task.jsm:166:12
[task 2017-03-18T22:11:13.937291Z] 22:11:13     INFO - TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:389:16
[task 2017-03-18T22:11:13.940358Z] 22:11:13     INFO - TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-03-18T22:11:13.943027Z] 22:11:13     INFO - process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:922:23
[task 2017-03-18T22:11:13.946112Z] 22:11:13     INFO - walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:806:7
[task 2017-03-18T22:11:13.948949Z] 22:11:13     INFO - 
[task 2017-03-18T22:11:13.952977Z] 22:11:13     INFO - Buffered messages finished
[task 2017-03-18T22:11:13.956076Z] 22:11:13     INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_ext_optionsPage_browser_style.js | This test exceeded the timeout threshold. It should be rewritten or split up. If that's not possible, use requestLongerTimeout(N), but only as a last resort. - 

Followed by many more extension tests timing out.
A month without further intermittent reports attached after the first, closing.
Status: NEW → RESOLVED
Last Resolved: 10 months ago
Resolution: --- → INVALID
Hit again: https://treeherder.mozilla.org/logviewer.html#?job_id=95421145&repo=mozilla-inbound
Please close bugs which lack recent occurrences with WORKSFORME, not INVALID.
Status: RESOLVED → REOPENED
Resolution: INVALID → ---

Comment 3

10 months ago
14 failures in 770 pushes (0.018 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* mozilla-inbound: 10
* mozilla-central: 2
* autoland: 2

Platform breakdown:
* linux32: 14

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1348639&startday=2017-05-01&endday=2017-05-07&tree=all

Comment 4

9 months ago
14 failures in 777 pushes (0.018 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* mozilla-inbound: 6
* autoland: 5
* mozilla-central: 3

Platform breakdown:
* linux32: 14

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1348639&startday=2017-05-15&endday=2017-05-21&tree=all

Comment 5

9 months ago
21 failures in 157 pushes (0.134 failures/push) were associated with this bug yesterday.   

Repository breakdown:
* mozilla-inbound: 7
* autoland: 6
* mozilla-central: 3
* try: 2
* graphics: 2
* oak: 1

Platform breakdown:
* linux32: 21

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1348639&startday=2017-05-25&endday=2017-05-25&tree=all
(Assignee)

Comment 6

9 months ago
Test durations for browser/components/extensions/test/browser/browser_ext_optionsPage_browser_style.js on mozilla-central,mozilla-inbound,autoland between 2017-05-19 and 2017-05-26
linux32-nightly/opt-chunked:     6.05 s (4.44 s - 8.15 s over 13 runs)
linux32-nightly/opt-e10s:        6.99 s (5.48 s - 8.15 s over 6 runs)
linux32/debug-chunked:          74.26 s (44.46 s - 93.86 s over 325 runs)
linux32/debug-e10s:             81.76 s (71.79 s - 93.86 s over 158 runs)
linux32/opt-chunked:             7.14 s (4.84 s - 15.20 s over 611 runs)
linux32/opt-e10s:                7.96 s (6.37 s - 15.20 s over 304 runs)
linux64-ccov/opt-chunked:       30.68 s (27.16 s - 37.15 s over 6 runs)
linux64-ccov/opt-e10s:          28.74 s (28.74 s - 28.74 s over 1 runs)
linux64-jsdcov/opt:             10.71 s (10.11 s - 11.24 s over 5 runs)
linux64-nightly/opt-chunked:     6.31 s (4.36 s - 10.08 s over 11 runs)
linux64-nightly/opt-e10s:        7.07 s (5.31 s - 10.08 s over 6 runs)
linux64/asan-chunked:           16.32 s (9.84 s - 28.04 s over 352 runs)
linux64/asan-e10s:              18.16 s (14.24 s - 28.04 s over 179 runs)
linux64/debug-chunked:          47.16 s (31.30 s - 69.04 s over 691 runs)
linux64/debug-e10s:             53.43 s (40.50 s - 69.04 s over 178 runs)
linux64/opt-chunked:             6.57 s (4.22 s - 13.46 s over 518 runs)
linux64/opt-e10s:                7.68 s (5.53 s - 11.37 s over 175 runs)
linux64/pgo-chunked:             5.87 s (3.63 s - 11.85 s over 536 runs)
linux64/pgo-e10s:                7.18 s (5.22 s - 11.85 s over 180 runs)
macosx64/debug-e10s:            18.61 s (8.65 s - 45.99 s over 516 runs)
macosx64/opt-e10s:               4.42 s (2.87 s - 6.21 s over 511 runs)
macosx64/opt:                    2.73 s (2.03 s - 4.71 s over 524 runs)
win32/debug-e10s:               15.97 s (10.65 s - 21.03 s over 177 runs)
win32/debug:                    13.35 s (9.90 s - 17.71 s over 189 runs)
win32/opt-e10s:                  4.76 s (3.56 s - 6.79 s over 326 runs)
win32/opt:                       3.70 s (3.06 s - 5.13 s over 202 runs)
win32/pgo-e10s:                  3.71 s (3.14 s - 5.57 s over 116 runs)
win32/pgo:                       3.27 s (2.76 s - 4.46 s over 112 runs)
win64/debug-e10s:               15.48 s (9.95 s - 20.92 s over 181 runs)
win64/debug:                    12.13 s (8.77 s - 16.70 s over 178 runs)
win64/opt-e10s:                  4.76 s (3.84 s - 13.74 s over 183 runs)
win64/opt:                       4.03 s (3.34 s - 8.41 s over 188 runs)
win64/pgo-e10s:                  4.16 s (3.46 s - 8.50 s over 108 runs)
win64/pgo:                       3.61 s (2.93 s - 12.89 s over 110 runs)
(Assignee)

Comment 7

9 months ago
Created attachment 8871810 [details] [diff] [review]
requestLongerTimeout

This test is intermittently running for longer than 90 seconds on linux32-debug. Let's increase the timeout for a quick fix.
Attachment #8871810 - Flags: review?(mwein)

Comment 8

9 months ago
Comment on attachment 8871810 [details] [diff] [review]
requestLongerTimeout

Review of attachment 8871810 [details] [diff] [review]:
-----------------------------------------------------------------

Sounds good to me. Could you also move extension.unload() before BrowserTestUtils.removeTab(tab) to get rid of the "Called getURLForExtension on unmapped extension" error? I'm not sure if that will fix the intermittent, but it would be nice to fix that error either way.

+mixedpuppy as additional reviewer for stamp of approval.
Attachment #8871810 - Flags: review?(mwein)
Attachment #8871810 - Flags: review?(mixedpuppy)
Attachment #8871810 - Flags: review+
(Assignee)

Comment 9

9 months ago
(In reply to Matthew Wein [:mattw] from comment #8)
> Could you also move extension.unload() before
> BrowserTestUtils.removeTab(tab) to get rid of the "Called getURLForExtension
> on unmapped extension" error? I'm not sure if that will fix the
> intermittent, but it would be nice to fix that error either way.

It's already in that order:

https://hg.mozilla.org/mozilla-central/file/f7adbf457ee20eeffde72694e0d17d73616e3cfd/browser/components/extensions/test/browser/browser_ext_optionsPage_browser_style.js#l55

Should it be 

  await BrowserTestUtils.removeTab(tab);

  await extension.unload();

?
Attachment #8871810 - Flags: review?(mixedpuppy) → review+
(In reply to Geoff Brown [:gbrown] from comment #9)
> (In reply to Matthew Wein [:mattw] from comment #8)
> > Could you also move extension.unload() before
> > BrowserTestUtils.removeTab(tab) to get rid of the "Called getURLForExtension
> > on unmapped extension" error? I'm not sure if that will fix the
> > intermittent, but it would be nice to fix that error either way.
> 
> It's already in that order:
> 
> https://hg.mozilla.org/mozilla-central/file/
> f7adbf457ee20eeffde72694e0d17d73616e3cfd/browser/components/extensions/test/
> browser/browser_ext_optionsPage_browser_style.js#l55
> 
> Should it be 
> 
>   await BrowserTestUtils.removeTab(tab);
> 
>   await extension.unload();
> 
> ?

Yes, sorry, I got that backwards.

Comment 11

9 months ago
46 failures in 891 pushes (0.052 failures/push) were associated with this bug in the last 7 days. 

This is the #29 most frequent failure this week.  

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. ** 

Repository breakdown:
* autoland: 14
* mozilla-inbound: 13
* mozilla-central: 9
* try: 6
* graphics: 3
* oak: 1

Platform breakdown:
* linux32: 44
* linux64: 2

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1348639&startday=2017-05-22&endday=2017-05-28&tree=all
gbrown, I see you uploaded a patch which has r+, should we land this?
Flags: needinfo?(gbrown)
Whiteboard: [stockwell needswork]
(Assignee)

Comment 13

9 months ago
Thanks for the reminder!
Flags: needinfo?(gbrown)

Comment 14

9 months ago
Pushed by gbrown@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/3eccf32d5a83
requestLongerTimeout for test browser_ext_optionsPage_browser_style.js; r=mattw,mixedpuppy
(Assignee)

Updated

9 months ago
Assignee: nobody → gbrown
Whiteboard: [stockwell needswork] → [stockwell fixed]

Comment 15

9 months ago
bugherder
https://hg.mozilla.org/mozilla-central/rev/3eccf32d5a83
Status: REOPENED → RESOLVED
Last Resolved: 10 months ago9 months ago
status-firefox55: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla55

Comment 16

9 months ago
14 failures in 820 pushes (0.017 failures/push) were associated with this bug in the last 7 days.   

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

Platform breakdown:
* linux32: 14

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1348639&startday=2017-05-29&endday=2017-06-04&tree=all
You need to log in before you can comment on or make changes to this bug.