Intermittent TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/delete_all_cookies/user_prompts.py | expected OK
Categories
(Remote Protocol :: Marionette, defect, P5)
Tracking
(Not tracked)
People
(Reporter: intermittent-bug-filer, Unassigned)
References
(Depends on 1 open bug)
Details
(Keywords: intermittent-failure)
Filed by: dvarga [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=294729677&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/ZlW_A_4yScORpOwmUsIiSw/runs/0/artifacts/public/logs/live_backing.log
[task 2020-03-25T18:31:38.660Z] 18:31:38 INFO - PID 3583 | WARNING: At least one completion condition is taking too long to complete. Conditions: [{"name":"RemoteSettingsClient - finish IDB access.","state":[{"method":"getLastModified","identifier":"main/fxmonitor-breaches"},{"method":"getLastModified","identifier":"blocklists/gfx"},{"method":"getLastModified","identifier":"main/url-classifier-skip-urls"},{"method":"getLastModified","identifier":"main/url-classifier-skip-urls"},{"method":"getLastModified","identifier":"main/url-classifier-skip-urls"},{"method":"getLastModified","identifier":"main/url-classifier-skip-urls"},{"method":"getLastModified","identifier":"main/url-classifier-skip-urls"},{"method":"getLastModified","identifier":"main/url-classifier-skip-urls"},{"method":"getLastModified","identifier":"main/url-classifier-skip-urls"}],"filename":"resource://services-settings/Database.jsm","lineNumber":509,"stack":["resource://services-settings/Database.jsm:ensureShutdownBlocker:509","resource://services-settings/Database.jsm:Database:442","resource://services-settings/RemoteSettingsClient.jsm:RemoteSettingsClient/<:239","resource://gre/modules/XPCOMUtils.jsm:get:129","resource://services-settings/Utils.jsm:hasLocalData:98","resource://services-settings/RemoteSettingsClient.jsm:get:309","resource://gre/modules/Blocklist.jsm:_updateEntries:1078","resource://gre/modules/Blocklist.jsm:_ensureEntries:1069","resource://gre/modules/Blocklist.jsm:getEntry:1229","resource://gre/modules/Blocklist.jsm:getAddonBlocklistEntry:1460","resource://gre/modules/addons/XPIDatabase.jsm:findBlocklistEntry:566","resource://gre/modules/addons/XPIDatabase.jsm:updateBlocklistState:574","resource://gre/modules/addons/XPIInstall.jsm:loadManifest:709"]},{"name":"Remote Settings profile-before-change","state":"Remaining: 1 callbacks (importJSONDump-3).","filename":"resource://services-settings/RemoteSettingsWorker.jsm","lineNumber":147,"stack":["resource://services-settings/RemoteSettingsWorker.jsm:null:147","resource://services-settings/RemoteSettingsClient.jsm:_importJSONDump:691","resource://services-settings/RemoteSettingsClient.jsm:get:316"]}] Barrier: profile-before-change
[task 2020-03-25T18:31:43.027Z] 18:31:43 INFO - PID 3583 | JavaScript error: resource://services-common/kinto-offline-client.js, line 505: AbortError: IndexedDB saveLastModified() A request was aborted, for example through a call to IDBTransaction.abort.
[task 2020-03-25T18:31:46.022Z] 18:31:46 INFO - PID 3583 | 1585161106019 Marionette TRACE Received observer notification xpcom-will-shutdown
[task 2020-03-25T18:31:46.025Z] 18:31:46 INFO - PID 3583 | 1585161106019 Marionette DEBUG Resetting recommended pref apz.content_response_timeout
[task 2020-03-25T18:31:46.025Z] 18:31:46 INFO - PID 3583 | 1585161106019 Marionette DEBUG Resetting recommended pref browser.contentblocking.introCount
[task 2020-03-25T18:31:46.027Z] 18:31:46 INFO - PID 3583 | 1585161106019 Marionette DEBUG Resetting recommended pref browser.download.panel.shown
[task 2020-03-25T18:31:46.028Z] 18:31:46 INFO - PID 3583 | 1585161106019 Marionette DEBUG Resetting recommended pref browser.newtabpage.enabled
[task 2020-03-25T18:31:46.029Z] 18:31:46 INFO - PID 3583 | 1585161106020 Marionette DEBUG Resetting recommended pref browser.pagethumbnails.capturing_disabled
[task 2020-03-25T18:31:46.031Z] 18:31:46 INFO - PID 3583 | 1585161106020 Marionette DEBUG Resetting recommended pref browser.search.update
[task 2020-03-25T18:31:46.032Z] 18:31:46 INFO - PID 3583 | 1585161106020 Marionette DEBUG Resetting recommended pref browser.tabs.disableBackgroundZombification
[task 2020-03-25T18:31:46.037Z] 18:31:46 INFO - PID 3583 | 1585161106020 Marionette DEBUG Resetting recommended pref browser.tabs.remote.separatePrivilegedContentProcess
[task 2020-03-25T18:31:46.038Z] 18:31:46 INFO - PID 3583 | 1585161106020 Marionette DEBUG Resetting recommended pref browser.tabs.unloadOnLowMemory
[task 2020-03-25T18:31:46.039Z] 18:31:46 INFO - PID 3583 | 1585161106020 Marionette DEBUG Resetting recommended pref browser.tabs.warnOnCloseOtherTabs
[task 2020-03-25T18:31:46.040Z] 18:31:46 INFO - PID 3583 | 1585161106020 Marionette DEBUG Resetting recommended pref browser.tabs.warnOnOpen
[task 2020-03-25T18:31:46.044Z] 18:31:46 INFO - PID 3583 | 1585161106020 Marionette DEBUG Resetting recommended pref browser.usedOnWindows10.introURL
[task 2020-03-25T18:31:46.045Z] 18:31:46 INFO - PID 3583 | 1585161106020 Marionette DEBUG Resetting recommended pref browser.urlbar.suggest.searches
[task 2020-03-25T18:31:46.045Z] 18:31:46 INFO - PID 3583 | 1585161106021 Marionette DEBUG Resetting recommended pref datareporting.policy.dataSubmissionPolicyAccepted
[task 2020-03-25T18:31:46.046Z] 18:31:46 INFO - PID 3583 | 1585161106021 Marionette DEBUG Resetting recommended pref dom.disable_beforeunload
[task 2020-03-25T18:31:46.046Z] 18:31:46 INFO - PID 3583 | 1585161106021 Marionette DEBUG Resetting recommended pref dom.disable_open_during_load
[task 2020-03-25T18:31:46.046Z] 18:31:46 INFO - PID 3583 | 1585161106021 Marionette DEBUG Resetting recommended pref dom.file.createInChild
[task 2020-03-25T18:31:46.047Z] 18:31:46 INFO - PID 3583 | 1585161106021 Marionette DEBUG Resetting recommended pref dom.max_chrome_script_run_time
[task 2020-03-25T18:31:46.047Z] 18:31:46 INFO - PID 3583 | 1585161106022 Marionette DEBUG Resetting recommended pref dom.max_script_run_time
[task 2020-03-25T18:31:46.049Z] 18:31:46 INFO - PID 3583 | 1585161106022 Marionette DEBUG Resetting recommended pref dom.push.connection.enabled
[task 2020-03-25T18:31:46.049Z] 18:31:46 INFO - PID 3583 | 1585161106022 Marionette DEBUG Resetting recommended pref extensions.getAddons.cache.enabled
[task 2020-03-25T18:31:46.049Z] 18:31:46 INFO - PID 3583 | 1585161106022 Marionette DEBUG Resetting recommended pref extensions.webservice.discoverURL
[task 2020-03-25T18:31:46.049Z] 18:31:46 INFO - PID 3583 | 1585161106022 Marionette DEBUG Resetting recommended pref network.http.prompt-temp-redirect
[task 2020-03-25T18:31:46.049Z] 18:31:46 INFO - PID 3583 | 1585161106023 Marionette DEBUG Resetting recommended pref network.http.speculative-parallel-limit
[task 2020-03-25T18:31:46.049Z] 18:31:46 INFO - PID 3583 | 1585161106023 Marionette DEBUG Resetting recommended pref privacy.trackingprotection.enabled
[task 2020-03-25T18:31:46.052Z] 18:31:46 INFO - PID 3583 | 1585161106024 Marionette DEBUG Resetting recommended pref security.fileuri.strict_origin_policy
[task 2020-03-25T18:31:46.055Z] 18:31:46 INFO - PID 3583 | 1585161106024 Marionette DEBUG Resetting recommended pref security.notification_enable_delay
[task 2020-03-25T18:31:46.056Z] 18:31:46 INFO - PID 3583 | 1585161106024 Marionette DEBUG Resetting recommended pref signon.autofillForms
[task 2020-03-25T18:31:46.057Z] 18:31:46 INFO - PID 3583 | 1585161106026 Marionette DEBUG Resetting recommended pref signon.rememberSignons
[task 2020-03-25T18:31:46.058Z] 18:31:46 INFO - PID 3583 | 1585161106026 Marionette DEBUG Resetting recommended pref toolkit.cosmeticAnimations.enabled
[task 2020-03-25T18:31:46.059Z] 18:31:46 INFO - PID 3583 | 1585161106027 Marionette DEBUG Marionette stopped listening
[task 2020-03-25T18:31:46.059Z] 18:31:46 INFO - PID 3583 |
[task 2020-03-25T18:31:46.060Z] 18:31:46 INFO - PID 3583 | ###!!! [Child][MessageChannel] Error: (msgtype=0xB80016,name=PWindowGlobal::Msg_Destroy) Channel closing: too late to send/recv, messages will be lost
[task 2020-03-25T18:31:46.061Z] 18:31:46 INFO - PID 3583 |
[task 2020-03-25T18:31:46.137Z] 18:31:46 INFO - PID 3583 | 1585161106129 geckodriver::marionette DEBUG Browser process stopped: exit code: 0
[task 2020-03-25T18:31:46.141Z] 18:31:46 INFO - PID 3583 | 1585161106137 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2020-03-25T18:31:46.157Z] 18:31:46 INFO - PID 3583 | 1585161106138 webdriver::server DEBUG -> POST /session {"capabilities": {"alwaysMatch": {"moz:firefoxOptions": {"binary": "/builds/worker/workspace/build/application/firefox/firefox", "prefs": {"media.peerconnection.mtransport_process": false, "network.dns.localDomains": "www1.xn--n8j6ds53lwwkrqhv28a.web-platform.test,op88.web-platform.test,op36.not-web-platform.test,op53.not-web-platform.test,op50.not-web-platform.test,xn--lve-6lad.www.web-platform.test,op98.web-platform.test,op24.not-web-platform.test,op31.not-web-platform.test,op95.not-web-platform.test,op85.web-platform.test,op83.not-web-platform.test,www2.not-web-platform.test,xn--lve-6lad.www.not-web-platform.test,op73.not-web-platform.test,op8.web-platform.test,www2.www2.not-web-platform.test,op89.web-platform.test,op66.web-platform.test,xn--lve-6lad.web-platform.test,op19.not-web-platform.test,www1.www2.web-platform.test,op72.web-platform.test,op24.web-platform.test,op21.not-web-platform.test,xn--lve-6lad.not-web-platform.test,op41.web-platform.test,op79.web-platform.test,op81.not-web-platform.test,op70.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.xn--lve-6lad.not-web-platform.test,op78.not-web-platform.test,op6.not-web-platform.test,www1.www.not-web-platform.test,op40.not-web-platform.test,op25.not-web-platform.test,op3.not-web-platform.test,op65.not-web-platform.test,op91.web-platform.test,www.www2.web-platform.test,op80.not-web-platform.test,op59.web-platform.test,op52.not-web-platform.test,xn--lve-6lad.xn--lve-6lad.web-platform.test,op68.not-web-platform.test,op45.not-web-platform.test,op71.not-web-platform.test,op72.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.www2.web-platform.test,op39.web-platform.test,op90.not-web-platform.test,op60.web-platform.test,op58.web-platform.test,op28.web-platform.test,www1.web-platform.test,xn--n8j6ds53lwwkrqhv28a.xn--lve-6lad.web-platform.test,op14.web-platform.test,op89.not-web-platform.test,op69.web-platform.test,op49.not-web-platform.test,op40.web-platform.test,op2.not-web-platform.test,op5.not-web-platform.test,www.www2.not-web-platform.test,op77.not-web-platform.test,www.xn--n8j6ds53lwwkrqhv28a.web-platform.test,op7.web-platform.test,op74.web-platform.test,op79.not-web-platform.test,op82.not-web-platform.test,www.www1.web-platform.test,op12.not-web-platform.test,op39.not-web-platform.test,op31.web-platform.test,www.not-web-platform.test,www.www.not-web-platform.test,op44.not-web-platform.test,www1.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.www1.web-platform.test,op58.not-web-platform.test,op14.not-web-platform.test,op30.not-web-platform.test,op62.not-web-platform.test,op61.not-web-platform.test,op92.not-web-platform.test,www2.xn--lve-6lad.web-platform.test,op29.not-web-platform.test,op18.web-platform.test,op73.web-platform.test,xn--n8j6ds53lwwkrqhv28a.xn--n8j6ds53lwwkrqhv28a.web-platform.test,op77.web-platform.test,op12.web-platform.test,op54.web-platform.test,op63.web-platform.test,op71.web-platform.test,www2.www1.not-web-platform.test,op95.web-platform.test,op16.web-platform.test,op36.web-platform.test,op27.web-platform.test,www.www.web-platform.test,op98.not-web-platform.test,op64.not-web-platform.test,op29.web-platform.test,op9.web-platform.test,op26.not-web-platform.test,op22.not-web-platform.test,op94.web-platform.test,xn--n8j6ds53lwwkrqhv28a.www2.not-web-platform.test,op44.web-platform.test,op94.not-web-platform.test,op33.web-platform.test,op38.not-web-platform.test,op33.not-web-platform.test,op84.web-platform.test,www1.www1.not-web-platform.test,op23.not-web-platform.test,op57.not-web-platform.test,op54.not-web-platform.test,op85.not-web-platform.test,www2.www2.web-platform.test,op46.not-web-platform.test,op97.not-web-platform.test,op32.web-platform.test,op61.web-platform.test,op70.web-platform.test,www2.web-platform.test,op32.not-web-platform.test,op60.not-web-platform.test,op4.web-platform.test,op43.web-platform.test,op7.not-web-platform.test,op78.web-platform.test,op26.web-platform.test,xn--lve-6lad.xn--n8j6ds53lwwkrqhv28a.web-platform.test,op96.not-web-platform.test,op51.not-web-platform.test,op41.not-web-platform.test,op76.web-platform.test,op52.web-platform.test,op99.web-platform.test,op35.not-web-platform.test,op99.not-web-platform.test,op86.web-platform.test,not-web-platform.test,op42.not-web-platform.test,op46.web-platform.test,op67.not-web-platform.test,op17.web-platform.test,op90.web-platform.test,op93.web-platform.test,op37.not-web-platform.test,op48.not-web-platform.test,op10.web-platform.test,op55.not-web-platform.test,op4.not-web-platform.test,www1.xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,op55.web-platform.test,xn--lve-6lad.www2.web-platform.test,op47.web-platform.test,op51.web-platform.test,op45.web-platform.test,op80.web-platform.test,op68.web-platform.test,op49.web-platform.test,op57.web-platform.test,www2.xn--n8j6ds53lwwkrqhv28a.web-platform.test,www.xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,op56.not-web-platform.test,web-platform.test,op84.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,xn--lve-6lad.xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,op34.not-web-platform.test,op6.web-platform.test,op35.web-platform.test,op67.web-platform.test,op69.not-web-platform.test,op11.not-web-platform.test,op93.not-web-platform.test,www1.www.web-platform.test,op86.not-web-platform.test,op8.not-web-platform.test,www2.xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,op92.web-platform.test,xn--lve-6lad.www1.not-web-platform.test,op15.web-platform.test,op13.not-web-platform.test,op13.web-platform.test,xn--n8j6ds53lwwkrqhv28a.web-platform.test,xn--n8j6ds53lwwkrqhv28a.www.web-platform.test,op75.web-platform.test,op20.not-web-platform.test,op76.not-web-platform.test,op64.web-platform.test,op97.web-platform.test,op37.web-platform.test,op56.web-platform.test,op62.web-platform.test,op82.web-platform.test,op25.web-platform.test,op11.web-platform.test,www.xn--lve-6lad.not-web-platform.test,www2.www1.web-platform.test,op27.not-web-platform.test,op50.web-platform.test,op17.not-web-platform.test,op38.web-platform.test,www2.www.not-web-platform.test,xn--lve-6lad.www1.web-platform.test,op75.not-web-platform.test,op83.web-platform.test,op81.web-platform.test,op15.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.www.not-web-platform.test,op20.web-platform.test,op3.web-platform.test,www1.www2.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,op2.web-platform.test,op21.web-platform.test,op23.web-platform.test,op42.web-platform.test,op47.not-web-platform.test,www1.www1.web-platform.test,op18.not-web-platform.test,op22.web-platform.test,xn--lve-6lad.xn--lve-6lad.not-web-platform.test,op63.not-web-platform.test,op28.not-web-platform.test,op65.web-platform.test,www.www1.not-web-platform.test,www1.xn--lve-6lad.web-platform.test,op43.not-web-platform.test,op66.not-web-platform.test,www2.www.web-platform.test,op96.web-platform.test,op91.not-web-platform.test,www.xn--lve-6lad.web-platform.test,op1.web-platform.test,op74.not-web-platform.test,op87.web-platform.test,op59.not-web-platform.test,op19.web-platform.test,xn--n8j6ds53lwwkrqhv28a.www1.not-web-platform.test,op9.not-web-platform.test,op88.not-web-platform.test,op53.web-platform.test,www2.xn--lve-6lad.not-web-platform.test,op87.not-web-platform.test,op30.web-platform.test,op10.not-web-platform.test,op48.web-platform.test,op16.not-web-platform.test,op34.web-platform.test,op1.not-web-platform.test,www.web-platform.test,op5.web-platform.test,www1.xn--lve-6lad.not-web-platform.test,xn--lve-6lad.www2.not-web-platform.test", "network.process.enabled": false}}, "unhandledPromptBehavior": "dismiss and notify"}}}
[task 2020-03-25T18:31:46.159Z] 18:31:46 INFO - PID 3583 | 1585161106141 mozrunner::runner INFO Running command: "/builds/worker/workspace/build/application/firefox/firefox" "-marionette" "-foreground" "-no-remote" "-profile" "/tmp/rust_mozprofileO2JJVP"
[task 2020-03-25T18:31:46.159Z] 18:31:46 INFO - PID 3583 | 1585161106141 geckodriver::marionette DEBUG Waiting 60s to connect to browser on 127.0.0.1:2828
[task 2020-03-25T18:31:50.661Z] 18:31:50 INFO - PID 3583 | 1585161110657 addons.webextension.doh-rollout@mozilla.org WARN Loading extension 'doh-rollout@mozilla.org': Reading manifest: Invalid extension permission: networkStatus
[task 2020-03-25T18:32:06.399Z] 18:32:06 INFO - TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/delete_all_cookies/user_prompts.py | expected OK
[task 2020-03-25T18:32:06.399Z] 18:32:06 INFO - TEST-INFO took 185003ms
[task 2020-03-25T18:32:06.664Z] 18:32:06 INFO - Closing logging queue
[task 2020-03-25T18:32:06.664Z] 18:32:06 INFO - queue closed
[task 2020-03-25T18:32:06.667Z] 18:32:06 INFO - Starting runner
[task 2020-03-25T18:32:06.687Z] 18:32:06 INFO - PID 5079 | 1585161126684 geckodriver DEBUG Listening on 127.0.0.1:55047
[task 2020-03-25T18:32:07.190Z] 18:32:07 INFO - WebDriver HTTP server listening at http://127.0.0.1:55047/
[task 2020-03-25T18:32:07.191Z] 18:32:07 INFO - TEST-START | /webdriver/tests/delete_session/delete.py
[task 2020-03-25T18:32:07.429Z] 18:32:07 INFO - STDOUT: ============================= test session starts ==============================
[task 2020-03-25T18:32:07.430Z] 18:32:07 INFO - STDOUT: platform linux2 -- Python 2.7.17, pytest-unknown, py-1.5.2, pluggy-0.5.3.dev -- /builds/worker/workspace/build/venv/bin/python
[task 2020-03-25T18:32:07.430Z] 18:32:07 INFO - STDOUT: rootdir: /builds/worker/workspace/build, inifile:
[task 2020-03-25T18:32:07.430Z] 18:32:07 INFO - STDOUT: collecting ...
[task 2020-03-25T18:32:09.725Z] 18:32:09 INFO - STDOUT: collected 2 items
[task 2020-03-25T18:32:09.726Z] 18:32:09 INFO - STDOUT: tests/web-platform/tests/webdriver/tests/delete_session/delete.py::test_null_response_value
[task 2020-03-25T18:32:09.744Z] 18:32:09 INFO - PID 5079 | 1585161129725 webdriver::server DEBUG -> POST /session {"capabilities": {"alwaysMatch": {"moz:firefoxOptions": {"binary": "/builds/worker/workspace/build/application/firefox/firefox", "prefs": {"media.peerconnection.mtransport_process": false, "network.dns.localDomains": "www1.xn--n8j6ds53lwwkrqhv28a.web-platform.test,op88.web-platform.test,op36.not-web-platform.test,op53.not-web-platform.test,op50.not-web-platform.test,xn--lve-6lad.www.web-platform.test,op98.web-platform.test,op24.not-web-platform.test,op31.not-web-platform.test,op95.not-web-platform.test,op85.web-platform.test,op83.not-web-platform.test,www2.not-web-platform.test,xn--lve-6lad.www.not-web-platform.test,op73.not-web-platform.test,op8.web-platform.test,www2.www2.not-web-platform.test,op89.web-platform.test,op66.web-platform.test,xn--lve-6lad.web-platform.test,op19.not-web-platform.test,www1.www2.web-platform.test,op72.web-platform.test,op24.web-platform.test,op21.not-web-platform.test,xn--lve-6lad.not-web-platform.test,op41.web-platform.test,op79.web-platform.test,op81.not-web-platform.test,op70.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.xn--lve-6lad.not-web-platform.test,op78.not-web-platform.test,op6.not-web-platform.test,www1.www.not-web-platform.test,op40.not-web-platform.test,op25.not-web-platform.test,op3.not-web-platform.test,op65.not-web-platform.test,op91.web-platform.test,www.www2.web-platform.test,op80.not-web-platform.test,op59.web-platform.test,op52.not-web-platform.test,xn--lve-6lad.xn--lve-6lad.web-platform.test,op68.not-web-platform.test,op45.not-web-platform.test,op71.not-web-platform.test,op72.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.www2.web-platform.test,op39.web-platform.test,op90.not-web-platform.test,op60.web-platform.test,op58.web-platform.test,op28.web-platform.test,www1.web-platform.test,xn--n8j6ds53lwwkrqhv28a.xn--lve-6lad.web-platform.test,op14.web-platform.test,op89.not-web-platform.test,op69.web-platform.test,op49.not-web-platform.test,op40.web-platform.test,op2.not-web-platform.test,op5.not-web-platform.test,www.www2.not-web-platform.test,op77.not-web-platform.test,www.xn--n8j6ds53lwwkrqhv28a.web-platform.test,op7.web-platform.test,op74.web-platform.test,op79.not-web-platform.test,op82.not-web-platform.test,www.www1.web-platform.test,op12.not-web-platform.test,op39.not-web-platform.test,op31.web-platform.test,www.not-web-platform.test,www.www.not-web-platform.test,op44.not-web-platform.test,www1.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.www1.web-platform.test,op58.not-web-platform.test,op14.not-web-platform.test,op30.not-web-platform.test,op62.not-web-platform.test,op61.not-web-platform.test,op92.not-web-platform.test,www2.xn--lve-6lad.web-platform.test,op29.not-web-platform.test,op18.web-platform.test,op73.web-platform.test,xn--n8j6ds53lwwkrqhv28a.xn--n8j6ds53lwwkrqhv28a.web-platform.test,op77.web-platform.test,op12.web-platform.test,op54.web-platform.test,op63.web-platform.test,op71.web-platform.test,www2.www1.not-web-platform.test,op95.web-platform.test,op16.web-platform.test,op36.web-platform.test,op27.web-platform.test,www.www.web-platform.test,op98.not-web-platform.test,op64.not-web-platform.test,op29.web-platform.test,op9.web-platform.test,op26.not-web-platform.test,op22.not-web-platform.test,op94.web-platform.test,xn--n8j6ds53lwwkrqhv28a.www2.not-web-platform.test,op44.web-platform.test,op94.not-web-platform.test,op33.web-platform.test,op38.not-web-platform.test,op33.not-web-platform.test,op84.web-platform.test,www1.www1.not-web-platform.test,op23.not-web-platform.test,op57.not-web-platform.test,op54.not-web-platform.test,op85.not-web-platform.test,www2.www2.web-platform.test,op46.not-web-platform.test,op97.not-web-platform.test,op32.web-platform.test,op61.web-platform.test,op70.web-platform.test,www2.web-platform.test,op32.not-web-platform.test,op60.not-web-platform.test,op4.web-platform.test,op43.web-platform.test,op7.not-web-platform.test,op78.web-platform.test,op26.web-platform.test,xn--lve-6lad.xn--n8j6ds53lwwkrqhv28a.web-platform.test,op96.not-web-platform.test,op51.not-web-platform.test,op41.not-web-platform.test,op76.web-platform.test,op52.web-platform.test,op99.web-platform.test,op35.not-web-platform.test,op99.not-web-platform.test,op86.web-platform.test,not-web-platform.test,op42.not-web-platform.test,op46.web-platform.test,op67.not-web-platform.test,op17.web-platform.test,op90.web-platform.test,op93.web-platform.test,op37.not-web-platform.test,op48.not-web-platform.test,op10.web-platform.test,op55.not-web-platform.test,op4.not-web-platform.test,www1.xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,op55.web-platform.test,xn--lve-6lad.www2.web-platform.test,op47.web-platform.test,op51.web-platform.test,op45.web-platform.test,op80.web-platform.test,op68.web-platform.test,op49.web-platform.test,op57.web-platform.test,www2.xn--n8j6ds53lwwkrqhv28a.web-platform.test,www.xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,op56.not-web-platform.test,web-platform.test,op84.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,xn--lve-6lad.xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,op34.not-web-platform.test,op6.web-platform.test,op35.web-platform.test,op67.web-platform.test,op69.not-web-platform.test,op11.not-web-platform.test,op93.not-web-platform.test,www1.www.web-platform.test,op86.not-web-platform.test,op8.not-web-platform.test,www2.xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,op92.web-platform.test,xn--lve-6lad.www1.not-web-platform.test,op15.web-platform.test,op13.not-web-platform.test,op13.web-platform.test,xn--n8j6ds53lwwkrqhv28a.web-platform.test,xn--n8j6ds53lwwkrqhv28a.www.web-platform.test,op75.web-platform.test,op20.not-web-platform.test,op76.not-web-platform.test,op64.web-platform.test,op97.web-platform.test,op37.web-platform.test,op56.web-platform.test,op62.web-platform.test,op82.web-platform.test,op25.web-platform.test,op11.web-platform.test,www.xn--lve-6lad.not-web-platform.test,www2.www1.web-platform.test,op27.not-web-platform.test,op50.web-platform.test,op17.not-web-platform.test,op38.web-platform.test,www2.www.not-web-platform.test,xn--lve-6lad.www1.web-platform.test,op75.not-web-platform.test,op83.web-platform.test,op81.web-platform.test,op15.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.www.not-web-platform.test,op20.web-platform.test,op3.web-platform.test,www1.www2.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,op2.web-platform.test,op21.web-platform.test,op23.web-platform.test,op42.web-platform.test,op47.not-web-platform.test,www1.www1.web-platform.test,op18.not-web-platform.test,op22.web-platform.test,xn--lve-6lad.xn--lve-6lad.not-web-platform.test,op63.not-web-platform.test,op28.not-web-platform.test,op65.web-platform.test,www.www1.not-web-platform.test,www1.xn--lve-6lad.web-platform.test,op43.not-web-platform.test,op66.not-web-platform.test,www2.www.web-platform.test,op96.web-platform.test,op91.not-web-platform.test,www.xn--lve-6lad.web-platform.test,op1.web-platform.test,op74.not-web-platform.test,op87.web-platform.test,op59.not-web-platform.test,op19.web-platform.test,xn--n8j6ds53lwwkrqhv28a.www1.not-web-platform.test,op9.not-web-platform.test,op88.not-web-platform.test,op53.web-platform.test,www2.xn--lve-6lad.not-web-platform.test,op87.not-web-platform.test,op30.web-platform.test,op10.not-web-platform.test,op48.web-platform.test,op16.not-web-platform.test,op34.web-platform.test,op1.not-web-platform.test,www.web-platform.test,op5.web-platform.test,www1.xn--lve-6lad.not-web-platform.test,xn--lve-6lad.www2.not-web-platform.test", "network.process.enabled": false}}}}}
Comment 1•4 years ago
|
||
The underlying reason here is:
[task 2020-03-25T18:31:37.415Z] 18:31:37 INFO - PID 3583 | console.error: (new Error("SessionFile is closed", "resource:///modules/sessionstore/SessionFile.jsm", 433))
[task 2020-03-25T18:31:38.660Z] 18:31:38 INFO - PID 3583 | WARNING: At least one completion condition is taking too long to complete. Conditions: [{"name":"RemoteSettingsClient - finish IDB access.","state":[{"method":"getLastModified","identifier":"main/fxmonitor-breaches"},{"method":"getLastModified","identifier":"blocklists/gfx"},{"method":"getLastModified","identifier":"main/url-classifier-skip-urls"},{"method":"getLastModified","identifier":"main/url-classifier-skip-urls"},{"method":"getLastModified","identifier":"main/url-classifier-skip-urls"},{"method":"getLastModified","identifier":"main/url-classifier-skip-urls"},{"method":"getLastModified","identifier":"main/url-classifier-skip-urls"},{"method":"getLastModified","identifier":"main/url-classifier-skip-urls"},{"method":"getLastModified","identifier":"main/url-classifier-skip-urls"}],"filename":"resource://services-settings/Database.jsm","lineNumber":509,"stack":["resource://services-settings/Database.jsm:ensureShutdownBlocker:509","resource://services-settings/Database.jsm:Database:442","resource://services-settings/RemoteSettingsClient.jsm:RemoteSettingsClient/<:239","resource://gre/modules/XPCOMUtils.jsm:get:129","resource://services-settings/Utils.jsm:hasLocalData:98","resource://services-settings/RemoteSettingsClient.jsm:get:309","resource://gre/modules/Blocklist.jsm:_updateEntries:1078","resource://gre/modules/Blocklist.jsm:_ensureEntries:1069","resource://gre/modules/Blocklist.jsm:getEntry:1229","resource://gre/modules/Blocklist.jsm:getAddonBlocklistEntry:1460","resource://gre/modules/addons/XPIDatabase.jsm:findBlocklistEntry:566","resource://gre/modules/addons/XPIDatabase.jsm:updateBlocklistState:574","resource://gre/modules/addons/XPIInstall.jsm:loadManifest:709"]},{"name":"Remote Settings profile-before-change","state":"Remaining: 1 callbacks (importJSONDump-3).","filename":"resource://services-settings/RemoteSettingsWorker.jsm","lineNumber":147,"stack":["resource://services-settings/RemoteSettingsWorker.jsm:null:147","resource://services-settings/RemoteSettingsClient.jsm:_importJSONDump:691","resource://services-settings/RemoteSettingsClient.jsm:get:316"]}] Barrier: profile-before-change
[task 2020-03-25T18:31:43.027Z] 18:31:43 INFO - PID 3583 | JavaScript error: resource://services-common/kinto-offline-client.js, line 505: AbortError: IndexedDB saveLastModified() A request was aborted, for example through a call to IDBTransaction.abort.
Could this be caused by the UrlClassifierListManager.jsm? Andrew, and Dimi, any idea?
Comment 2•4 years ago
|
||
(In reply to Henrik Skupin (:whimboo) [⌚️UTC+1] from comment #1)
Could this be caused by the UrlClassifierListManager.jsm? Andrew, and Dimi, any idea?
I guess not, I think the error shouldn't affect the result of the test (Although I should still be able to provide a patch to fix that error).
You can also see that the error occur all over the log, even between tests that succeed.
I am not familiar with this test, but from the log, it looks like it can't finish all the testcases in it before the timeout.
Comment 3•4 years ago
|
||
The problem with the test is that it times out due to the long shutdown delays of Firefox. Here the shutdown always takes around 14s in-between each test. So I wonder which component is causing this. Maybe it's the RemoteClient or fxmonitor-breaches? I don't know yet how to read this At least one completion condition is taking too long to complete
warning line as given above. Also cc'ing Gijs and Florian in case they can help.
Also I see a very slow startup of Firefox due to:
[task 2020-03-25T18:30:43.640Z] 18:30:43 INFO - PID 3583 | 1585161043631 addons.webextension.doh-rollout@mozilla.org WARN Loading extension 'doh-rollout@mozilla.org': Reading manifest: Invalid extension permission: networkStatus
[task 2020-03-25T18:31:04.029Z] 18:31:04 INFO - PID 3583 | 1585161064024 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: mozillaAddons
Is that caused by the doh-rollout@mozilla.org extension?
Comment 4•4 years ago
|
||
From comment 1 it looks like everything is blocking on the remote-settings databases's getLastModified
. Needinfo-ing :gijs who recently introduced the shutdown blocker in case there's an obvious data-flow problem in the JS code.
My one IDB-related insight would be that I see that the DB_VERSION is 2. If someone has the database open with a lower version number than 2 and doesn't respond to the versionchange
event by closing its database, all open requests with the higher version number will stall until that database is closed, which could be forever.
It's also conceivable there could be an IDB problem. I have requested the pernosco self-service API reproduce the failures from the log run in comment 0 using the docs at https://github.com/Pernosco/pernosco/wiki/Mozilla-Tips#reproducing-arbitrary-taskcluster-job-failures and will report back if the robot sends me an email. Please feel free to needinfo or ping me on riot/slack if I haven't commented back in a few hours about whether the robot sent me reproductions.
Comment 6•4 years ago
|
||
I tried to reproduce each failed test once (there are 2) in normal mode and once in chaos mode and pernosco said it couldn't in either. It said this pretty quickly so this might be the situation where it just doesn't understand the scenario. I haven't dug into it deeply, it might be worth seeking clarification in the pernosco channel in riot/matrix.
Comment 7•4 years ago
|
||
[task 2020-03-25T18:30:35.609Z] 18:30:35 INFO - PID 3583 | JavaScript error: resource://services-common/kinto-offline-client.js, line 505: AbortError: IndexedDB saveLastModified() A request was aborted, for example through a call to IDBTransaction.abort.
Mathieu, I thought Database.jsm
replaced all uses of kinto-offline-client.js
- but this seems to show I was wrong. What do we still use it for?
Also, any idea what would trip all those checks of getLastModified
? Perhaps the remote settings timer going off and attempting to sync all the collections or something?
Comment 8•4 years ago
|
||
Mathieu, I thought Database.jsm replaced all uses of kinto-offline-client.js - but this seems to show I was wrong. What do we still use it for?
We got rid of kinto-offline-client.js
in Remote Settings.
It is still used by normandy migrations, and the WebExtensions storage.sync
API, but using a different storage adapter (sqlite) so we shouldn't see any trace IndexedDB.
Also, any idea what would trip all those checks of getLastModified ? Perhaps the remote settings timer going off and attempting to sync all the collections or something?
That's where getLastModified()
would be used indeed.
The stack in the first comment shows XPIInstall.jsm:loadManifest
though.
"resource://services-settings/Database.jsm","lineNumber":509,"stack":[
"resource://services-settings/Database.jsm:ensureShutdownBlocker:509",
"resource://services-settings/Database.jsm:Database:442",
"resource://services-settings/RemoteSettingsClient.jsm:RemoteSettingsClient/<:239",
"resource://gre/modules/XPCOMUtils.jsm:get:129",
"resource://services-settings/Utils.jsm:hasLocalData:98",
"resource://services-settings/RemoteSettingsClient.jsm:get:309",
"resource://gre/modules/Blocklist.jsm:_updateEntries:1078",
"resource://gre/modules/Blocklist.jsm:_ensureEntries:1069",
"resource://gre/modules/Blocklist.jsm:getEntry:1229",
"resource://gre/modules/Blocklist.jsm:getAddonBlocklistEntry:1460",
"resource://gre/modules/addons/XPIDatabase.jsm:findBlocklistEntry:566",
"resource://gre/modules/addons/XPIDatabase.jsm:updateBlocklistState:574",
"resource://gre/modules/addons/XPIInstall.jsm:loadManifest:709"
My one IDB-related insight would be that I see that the DB_VERSION is 2. If someone has the database open with a lower version number than 2 and doesn't respond to the versionchange event by closing its database, all open requests with the higher version number will stall until that database is closed, which could be forever.
We are in version 2 since summer 2018, I don't someone would still have a database open with a lower version. Isn't onupgradeneeded
enough?
Comment 9•4 years ago
•
|
||
(In reply to Mathieu Leplatre [:leplatrem] from comment #8)
Mathieu, I thought Database.jsm replaced all uses of kinto-offline-client.js - but this seems to show I was wrong. What do we still use it for?
We got rid of
kinto-offline-client.js
in Remote Settings.It is still used by normandy migrations, and the WebExtensions
storage.sync
API, but using a different storage adapter (sqlite) so we shouldn't see any trace IndexedDB.
OK, I've filed bug 1625425 to not do this every startup from normandy.
bug 1455464 might also help with this issue, assuming we block shutdown of the initial browser run on the completion of all migrations. Either way, given the error about the abort(), perhaps this isn't what is breaking things...
The stack in the first comment shows
XPIInstall.jsm:loadManifest
though."resource://services-settings/Database.jsm","lineNumber":509,"stack":[ "resource://services-settings/Database.jsm:ensureShutdownBlocker:509", "resource://services-settings/Database.jsm:Database:442", "resource://services-settings/RemoteSettingsClient.jsm:RemoteSettingsClient/<:239", "resource://gre/modules/XPCOMUtils.jsm:get:129", "resource://services-settings/Utils.jsm:hasLocalData:98", "resource://services-settings/RemoteSettingsClient.jsm:get:309", "resource://gre/modules/Blocklist.jsm:_updateEntries:1078", "resource://gre/modules/Blocklist.jsm:_ensureEntries:1069", "resource://gre/modules/Blocklist.jsm:getEntry:1229", "resource://gre/modules/Blocklist.jsm:getAddonBlocklistEntry:1460", "resource://gre/modules/addons/XPIDatabase.jsm:findBlocklistEntry:566", "resource://gre/modules/addons/XPIDatabase.jsm:updateBlocklistState:574", "resource://gre/modules/addons/XPIInstall.jsm:loadManifest:709"
This is the stack that triggered the first load of Database.jsm which will have added the shutdown blocker. It won't necessarily be related to what is stopping us later, unfortunately.
Anyway, hopefully the patch in bug 1624983 will help...
Comment hidden (Intermittent Failures Robot) |
Comment 11•4 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.
Comment 12•1 year ago
|
||
Moving bug to Remote Protocol::Marionette component per bug 1815831.
Description
•