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

RESOLVED FIXED
2 years ago
7 months ago

People

(Reporter: aryx, Assigned: gbrown)

Tracking

({intermittent-failure})

unspecified
mozilla55
intermittent-failure

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: 2 years 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 hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
(Assignee)

Comment 6

2 years 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

2 years 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 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

2 years 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 hidden (Intermittent Failures Robot)
gbrown, I see you uploaded a patch which has r+, should we land this?
Flags: needinfo?(gbrown)
Whiteboard: [stockwell needswork]
(Assignee)

Comment 13

2 years ago
Thanks for the reminder!
Flags: needinfo?(gbrown)

Comment 14

2 years 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

2 years ago
Assignee: nobody → gbrown
Whiteboard: [stockwell needswork] → [stockwell fixed]

Comment 15

2 years ago
bugherder
https://hg.mozilla.org/mozilla-central/rev/3eccf32d5a83
Status: REOPENED → RESOLVED
Last Resolved: 2 years ago2 years ago
status-firefox55: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla55
Comment hidden (Intermittent Failures Robot)

Updated

7 months ago
Product: Toolkit → WebExtensions
You need to log in before you can comment on or make changes to this bug.