Closed Bug 1740239 Opened 4 years ago Closed 4 years ago

Intermittent TEST-UNEXPECTED-TIMEOUT | /service-workers/cache-storage/serviceworker/cache-abort.https.html | Cache Storage: Abort - Test timed out | expected OK

Categories

(Core :: DOM: Service Workers, defect, P5)

Product:
Core
Component:
DOM: Service Workers
Type:
defect

Tracking

()

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

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

[task 2021-11-09T11:39:53.357Z] 11:39:53     INFO - TEST-START | /service-workers/cache-storage/serviceworker/cache-abort.https.html
[task 2021-11-09T11:39:53.385Z] 11:39:53     INFO - Setting pref javascript.options.streams (true)
[task 2021-11-09T11:39:53.394Z] 11:39:53     INFO - Setting pref dom.serviceWorkers.mitigations.bypass_on_fault (false)
[task 2021-11-09T11:39:53.411Z] 11:39:53     INFO - Setting pref dom.serviceWorkers.enabled (true)
[task 2021-11-09T11:39:53.430Z] 11:39:53     INFO - Setting pref dom.serviceWorkers.exemptFromPerDomainMax (true)
[task 2021-11-09T11:40:53.660Z] 11:40:53     INFO - 
[task 2021-11-09T11:40:53.660Z] 11:40:53     INFO - TEST-UNEXPECTED-TIMEOUT | /service-workers/cache-storage/serviceworker/cache-abort.https.html | Cache Storage: Abort - Test timed out
[task 2021-11-09T11:40:53.670Z] 11:40:53     INFO - TEST-UNEXPECTED-TIMEOUT | /service-workers/cache-storage/serviceworker/cache-abort.https.html | expected OK
[task 2021-11-09T11:40:53.670Z] 11:40:53     INFO - TEST-INFO took 60303ms
[task 2021-11-09T11:40:53.672Z] 11:40:53     INFO - PID 6632 | 1636458053671	Marionette	INFO	Stopped listening on port 50127
[task 2021-11-09T11:40:53.697Z] 11:40:53     INFO - PID 6632 | JavaScript error: resource://activity-stream/lib/ActivityStreamPrefs.jsm, line 27: NS_ERROR_ILLEGAL_VALUE: Component returned failure code: 0x80070057 (NS_ERROR_ILLEGAL_VALUE) [nsIPrefBranch.removeObserver]
[task 2021-11-09T11:41:03.865Z] 11:41:03     INFO - PID 6632 | WARNING: At least one completion condition is taking too long to complete. Conditions: [{"name":"Places Connection shutdown","state":{"PlacesShutdownProgress":5},"filename":"/builds/worker/checkouts/gecko/toolkit/components/places/Database.cpp","lineNumber":467,"stack":["resource://gre/modules/nsAsyncShutdown.jsm:addBlocker:162","resource://gre/modules/XPCOMUtils.jsm:XPCU_serviceLambda:161","resource://gre/modules/XPCOMUtils.jsm:get:62","resource:///modules/BrowserGlue.jsm:BG__onFirstWindowLoaded:1681","resource:///modules/BrowserGlue.jsm:BG_observe:997","chrome://browser/content/browser.js:_delayedStartup:2119"]},{"name":"Sqlite.jsm shutdown blocker","state":{"description":"Waiting for connections to close","state":[{"name":"protections.sqlite#0: waiting for shutdown","state":{"identifier":"protections.sqlite#0","isCloseRequested":false,"hasDbConn":true,"initiatedTransaction":false,"pendingStatements":1,"statementCounter":3},"filename":"resource://gre/modules/Sqlite.jsm","lineNumber":336,"stack":["resource://gre/modules/Sqlite.jsm:ConnectionData:336","resource://gre/modules/Sqlite.jsm:OpenedConnection:1408","resource://gre/modules/Sqlite.jsm:openConnection/</<:1195","resource://gre/modules/AsyncShutdown.jsm:observe:575"]}]},"filename":"resource://gre/modules/Sqlite.jsm","lineNumber":211,"stack":["resource://gre/modules/Sqlite.jsm:null:211","resource://gre/modules/XPCOMUtils.jsm:get:62","resource://gre/modules/Sqlite.jsm:ConnectionData:336","resource://gre/modules/Sqlite.jsm:OpenedConnection:1408","resource://gre/modules/Sqlite.jsm:openConnection/</<:1195"]},{"name":"Remote Settings profile-before-change","state":"Remaining: 7 callbacks (importJSONDump-main-anti-tracking-url-decoration-1, importJSONDump-main-hijack-blocklists-2, importJSONDump-main-search-telemetry-3, importJSONDump-main-search-config-4, importJSONDump-blocklists-gfx-5, importJSONDump-main-url-classifier-skip-urls-8, importJSONDump-main-doh-providers-11).","filename":"resource://services-settings/RemoteSettingsWorker.jsm","lineNumber":201,"stack":["resource://services-settings/RemoteSettingsWorker.jsm:null:201","resource://services-settings/RemoteSettingsClient.jsm:_importJSONDump:811","resource://services-settings/RemoteSettingsClient.jsm:get/this._importingPromise<:371","resource://services-settings/RemoteSettingsClient.jsm:get:380"]}] Barrier: profile-before-change
[task 2021-11-09T11:41:03.873Z] 11:41:03     INFO - PID 6632 | WARNING: At least one completion condition is taking too long to complete. Conditions: [{"name":"protections.sqlite#0: waiting for shutdown","state":{"identifier":"protections.sqlite#0","isCloseRequested":false,"hasDbConn":true,"initiatedTransaction":false,"pendingStatements":1,"statementCounter":3},"filename":"resource://gre/modules/Sqlite.jsm","lineNumber":336,"stack":["resource://gre/modules/Sqlite.jsm:ConnectionData:336","resource://gre/modules/Sqlite.jsm:OpenedConnection:1408","resource://gre/modules/Sqlite.jsm:openConnection/</<:1195","resource://gre/modules/AsyncShutdown.jsm:observe:575"]}] Barrier: Sqlite.jsm: wait until all connections are closed
[task 2021-11-09T11:41:08.717Z] 11:41:08     INFO - PID 6632 | console.error: (new Error("SessionFile is closed", "resource:///modules/sessionstore/SessionFile.jsm", 446))
[task 2021-11-09T11:41:19.899Z] 11:41:19     INFO - PID 6632 | console.log: "RemoteSettingsWorker error: Error: Can't import when we've started shutting down."
[task 2021-11-09T11:41:36.235Z] 11:41:36     INFO - PID 6632 | JavaScript error: resource://gre/modules/JSONFile.jsm, line 186: Error: Data is not ready.
[task 2021-11-09T11:41:38.256Z] 11:41:38     INFO - PID 6632 | console.log: "RemoteSettingsWorker error: Error: Can't import when we've started shutting down."
[task 2021-11-09T11:41:38.262Z] 11:41:38     INFO - PID 6632 | console.log: "RemoteSettingsWorker error: Error: Can't import when we've started shutting down."
[task 2021-11-09T11:41:38.265Z] 11:41:38     INFO - PID 6632 | console.log: "RemoteSettingsWorker error: Error: Can't import when we've started shutting down."
[task 2021-11-09T11:41:38.267Z] 11:41:38     INFO - PID 6632 | console.log: "RemoteSettingsWorker error: Error: Can't import when we've started shutting down."
[task 2021-11-09T11:41:38.269Z] 11:41:38     INFO - PID 6632 | console.log: "RemoteSettingsWorker error: Error: Can't import when we've started shutting down."
[task 2021-11-09T11:41:38.270Z] 11:41:38     INFO - PID 6632 | console.log: "RemoteSettingsWorker error: Error: Can't import when we've started shutting down."
[task 2021-11-09T11:41:38.283Z] 11:41:38     INFO - PID 6632 | console.error: "Could not load engine google@search.mozilla.org: [Exception... \"AddonManager is not initialized\"  nsresult: \"0xc1f30001 (NS_ERROR_NOT_INITIALIZED)\"  location: \"JS frame :: resource://gre/modules/AddonManager.jsm :: installBuiltinAddon :: line 2541\"  data: no]"
[task 2021-11-09T11:41:38.291Z] 11:41:38     INFO - PID 6632 | console.error: "Could not load engine amazondotcom@search.mozilla.org: [Exception... \"AddonManager is not initialized\"  nsresult: \"0xc1f30001 (NS_ERROR_NOT_INITIALIZED)\"  location: \"JS frame :: resource://gre/modules/AddonManager.jsm :: installBuiltinAddon :: line 2541\"  data: no]"
[task 2021-11-09T11:41:38.291Z] 11:41:38     INFO - PID 6632 | console.error: "Could not load engine wikipedia@search.mozilla.org: [Exception... \"AddonManager is not initialized\"  nsresult: \"0xc1f30001 (NS_ERROR_NOT_INITIALIZED)\"  location: \"JS frame :: resource://gre/modules/AddonManager.jsm :: installBuiltinAddon :: line 2541\"  data: no]"
[task 2021-11-09T11:41:38.292Z] 11:41:38     INFO - PID 6632 | console.error: "Could not load engine bing@search.mozilla.org: [Exception... \"AddonManager is not initialized\"  nsresult: \"0xc1f30001 (NS_ERROR_NOT_INITIALIZED)\"  location: \"JS frame :: resource://gre/modules/AddonManager.jsm :: installBuiltinAddon :: line 2541\"  data: no]"
[task 2021-11-09T11:41:38.293Z] 11:41:38     INFO - PID 6632 | console.error: "Could not load engine ddg@search.mozilla.org: [Exception... \"AddonManager is not initialized\"  nsresult: \"0xc1f30001 (NS_ERROR_NOT_INITIALIZED)\"  location: \"JS frame :: resource://gre/modules/AddonManager.jsm :: installBuiltinAddon :: line 2541\"  data: no]"
[task 2021-11-09T11:41:38.294Z] 11:41:38     INFO - PID 6632 | console.error: "Could not load engine ebay@search.mozilla.org: [Exception... \"AddonManager is not initialized\"  nsresult: \"0xc1f30001 (NS_ERROR_NOT_INITIALIZED)\"  location: \"JS frame :: resource://gre/modules/AddonManager.jsm :: installBuiltinAddon :: line 2541\"  data: no]"
[task 2021-11-09T11:41:38.294Z] 11:41:38     INFO - PID 6632 | console.warn: SearchService: "_init: abandoning init due to shutting down"
[task 2021-11-09T11:41:38.295Z] 11:41:38     INFO - PID 6632 | JavaScript error: , line 0: uncaught exception: 2147500036
[task 2021-11-09T11:41:38.295Z] 11:41:38     INFO - PID 6632 | JavaScript error: , line 0: uncaught exception: 2147500036
[task 2021-11-09T11:41:38.296Z] 11:41:38     INFO - PID 6632 | JavaScript error: , line 0: uncaught exception: 2147500036
[task 2021-11-09T11:41:38.296Z] 11:41:38     INFO - PID 6632 | JavaScript error: , line 0: uncaught exception: 2147500036
[task 2021-11-09T11:41:38.297Z] 11:41:38     INFO - PID 6632 | JavaScript error: , line 0: uncaught exception: 2147500036
[task 2021-11-09T11:41:38.297Z] 11:41:38     INFO - PID 6632 | JavaScript error: , line 0: uncaught exception: 2147500036
[task 2021-11-09T11:41:38.298Z] 11:41:38     INFO - PID 6632 | JavaScript error: , line 0: uncaught exception: 2147500036
[task 2021-11-09T11:41:38.298Z] 11:41:38     INFO - PID 6632 | JavaScript error: , line 0: uncaught exception: 2147500036
[task 2021-11-09T11:41:38.298Z] 11:41:38     INFO - PID 6632 | JavaScript error: , line 0: uncaught exception: 2147500036
[task 2021-11-09T11:41:38.299Z] 11:41:38     INFO - PID 6632 | JavaScript error: , line 0: uncaught exception: 2147500036
[task 2021-11-09T11:41:38.299Z] 11:41:38     INFO - PID 6632 | JavaScript error: , line 0: uncaught exception: 2147500036
[task 2021-11-09T11:41:38.300Z] 11:41:38     INFO - PID 6632 | JavaScript error: , line 0: uncaught exception: 2147500036
[task 2021-11-09T11:41:38.300Z] 11:41:38     INFO - PID 6632 | JavaScript error: , line 0: uncaught exception: 2147500036
[task 2021-11-09T11:41:38.301Z] 11:41:38     INFO - PID 6632 | JavaScript error: , line 0: uncaught exception: 2147500036
[task 2021-11-09T11:41:38.301Z] 11:41:38     INFO - PID 6632 | JavaScript error: , line 0: uncaught exception: 2147500036
[task 2021-11-09T11:41:38.302Z] 11:41:38     INFO - PID 6632 | JavaScript error: resource://gre/modules/AsyncShutdown.jsm, line 718: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "DoHController: clear state and remove observers"
[task 2021-11-09T11:41:53.738Z] 11:41:53     INFO - PID 6632 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-11-09T11:41:53.801Z] 11:41:53     INFO - Browser exited with return code 0
[task 2021-11-09T11:41:53.805Z] 11:41:53     INFO - Closing logging queue
[task 2021-11-09T11:41:53.806Z] 11:41:53     INFO - queue closed
[task 2021-11-09T11:42:03.773Z] 11:42:03     INFO - Application command: Z:\task_163645496480021\build\application\firefox\firefox.exe -marionette about:blank --wait-for-browser -profile C:\Users\task_163645496480021\AppData\Local\Temp\tmp60i60iwy
[task 2021-11-09T11:42:03.786Z] 11:42:03     INFO - Starting runner
[task 2021-11-09T11:42:07.191Z] 11:42:07     INFO - PID 8712 | 1636458127192	Marionette	INFO	Marionette enabled
[task 2021-11-09T11:42:22.365Z] 11:42:22     INFO - PID 8712 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at C:\\Users\\task_163645496480021\\AppData\\Local\\Temp\\tmp60i60iwy\\search.json.mozlz4", (void 0)))
[task 2021-11-09T11:42:24.843Z] 11:42:24     INFO - PID 8712 | 1636458144847	Marionette	INFO	Listening on port 50181
[task 2021-11-09T11:43:06.380Z] 11:43:06     INFO - Browser exited with return code 572
[task 2021-11-09T11:43:16.395Z] 11:43:16  WARNING - Forcibly terminating runner process
[task 2021-11-09T11:43:19.422Z] 11:43:19     INFO - Application command: Z:\task_163645496480021\build\application\firefox\firefox.exe -marionette about:blank --wait-for-browser -profile C:\Users\task_163645496480021\AppData\Local\Temp\tmp24s4djtn
[task 2021-11-09T11:43:19.434Z] 11:43:19     INFO - Starting runner
[task 2021-11-09T11:43:20.949Z] 11:43:20     INFO - PID 6264 | 1636458200948	Marionette	INFO	Marionette enabled
[task 2021-11-09T11:43:30.111Z] 11:43:30     INFO - PID 6264 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at C:\\Users\\task_163645496480021\\AppData\\Local\\Temp\\tmp24s4djtn\\search.json.mozlz4", (void 0)))
[task 2021-11-09T11:43:32.931Z] 11:43:32     INFO - PID 6264 | 1636458212942	Marionette	INFO	Listening on port 50230
[task 2021-11-09T11:43:47.958Z] 11:43:47     INFO - TEST-START | /service-workers/cache-storage/serviceworker/cache-add.https.html

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.