Open
Bug 1304273
Opened 8 years ago
Updated 1 year ago
Intermittent browser/base/content/test/general/browser_offlineQuotaNotification.js | Test timed out -
Categories
(Firefox :: General, defect, P5)
Firefox
General
Tracking
()
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: intermittent-failure, leave-open, Whiteboard: [stockwell disabled])
Attachments
(2 files)
59 bytes,
text/x-review-board-request
|
Details | |
1.25 KB,
patch
|
gbrown
:
review+
|
Details | Diff | Splinter Review |
Filed by: philringnalda [at] gmail.com https://treeherder.mozilla.org/logviewer.html#?job_id=36172242&repo=mozilla-inbound https://archive.mozilla.org/pub/firefox/tinderbox-builds/mozilla-inbound-linux64/1474413915/mozilla-inbound_ubuntu64_vm_test-mochitest-browser-chrome-7-bm117-tests1-linux64-build157.txt.gz
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 3•7 years ago
|
||
this is hitting our threshold of 30 failures/week (given recent data)- I am starting to look into this. On Feb 2nd, this started up, I have done a lot of retriggers: https://treeherder.mozilla.org/#/jobs?repo=autoland&filter-searchStr=linux%20opt%20browser-chrome-2&tochange=4e2d67e6ce3e81bc357e7c7992b35a2a9ccd9f49&fromchange=58967ce933159d16ac5825830782d670ce105d0e&selectedJob=73989810 the test finishes typically in <5 seconds, especially on linux32/64 opt/pgo where this is failing. this is not failing in e10s mode. this is the error we get: TEST-UNEXPECTED-FAIL | browser/base/content/test/general/browser_offlineQuotaNotification.js | A promise chain failed to handle a rejection: - at chrome://mochitests/content/browser/browser/base/content/test/general/browser_offlineQuotaNotification.js:69 - TypeError: PopupNotifications.panel.firstElementChild is null and from the same log[0] we get this full output: [task 2017-02-02T19:34:39.169204Z] 19:34:39 INFO - TEST-START | browser/base/content/test/general/browser_offlineQuotaNotification.js [task 2017-02-02T19:34:40.320998Z] 19:34:40 INFO - ************************* [task 2017-02-02T19:34:40.324912Z] 19:34:40 INFO - A coding exception was thrown in a Promise resolution callback. [task 2017-02-02T19:34:40.325301Z] 19:34:40 INFO - See https://developer.mozilla.org/Mozilla/JavaScript_code_modules/Promise.jsm/Promise [task 2017-02-02T19:34:40.328031Z] 19:34:40 INFO - Full message: TypeError: PopupNotifications.panel.firstElementChild is null [task 2017-02-02T19:34:40.336567Z] 19:34:40 INFO - Full stack: test/</<@chrome://mochitests/content/browser/browser/base/content/test/general/browser_offlineQuotaNotification.js:69:7 [task 2017-02-02T19:34:40.338163Z] 19:34:40 INFO - process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:922:23 [task 2017-02-02T19:34:40.340044Z] 19:34:40 INFO - walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:806:7 [task 2017-02-02T19:34:40.342385Z] 19:34:40 INFO - Promise*scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:739:11 [task 2017-02-02T19:34:40.345035Z] 19:34:40 INFO - schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:770:7 [task 2017-02-02T19:34:40.345425Z] 19:34:40 INFO - completePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:707:7 [task 2017-02-02T19:34:40.348984Z] 19:34:40 INFO - receiveMessage@resource://testing-common/ContentTask.jsm:113:9 [task 2017-02-02T19:34:40.350973Z] 19:34:40 INFO - ************************* [task 2017-02-02T19:34:47.100854Z] 19:34:47 INFO - TEST-INFO | started process screentopng [task 2017-02-02T19:34:47.993024Z] 19:34:47 INFO - TEST-INFO | screentopng: exit 0 [task 2017-02-02T19:34:47.996736Z] 19:34:47 INFO - Buffered messages logged at 19:34:40 [task 2017-02-02T19:34:47.998495Z] 19:34:47 INFO - Loaded page, adding onCached handler [task 2017-02-02T19:34:48.002018Z] 19:34:48 INFO - Console message: Offline cache update done, URL=http://mochi.test:8888/browser/browser/base/content/test/general/offlineQuotaNotification.cacheManifest [task 2017-02-02T19:34:48.004106Z] 19:34:48 INFO - TEST-PASS | browser/base/content/test/general/browser_offlineQuotaNotification.js | have offline-app-usage notification - [task 2017-02-02T19:34:48.006060Z] 19:34:48 INFO - Buffered messages finished [task 2017-02-02T19:34:48.008544Z] 19:34:48 INFO - TEST-UNEXPECTED-FAIL | browser/base/content/test/general/browser_offlineQuotaNotification.js | A promise chain failed to handle a rejection: - at chrome://mochitests/content/browser/browser/base/content/test/general/browser_offlineQuotaNotification.js:69 - TypeError: PopupNotifications.panel.firstElementChild is null [task 2017-02-02T19:34:48.010770Z] 19:34:48 INFO - Stack trace: [task 2017-02-02T19:34:48.012999Z] 19:34:48 INFO - test/</<@chrome://mochitests/content/browser/browser/base/content/test/general/browser_offlineQuotaNotification.js:69:7 [task 2017-02-02T19:34:48.016334Z] 19:34:48 INFO - process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:922:23 [task 2017-02-02T19:34:48.020103Z] 19:34:48 INFO - walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:806:7 [task 2017-02-02T19:34:48.022158Z] 19:34:48 INFO - Promise*scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:739:11 [task 2017-02-02T19:34:48.024027Z] 19:34:48 INFO - schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:770:7 [task 2017-02-02T19:34:48.025904Z] 19:34:48 INFO - completePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:707:7 [task 2017-02-02T19:34:48.027681Z] 19:34:48 INFO - receiveMessage@resource://testing-common/ContentTask.jsm:113:9 [task 2017-02-02T19:35:09.150492Z] 19:35:09 INFO - Console message: [JavaScript Error: "1486064109090 Toolkit.Telemetry ERROR TelemetrySend::_doPing - error making request to https://127.0.0.1:8888/telemetry-dummy//submit/telemetry/6b46a1d1-91fb-45f3-ba64-88b213b59a67/main/Firefox/54.0a1/default/20170202190229?v=4: timeout" {file: "resource://gre/modules/Log.jsm" line: 748}] [task 2017-02-02T19:35:09.151235Z] 19:35:09 INFO - App_append@resource://gre/modules/Log.jsm:748:9 [task 2017-02-02T19:35:09.154182Z] 19:35:09 INFO - log@resource://gre/modules/Log.jsm:386:7 [task 2017-02-02T19:35:09.155719Z] 19:35:09 INFO - getLoggerWithMessagePrefix/proxy.log@resource://gre/modules/Log.jsm:501:44 [task 2017-02-02T19:35:09.157622Z] 19:35:09 INFO - error@resource://gre/modules/Log.jsm:394:5 [task 2017-02-02T19:35:09.160481Z] 19:35:09 INFO - errorhandler@resource://gre/modules/TelemetrySend.jsm:951:7 [task 2017-02-02T19:35:09.160829Z] 19:35:09 INFO - EventHandlerNonNull*_doPing@resource://gre/modules/TelemetrySend.jsm:955:5 [task 2017-02-02T19:35:09.161138Z] 19:35:09 INFO - sendPings/p<@resource://gre/modules/TelemetrySend.jsm:784:17 [task 2017-02-02T19:35:09.161379Z] 19:35:09 INFO - TaskImpl_run@resource://gre/modules/Task.jsm:319:42 [task 2017-02-02T19:35:09.164385Z] 19:35:09 INFO - TaskImpl@resource://gre/modules/Task.jsm:277:3 [task 2017-02-02T19:35:09.166401Z] 19:35:09 INFO - asyncFunction@resource://gre/modules/Task.jsm:252:14 [task 2017-02-02T19:35:09.168561Z] 19:35:09 INFO - Task_spawn@resource://gre/modules/Task.jsm:166:12 [task 2017-02-02T19:35:09.170683Z] 19:35:09 INFO - sendPings@resource://gre/modules/TelemetrySend.jsm:782:15 [task 2017-02-02T19:35:09.172814Z] 19:35:09 INFO - SendScheduler._doSendTask<@resource://gre/modules/TelemetrySend.jsm:460:13 [task 2017-02-02T19:35:09.175148Z] 19:35:09 INFO - TaskImpl_run@resource://gre/modules/Task.jsm:319:42 [task 2017-02-02T19:35:09.176997Z] 19:35:09 INFO - TaskImpl@resource://gre/modules/Task.jsm:277:3 [task 2017-02-02T19:35:09.179003Z] 19:35:09 INFO - asyncFunction@resource://gre/modules/Task.jsm:252:14 [task 2017-02-02T19:35:09.183205Z] 19:35:09 INFO - triggerSendingPings@resource://gre/modules/TelemetrySend.jsm:385:24 [task 2017-02-02T19:35:09.185156Z] 19:35:09 INFO - submitPing@resource://gre/modules/TelemetrySend.jsm:720:5 [task 2017-02-02T19:35:09.186961Z] 19:35:09 INFO - submitPing@resource://gre/modules/TelemetrySend.jsm:209:12 [task 2017-02-02T19:35:09.189041Z] 19:35:09 INFO - Impl._submitPingLogic<@resource://gre/modules/TelemetryController.jsm:476:12 [task 2017-02-02T19:35:09.190923Z] 19:35:09 INFO - TaskImpl_run@resource://gre/modules/Task.jsm:319:42 [task 2017-02-02T19:35:09.192645Z] 19:35:09 INFO - TaskImpl@resource://gre/modules/Task.jsm:277:3 [task 2017-02-02T19:35:09.195226Z] 19:35:09 INFO - asyncFunction@resource://gre/modules/Task.jsm:252:14 [task 2017-02-02T19:35:09.197039Z] 19:35:09 INFO - send@resource://gre/modules/TelemetryController.jsm:520:19 [task 2017-02-02T19:35:09.198950Z] 19:35:09 INFO - submitExternalPing@resource://gre/modules/TelemetryController.jsm:206:12 [task 2017-02-02T19:35:09.200965Z] 19:35:09 INFO - _onEnvironmentChange@resource://gre/modules/TelemetrySession.jsm:2082:5 [task 2017-02-02T19:35:09.203032Z] 19:35:09 INFO - delayedInit/this._delayedInitTask</<@resource://gre/modules/TelemetrySession.jsm:1543:52 [task 2017-02-02T19:35:09.205433Z] 19:35:09 INFO - _onEnvironmentChange@resource://gre/modules/TelemetryEnvironment.jsm:1455:9 [task 2017-02-02T19:35:09.207387Z] 19:35:09 INFO - _checkForChanges/this._pendingTask<@resource://gre/modules/TelemetryEnvironment.jsm:492:11 [task 2017-02-02T19:35:09.209608Z] 19:35:09 INFO - process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:922:23 [task 2017-02-02T19:35:09.213550Z] 19:35:09 INFO - walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:806:7 [task 2017-02-02T19:35:09.215475Z] 19:35:09 INFO - Promise*scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:739:11 [task 2017-02-02T19:35:09.217400Z] 19:35:09 INFO - schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:770:7 [task 2017-02-02T19:35:09.219181Z] 19:35:09 INFO - completePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:707:7 [task 2017-02-02T19:35:09.221023Z] 19:35:09 INFO - get _worker/worker.onmessage@resource://gre/modules/PromiseWorker.jsm:231:9 [task 2017-02-02T19:35:09.224707Z] 19:35:09 INFO - EventHandlerNonNull*get _worker@resource://gre/modules/PromiseWorker.jsm:217:5 [task 2017-02-02T19:35:09.226600Z] 19:35:09 INFO - postMessage@resource://gre/modules/PromiseWorker.jsm:291:9 [task 2017-02-02T19:35:09.228328Z] 19:35:09 INFO - TaskImpl_run@resource://gre/modules/Task.jsm:319:42 [task 2017-02-02T19:35:09.230455Z] 19:35:09 INFO - process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:922:23 [task 2017-02-02T19:35:09.232345Z] 19:35:09 INFO - walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:806:7 [task 2017-02-02T19:35:09.234174Z] 19:35:09 INFO - Promise*scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:739:11 [task 2017-02-02T19:35:09.236247Z] 19:35:09 INFO - schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:770:7 [task 2017-02-02T19:35:09.241158Z] 19:35:09 INFO - completePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:707:7 [task 2017-02-02T19:35:09.243062Z] 19:35:09 INFO - observe@resource://gre/modules/AddonManager.jsm:2857:17 [task 2017-02-02T19:35:09.244815Z] 19:35:09 INFO - reply@resource://app/modules/ExtensionsUI.jsm:131:9 [task 2017-02-02T19:35:09.246666Z] 19:35:09 INFO - promise callback*observe@resource://app/modules/ExtensionsUI.jsm:140:9 [task 2017-02-02T19:35:09.248452Z] 19:35:09 INFO - setupPromptHandler/install.promptHandler/<@resource://gre/modules/AddonManager.jsm:2868:9 [task 2017-02-02T19:35:09.250490Z] 19:35:09 INFO - Promise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:390:5 [task 2017-02-02T19:35:09.252331Z] 19:35:09 INFO - setupPromptHandler/install.promptHandler@resource://gre/modules/AddonManager.jsm:2827:37 [task 2017-02-02T19:35:09.258171Z] 19:35:09 INFO - checkPrompt/<@resource://gre/modules/addons/XPIProvider.jsm:5632:17 [task 2017-02-02T19:35:09.260256Z] 19:35:09 INFO - TaskImpl_run@resource://gre/modules/Task.jsm:319:42 [task 2017-02-02T19:35:09.262128Z] 19:35:09 INFO - TaskImpl@resource://gre/modules/Task.jsm:277:3 [task 2017-02-02T19:35:09.263848Z] 19:35:09 INFO - asyncFunction@resource://gre/modules/Task.jsm:252:14 [task 2017-02-02T19:35:09.265614Z] 19:35:09 INFO - Task_spawn@resource://gre/modules/Task.jsm:166:12 [task 2017-02-02T19:35:09.267433Z] 19:35:09 INFO - checkPrompt@resource://gre/modules/addons/XPIProvider.jsm:5623:5 [task 2017-02-02T19:35:09.269151Z] 19:35:09 INFO - install@resource://gre/modules/addons/XPIProvider.jsm:5354:7 [task 2017-02-02T19:35:09.271142Z] 19:35:09 INFO - install@resource://gre/modules/addons/XPIProvider.jsm:6130:7 [task 2017-02-02T19:35:09.272934Z] 19:35:09 INFO - downloadCompleted/<@resource://gre/modules/addons/XPIProvider.jsm:6446:9 [task 2017-02-02T19:35:09.274766Z] 19:35:09 INFO - makeSafe/<@resource://gre/modules/addons/XPIProvider.jsm -> resource://gre/modules/addons/XPIProviderUtils.js:172:17 [task 2017-02-02T19:35:09.276580Z] 19:35:09 INFO - getRepositoryAddon@resource://gre/modules/addons/XPIProvider.jsm -> resource://gre/modules/addons/XPIProviderUtils.js:153:5 [task 2017-02-02T19:35:09.278595Z] 19:35:09 INFO - getAddon/<@resource://gre/modules/addons/XPIProvider.jsm -> resource://gre/modules/addons/XPIProviderUtils.js:1069:9 [task 2017-02-02T19:35:09.280807Z] 19:35:09 INFO - process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:922:23 [task 2017-02-02T19:35:09.284388Z] 19:35:09 INFO - walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:806:7 [task 2017-02-02T19:35:09.286428Z] 19:35:09 INFO - Promise*scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:739:11 [task 2017-02-02T19:35:09.290408Z] 19:35:09 INFO - schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:770:7 [task 2017-02-02T19:35:09.292738Z] 19:35:09 INFO - completePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:707:7 [task 2017-02-02T19:35:09.294571Z] 19:35:09 INFO - openSignedAppFileFinished@resource://gre/modules/addons/XPIProvider.jsm:1819:9 [task 2017-02-02T19:35:09.296255Z] 19:35:09 INFO - [task 2017-02-02T19:36:09.275682Z] 19:36:09 INFO - Not taking screenshot here: see the one that was previously logged [task 2017-02-02T19:36:09.279996Z] 19:36:09 INFO - TEST-UNEXPECTED-FAIL | browser/base/content/test/general/browser_offlineQuotaNotification.js | Test timed out - [task 2017-02-02T19:36:09.413046Z] 19:36:09 INFO - MEMORY STAT | vsize 986MB | residentFast 272MB | heapAllocated 113MB [task 2017-02-02T19:36:09.415917Z] 19:36:09 INFO - TEST-OK | browser/base/content/test/general/browser_offlineQuotaNotification.js | took 90244ms there isn't much here to help figure out the root cause. I do wonder about this message in there: Full message: TypeError: PopupNotifications.panel.firstElementChild is null this fails here in the code: https://dxr.mozilla.org/mozilla-central/source/browser/base/content/test/general/browser_offlineQuotaNotification.js?q=path%3Abrowser_offlineQuotaNotification.js&redirect_type=single#69 here is a screenshot from the failure: https://public-artifacts.taskcluster.net/AQzCDlD_ShCPeXzYcQrV9w/0/public/test_info//mozilla-test-fail-screenshot_lqgr3H.png :jaws, I see you did a lot of changes to this test over time, could you take a look at it or help find someone to look at it? [0] https://public-artifacts.taskcluster.net/AQzCDlD_ShCPeXzYcQrV9w/0/public/logs/live_backing.log
Flags: needinfo?(jaws)
Comment 4•7 years ago
|
||
my retriggers don't really point at a root cause, but I do suspect it is somewhere in this range: https://treeherder.mozilla.org/#/jobs?repo=autoland&filter-searchStr=linux%20opt%20browser-chrome-2&tochange=4e2d67e6ce3e81bc357e7c7992b35a2a9ccd9f49&fromchange=58967ce933159d16ac5825830782d670ce105d0e&selectedJob=75294950
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 7•7 years ago
|
||
checking in here :jaws, it has been a week since I pinged you, can we get this bug fixed this week, or shoul we consider disabling it until there are resources to work on this?
Comment hidden (mozreview-request) |
Comment 9•7 years ago
|
||
I need to figure out why it is randomly failing on e10s with the rewrite, and might not be able to come back to this for a few days. I attached my WIP here in case anyone wants to complete this. Leaving NI on to remind me to come back.
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 12•7 years ago
|
||
:jaws, checking back in here, it has been 10 days since last communication, have you had a chance to get back to this bug? should we disable this test on linux && !debug, until you have more time to work on it?
Comment 13•7 years ago
|
||
Yeah, we should disable on linux && !debug. Sorry for not getting back to it sooner.
Flags: needinfo?(jaws)
Comment 14•7 years ago
|
||
Attachment #8841018 -
Flags: review?(gbrown)
Updated•7 years ago
|
Keywords: leave-open
Whiteboard: [stockwell disabled]
Updated•7 years ago
|
Attachment #8841018 -
Flags: review?(gbrown) → review+
Comment hidden (Intermittent Failures Robot) |
Comment 16•7 years ago
|
||
Pushed by jmaher@mozilla.com: https://hg.mozilla.org/integration/mozilla-inbound/rev/7222bd7c4a20 Intermittent browser/base/content/test/general/browser_offlineQuotaNotification.js. disabled on linux opt/pgo. r=gbrown
Comment 17•7 years ago
|
||
bugherder |
https://hg.mozilla.org/mozilla-central/rev/7222bd7c4a20
Comment 18•7 years ago
|
||
uplift |
https://hg.mozilla.org/releases/mozilla-aurora/rev/f4dbb2f81e8c https://hg.mozilla.org/releases/mozilla-beta/rev/6c43b3dae2bb https://hg.mozilla.org/releases/mozilla-release/rev/6c43b3dae2bb https://hg.mozilla.org/releases/mozilla-esr52/rev/6c43b3dae2bb
status-firefox52:
--- → disabled
status-firefox53:
--- → disabled
status-firefox54:
--- → disabled
status-firefox-esr52:
--- → disabled
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Updated•5 years ago
|
Priority: -- → P5
Comment hidden (Intermittent Failures Robot) |
Updated•1 year ago
|
Severity: normal → S3
You need to log in
before you can comment on or make changes to this bug.
Description
•