Closed
Bug 1699297
Opened 5 years ago
Closed 5 years ago
Intermittent /webdriver/tests/new_session/create_firstMatch.py | test_valid[pageLoadStrategy-normal] - AssertionError: timeout (500): No connection could be made because the target machine actively refused it. (os error 10061)
Categories
(Remote Protocol :: Marionette, defect, P5)
Remote Protocol
Marionette
Tracking
(Not tracked)
RESOLVED
DUPLICATE
of bug 1630132
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: assertion, intermittent-failure)
Filed by: btara [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=333551106&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/Q9X790W4TOy5iIIJ5sN0YA/runs/0/artifacts/public/logs/live_backing.log
...
[task 2021-03-17T21:26:47.263Z] 21:26:47 INFO - STDOUT: tests/web-platform/tests/webdriver/tests/new_session/create_firstMatch.py::test_valid[test:extension-value26]
[task 2021-03-17T21:26:47.276Z] 21:26:47 INFO - PID 3316 | 1616016407262 webdriver::server DEBUG -> POST /session {"capabilities": {"firstMatch": [{"moz:firefoxOptions": {"binary": "Z:\\task_1616015341\\build\\application\\firefox\\firefox.exe", "prefs": {"network.dns.localDomains": "op49.web-platform.test,op7.web-platform.test,op48.web-platform.test,op58.web-platform.test,op95.web-platform.test,op1.not-web-platform.test,op53.not-web-platform.test,www.xn--n8j6ds53lwwkrqhv28a.web-platform.test,op71.not-web-platform.test,www1.web-platform.test,op73.not-web-platform.test,www.www2.not-web-platform.test,op52.not-web-platform.test,op21.not-web-platform.test,op64.not-web-platform.test,op35.web-platform.test,xn--lve-6lad.xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.web-platform.test,www1.xn--lve-6lad.web-platform.test,xn--n8j6ds53lwwkrqhv28a.www.web-platform.test,op1.web-platform.test,op83.not-web-platform.test,op8.web-platform.test,op67.web-platform.test,op98.web-platform.test,op63.web-platform.test,www1.www1.not-web-platform.test,op39.web-platform.test,op14.web-platform.test,op25.not-web-platform.test,op79.web-platform.test,op3.web-platform.test,op56.not-web-platform.test,op29.not-web-platform.test,op56.web-platform.test,op38.web-platform.test,op32.web-platform.test,xn--lve-6lad.xn--lve-6lad.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.xn--lve-6lad.not-web-platform.test,op70.web-platform.test,www2.www2.web-platform.test,op31.web-platform.test,www2.xn--n8j6ds53lwwkrqhv28a.web-platform.test,op38.not-web-platform.test,op16.not-web-platform.test,op5.not-web-platform.test,op95.not-web-platform.test,op57.web-platform.test,op99.web-platform.test,op74.not-web-platform.test,op18.not-web-platform.test,op45.web-platform.test,op66.not-web-platform.test,xn--lve-6lad.xn--n8j6ds53lwwkrqhv28a.web-platform.test,op73.web-platform.test,op36.not-web-platform.test,op89.web-platform.test,op69.not-web-platform.test,op87.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,op26.not-web-platform.test,op52.web-platform.test,www2.not-web-platform.test,www.xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,op28.web-platform.test,op12.web-platform.test,op77.not-web-platform.test,op47.not-web-platform.test,op97.not-web-platform.test,op19.web-platform.test,op19.not-web-platform.test,op3.not-web-platform.test,op98.not-web-platform.test,op62.web-platform.test,op61.web-platform.test,op4.not-web-platform.test,op80.web-platform.test,op54.not-web-platform.test,www1.www1.web-platform.test,op8.not-web-platform.test,op58.not-web-platform.test,op4.web-platform.test,op51.web-platform.test,op30.not-web-platform.test,op18.web-platform.test,op97.web-platform.test,op30.web-platform.test,op11.web-platform.test,op67.not-web-platform.test,op85.not-web-platform.test,op69.web-platform.test,op13.web-platform.test,op50.web-platform.test,op5.web-platform.test,xn--lve-6lad.xn--lve-6lad.web-platform.test,xn--n8j6ds53lwwkrqhv28a.xn--lve-6lad.web-platform.test,op27.not-web-platform.test,op25.web-platform.test,xn--lve-6lad.www.not-web-platform.test,op13.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.www1.not-web-platform.test,op45.not-web-platform.test,op44.not-web-platform.test,op46.not-web-platform.test,xn--lve-6lad.www1.web-platform.test,op88.not-web-platform.test,op68.web-platform.test,op92.web-platform.test,op82.not-web-platform.test,www1.not-web-platform.test,op78.web-platform.test,op87.web-platform.test,xn--lve-6lad.www1.not-web-platform.test,op62.not-web-platform.test,op40.web-platform.test,op40.not-web-platform.test,op88.web-platform.test,op10.not-web-platform.test,op16.web-platform.test,op21.web-platform.test,web-platform.test,www.www1.web-platform.test,op59.web-platform.test,op85.web-platform.test,op35.not-web-platform.test,www.not-web-platform.test,www1.xn--lve-6lad.not-web-platform.test,op51.not-web-platform.test,op7.not-web-platform.test,op94.not-web-platform.test,op80.not-web-platform.test,op6.not-web-platform.test,op54.web-platform.test,op89.not-web-platform.test,op42.web-platform.test,op91.web-platform.test,op14.not-web-platform.test,www2.www1.web-platform.test,xn--lve-6lad.not-web-platform.test,not-web-platform.test,www2.www.not-web-platform.test,op41.web-platform.test,op55.web-platform.test,www2.www2.not-web-platform.test,op76.web-platform.test,op24.not-web-platform.test,op55.not-web-platform.test,op96.not-web-platform.test,op86.not-web-platform.test,op17.not-web-platform.test,op84.not-web-platform.test,op63.not-web-platform.test,op60.not-web-platform.test,www2.web-platform.test,www1.www.web-platform.test,xn--n8j6ds53lwwkrqhv28a.xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,op77.web-platform.test,op83.web-platform.test,op42.not-web-platform.test,op90.web-platform.test,op78.not-web-platform.test,op93.not-web-platform.test,op10.web-platform.test,op12.not-web-platform.test,op11.not-web-platform.test,www.www2.web-platform.test,op70.not-web-platform.test,www2.xn--lve-6lad.web-platform.test,op46.web-platform.test,op17.web-platform.test,op75.not-web-platform.test,op9.web-platform.test,www2.xn--lve-6lad.not-web-platform.test,op65.web-platform.test,op43.web-platform.test,op92.not-web-platform.test,op84.web-platform.test,op48.not-web-platform.test,op43.not-web-platform.test,op23.not-web-platform.test,op53.web-platform.test,op33.web-platform.test,op64.web-platform.test,op66.web-platform.test,www1.xn--n8j6ds53lwwkrqhv28a.web-platform.test,op36.web-platform.test,op6.web-platform.test,op81.not-web-platform.test,op90.not-web-platform.test,op49.not-web-platform.test,op27.web-platform.test,op50.not-web-platform.test,op2.not-web-platform.test,www1.www.not-web-platform.test,op47.web-platform.test,op28.not-web-platform.test,op37.not-web-platform.test,op34.not-web-platform.test,op37.web-platform.test,op79.not-web-platform.test,www.www.web-platform.test,op34.web-platform.test,xn--lve-6lad.www2.web-platform.test,op96.web-platform.test,www2.www.web-platform.test,op2.web-platform.test,op74.web-platform.test,op15.web-platform.test,op22.web-platform.test,op39.not-web-platform.test,op65.not-web-platform.test,op68.not-web-platform.test,op26.web-platform.test,xn--lve-6lad.www.web-platform.test,op99.not-web-platform.test,op22.not-web-platform.test,xn--lve-6lad.web-platform.test,op76.not-web-platform.test,op57.not-web-platform.test,op32.not-web-platform.test,op61.not-web-platform.test,www.xn--lve-6lad.web-platform.test,op9.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.xn--n8j6ds53lwwkrqhv28a.web-platform.test,op86.web-platform.test,op72.web-platform.test,xn--n8j6ds53lwwkrqhv28a.www.not-web-platform.test,op81.web-platform.test,www2.xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,www.www.not-web-platform.test,op24.web-platform.test,op23.web-platform.test,www2.www1.not-web-platform.test,op20.web-platform.test,op20.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.www2.not-web-platform.test,op93.web-platform.test,www.www1.not-web-platform.test,op41.not-web-platform.test,xn--lve-6lad.www2.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.www2.web-platform.test,op15.not-web-platform.test,www1.www2.not-web-platform.test,op94.web-platform.test,op82.web-platform.test,op91.not-web-platform.test,www.web-platform.test,op31.not-web-platform.test,op75.web-platform.test,www1.www2.web-platform.test,op33.not-web-platform.test,op60.web-platform.test,op29.web-platform.test,op71.web-platform.test,www.xn--lve-6lad.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.www1.web-platform.test,www1.xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,op72.not-web-platform.test,op44.web-platform.test,op59.not-web-platform.test", "toolkit.asyncshutdown.log": true, "media.peerconnection.mtransport_process": false, "network.process.enabled": false}}, "test:extension": {"key": "value"}}]}}
[task 2021-03-17T21:26:47.277Z] 21:26:47 INFO - PID 3316 | 1616016407265 geckodriver::capabilities DEBUG Trying to read firefox version from ini files
[task 2021-03-17T21:26:47.278Z] 21:26:47 INFO - PID 3316 | 1616016407266 geckodriver::capabilities DEBUG Found version 88.0a1
[task 2021-03-17T21:26:47.279Z] 21:26:47 INFO - PID 3316 | 1616016407270 mozrunner::runner INFO Running command: "Z:\\task_1616015341\\build\\application\\firefox\\firefox.exe" "--marionette" "-foreground" "-no-remote" "-profile" "C:\\Users\\task_1616015341\\AppData\\Local\\Temp\\rust_mozprofile9efMK2"
[task 2021-03-17T21:26:47.280Z] 21:26:47 INFO - PID 3316 | 1616016407271 geckodriver::marionette DEBUG Waiting 60s to connect to browser on 127.0.0.1:2828
[task 2021-03-17T21:26:47.425Z] 21:26:47 INFO - PID 3316 | DEBUG: Adding blocker OS.File: flush pending requests, warn about unclosed files, shut down service. for phase xpcom-will-shutdown
[task 2021-03-17T21:26:47.426Z] 21:26:47 INFO - PID 3316 | DEBUG: Adding blocker OS.File: flush I/O queued before profileBeforeChange for phase profile-before-change
[task 2021-03-17T21:26:47.426Z] 21:26:47 INFO - PID 3316 | DEBUG: Adding blocker AddonManager: shutting down. for phase profile-before-change
[task 2021-03-17T21:26:47.479Z] 21:26:47 INFO - PID 3316 | DEBUG: Adding blocker Flush WebExtension StartupCache for phase profile-before-change
[task 2021-03-17T21:26:47.493Z] 21:26:47 INFO - PID 3316 | DEBUG: Adding blocker ClientManagerService: start destroying IPC actors early for phase xpcom-will-shutdown
[task 2021-03-17T21:26:47.625Z] 21:26:47 INFO - PID 3316 | DEBUG: Adding blocker JSON store: writing data for phase AddonManager: Waiting for providers to shut down.
[task 2021-03-17T21:26:47.628Z] 21:26:47 INFO - PID 3316 | DEBUG: Adding blocker Update add-on blocklist state into add-on DB for phase AddonManager: Waiting to start provider shutdown.
[task 2021-03-17T21:26:47.629Z] 21:26:47 INFO - PID 3316 | DEBUG: Completed blocker Update add-on blocklist state into add-on DB for phase AddonManager: Waiting to start provider shutdown.
[task 2021-03-17T21:26:47.637Z] 21:26:47 INFO - PID 3316 | DEBUG: Adding blocker XPIProvider shutdown for phase quit-application-granted
[task 2021-03-17T21:26:47.637Z] 21:26:47 INFO - PID 3316 | DEBUG: Adding blocker XPIProvider for phase AddonManager: Waiting for providers to shut down.
[task 2021-03-17T21:26:47.638Z] 21:26:47 INFO - PID 3316 | DEBUG: Adding blocker PluginProvider for phase AddonManager: Waiting for providers to shut down.
[task 2021-03-17T21:26:47.639Z] 21:26:47 INFO - PID 3316 | DEBUG: Adding blocker ServiceWorkerRegistrar: Flushing data for phase profile-before-change
[task 2021-03-17T21:26:47.642Z] 21:26:47 INFO - PID 3316 | DEBUG: Adding blocker CrashMonitor: Writing notifications to file after receiving profile-before-change for phase OS.File: Waiting for clients before profileBeforeChange
[task 2021-03-17T21:26:47.666Z] 21:26:47 INFO - PID 3316 | DEBUG: Adding blocker TelemetryController: shutting down for phase profile-before-change-telemetry
[task 2021-03-17T21:26:47.694Z] 21:26:47 INFO - PID 3316 | DEBUG: Adding blocker EnvironmentAddonBuilder for phase AddonManager: Waiting to start provider shutdown.
[task 2021-03-17T21:26:47.708Z] 21:26:47 INFO - PID 3316 | DEBUG: Adding blocker RemoteSettingsClient - finish IDB access. for phase profile-before-change
[task 2021-03-17T21:26:47.714Z] 21:26:47 INFO - PID 3316 | 1616016407713 Marionette INFO Marionette enabled
[task 2021-03-17T21:26:47.805Z] 21:26:47 INFO - PID 3316 | 1616016407805 Marionette TRACE Received observer notification toplevel-window-ready
[task 2021-03-17T21:26:47.815Z] 21:26:47 INFO - PID 3316 | DEBUG: Adding blocker IOUtils Blocker for phase profile-before-change
[task 2021-03-17T21:26:47.832Z] 21:26:47 INFO - PID 3316 | DEBUG: Adding blocker Flush AddonRepository for phase profile-before-change
[task 2021-03-17T21:26:48.043Z] 21:26:48 INFO - PID 3316 | DEBUG: Adding blocker MediaShutdownManager: shutdown for phase profile-before-change
[task 2021-03-17T21:26:48.076Z] 21:26:48 INFO - PID 3316 | DEBUG: Adding blocker JSON store: writing data for phase profile-before-change
[task 2021-03-17T21:26:48.113Z] 21:26:48 INFO - PID 3316 | DEBUG: Adding blocker Remote Settings profile-before-change for phase profile-before-change
[task 2021-03-17T21:26:48.116Z] 21:26:48 INFO - PID 3316 | DEBUG: Adding blocker JSON store: writing data for phase profile-before-change
[task 2021-03-17T21:26:48.238Z] 21:26:48 INFO - PID 3316 | DEBUG: Adding blocker GMPProvider for phase AddonManager: Waiting for providers to shut down.
[task 2021-03-17T21:26:48.245Z] 21:26:48 INFO - PID 3316 | DEBUG: Adding blocker ContentParent: id=203ef6de800 for phase xpcom-will-shutdown
[task 2021-03-17T21:26:48.246Z] 21:26:48 INFO - PID 3316 | DEBUG: Adding blocker ContentParent: id=203ef6de800 for phase profile-before-change
[task 2021-03-17T21:26:48.298Z] 21:26:48 INFO - PID 3316 | DEBUG: Adding blocker ServiceWorkerShutdownBlocker: shutting down Service Workers for phase profile-change-teardown
[task 2021-03-17T21:26:48.327Z] 21:26:48 INFO - PID 3316 | DEBUG: Adding blocker ContentParent: id=203efdcf000 for phase xpcom-will-shutdown
[task 2021-03-17T21:26:48.328Z] 21:26:48 INFO - PID 3316 | DEBUG: Adding blocker ContentParent: id=203efdcf000 for phase profile-before-change
[task 2021-03-17T21:26:48.615Z] 21:26:48 INFO - PID 3316 | DEBUG: Adding blocker PageActions: purging unregistered actions from cache for phase profile-before-change
[task 2021-03-17T21:26:48.622Z] 21:26:48 INFO - PID 3316 | DEBUG: Adding blocker Places Clients shutdown for phase profile-change-teardown
[task 2021-03-17T21:26:48.623Z] 21:26:48 INFO - PID 3316 | DEBUG: Adding blocker Places Connection shutdown for phase profile-before-change
[task 2021-03-17T21:26:48.668Z] 21:26:48 INFO - PID 3316 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new Error("", "(unknown module)"))
[task 2021-03-17T21:26:48.718Z] 21:26:48 INFO - PID 3316 | DEBUG: Adding blocker Sqlite.jsm shutdown blocker for phase profile-before-change
[task 2021-03-17T21:26:48.720Z] 21:26:48 INFO - PID 3316 | DEBUG: Adding blocker content-prefs.sqlite#0: waiting for shutdown for phase Sqlite.jsm: wait until all connections are closed
[task 2021-03-17T21:26:48.721Z] 21:26:48 INFO - PID 3316 | DEBUG: Adding blocker Closing ContentPrefService2 connection. for phase Sqlite.jsm: wait until all clients have completed their task
[task 2021-03-17T21:26:48.729Z] 21:26:48 INFO - PID 3316 | DEBUG: Adding blocker Transaction (0) for phase content-prefs.sqlite#0: waiting for clients
[task 2021-03-17T21:26:48.751Z] 21:26:48 INFO - PID 3316 | DEBUG: Adding blocker sanitize.js: Sanitize on shutdown for phase Places Clients shutdown
[task 2021-03-17T21:26:48.879Z] 21:26:48 INFO - PID 3316 | DEBUG: Adding blocker DoHController: clear state and remove observers for phase profile-before-change
[task 2021-03-17T21:26:48.902Z] 21:26:48 INFO - PID 3316 | DEBUG: Adding blocker JSON store: writing data for phase profile-before-change
[task 2021-03-17T21:26:48.940Z] 21:26:48 INFO - PID 3316 | DEBUG: Completed blocker Transaction (0) for phase content-prefs.sqlite#0: waiting for clients
[task 2021-03-17T21:26:48.957Z] 21:26:48 INFO - PID 3316 | DEBUG: Adding blocker Transaction (1) for phase content-prefs.sqlite#0: waiting for clients
[task 2021-03-17T21:26:48.958Z] 21:26:48 INFO - PID 3316 | DEBUG: Adding blocker Transaction (2) for phase content-prefs.sqlite#0: waiting for clients
...
[task 2021-03-17T21:26:49.471Z] 21:26:49 INFO - PID 3316 | DEBUG: Adding blocker JSON store: writing data for phase profile-before-change
[task 2021-03-17T21:26:49.506Z] 21:26:49 INFO - PID 3316 | DEBUG: Adding blocker places.sqlite#1: PlacesUIUtils: maybeAddImportButton (18) for phase places.sqlite#1: waiting for clients
[task 2021-03-17T21:26:49.508Z] 21:26:49 INFO - PID 3316 | DEBUG: Completed blocker places.sqlite#1: PlacesUIUtils: maybeAddImportButton (18) for phase places.sqlite#1: waiting for clients
[task 2021-03-17T21:26:49.639Z] 21:26:49 INFO - PID 3316 | DEBUG: Adding blocker ContentParent: id=203f48f0800 for phase xpcom-will-shutdown
[task 2021-03-17T21:26:49.641Z] 21:26:49 INFO - PID 3316 | DEBUG: Adding blocker ContentParent: id=203f48f0800 for phase profile-before-change
[task 2021-03-17T21:26:49.681Z] 21:26:49 INFO - PID 3316 | 1616016409679 Marionette TRACE Received observer notification marionette-startup-requested
[task 2021-03-17T21:26:49.682Z] 21:26:49 INFO - PID 3316 | 1616016409679 Marionette TRACE Waiting until startup recorder finished recording startup scripts...
[task 2021-03-17T21:26:49.706Z] 21:26:49 INFO - PID 3316 | 1616016409705 Marionette TRACE All scripts recorded.
[task 2021-03-17T21:26:49.707Z] 21:26:49 INFO - PID 3316 | 1616016409705 Marionette DEBUG Setting recommended pref apz.content_response_timeout to 60000
[task 2021-03-17T21:26:49.709Z] 21:26:49 INFO - PID 3316 | 1616016409705 Marionette DEBUG Setting recommended pref browser.contentblocking.introCount to 99
[task 2021-03-17T21:26:49.710Z] 21:26:49 INFO - PID 3316 | 1616016409706 Marionette DEBUG Setting recommended pref browser.download.panel.shown to true
[task 2021-03-17T21:26:49.710Z] 21:26:49 INFO - PID 3316 | 1616016409706 Marionette DEBUG Setting recommended pref browser.newtabpage.enabled to false
[task 2021-03-17T21:26:49.712Z] 21:26:49 INFO - PID 3316 | 1616016409708 Marionette DEBUG Setting recommended pref browser.pagethumbnails.capturing_disabled to true
[task 2021-03-17T21:26:49.713Z] 21:26:49 INFO - PID 3316 | 1616016409709 Marionette DEBUG Setting recommended pref browser.search.update to false
[task 2021-03-17T21:26:49.714Z] 21:26:49 INFO - PID 3316 | 1616016409709 Marionette DEBUG Setting recommended pref browser.tabs.disableBackgroundZombification to false
[task 2021-03-17T21:26:49.715Z] 21:26:49 INFO - PID 3316 | 1616016409709 Marionette DEBUG Setting recommended pref browser.tabs.remote.separatePrivilegedContentProcess to false
[task 2021-03-17T21:26:49.717Z] 21:26:49 INFO - PID 3316 | 1616016409709 Marionette DEBUG Setting recommended pref browser.tabs.unloadOnLowMemory to false
[task 2021-03-17T21:26:49.717Z] 21:26:49 INFO - PID 3316 | 1616016409710 Marionette DEBUG Setting recommended pref browser.tabs.warnOnCloseOtherTabs to false
[task 2021-03-17T21:26:49.718Z] 21:26:49 INFO - PID 3316 | 1616016409710 Marionette DEBUG Setting recommended pref browser.tabs.warnOnOpen to false
[task 2021-03-17T21:26:49.720Z] 21:26:49 INFO - PID 3316 | 1616016409710 Marionette DEBUG Setting recommended pref browser.toolbars.bookmarks.visibility to never
[task 2021-03-17T21:26:49.721Z] 21:26:49 INFO - PID 3316 | 1616016409710 Marionette DEBUG Setting recommended pref browser.usedOnWindows10.introURL to
[task 2021-03-17T21:26:49.722Z] 21:26:49 INFO - PID 3316 | 1616016409711 Marionette DEBUG Setting recommended pref browser.urlbar.suggest.searches to false
[task 2021-03-17T21:26:49.723Z] 21:26:49 INFO - PID 3316 | 1616016409712 Marionette DEBUG Setting recommended pref datareporting.policy.dataSubmissionPolicyAccepted to false
[task 2021-03-17T21:26:49.724Z] 21:26:49 INFO - PID 3316 | 1616016409713 Marionette DEBUG Setting recommended pref dom.disable_beforeunload to true
[task 2021-03-17T21:26:49.725Z] 21:26:49 INFO - PID 3316 | 1616016409713 Marionette DEBUG Setting recommended pref dom.disable_open_during_load to false
[task 2021-03-17T21:26:49.726Z] 21:26:49 INFO - PID 3316 | 1616016409713 Marionette DEBUG Setting recommended pref dom.file.createInChild to true
[task 2021-03-17T21:26:49.727Z] 21:26:49 INFO - PID 3316 | 1616016409713 Marionette DEBUG Setting recommended pref dom.max_chrome_script_run_time to 0
[task 2021-03-17T21:26:49.728Z] 21:26:49 INFO - PID 3316 | 1616016409713 Marionette DEBUG Setting recommended pref dom.max_script_run_time to 0
[task 2021-03-17T21:26:49.729Z] 21:26:49 INFO - PID 3316 | 1616016409715 Marionette DEBUG Setting recommended pref dom.push.connection.enabled to false
[task 2021-03-17T21:26:49.729Z] 21:26:49 INFO - PID 3316 | 1616016409715 Marionette DEBUG Setting recommended pref extensions.getAddons.cache.enabled to false
[task 2021-03-17T21:26:49.731Z] 21:26:49 INFO - PID 3316 | 1616016409715 Marionette DEBUG Setting recommended pref extensions.getAddons.discovery.api_url to data:,
[task 2021-03-17T21:26:49.732Z] 21:26:49 INFO - PID 3316 | 1616016409716 Marionette DEBUG Setting recommended pref network.http.prompt-temp-redirect to false
[task 2021-03-17T21:26:49.733Z] 21:26:49 INFO - PID 3316 | 1616016409716 Marionette DEBUG Setting recommended pref privacy.trackingprotection.enabled to false
[task 2021-03-17T21:26:49.734Z] 21:26:49 INFO - PID 3316 | 1616016409716 Marionette DEBUG Setting recommended pref prompts.contentPromptSubDialog to false
[task 2021-03-17T21:26:49.735Z] 21:26:49 INFO - PID 3316 | 1616016409716 Marionette DEBUG Setting recommended pref security.fileuri.strict_origin_policy to false
[task 2021-03-17T21:26:49.736Z] 21:26:49 INFO - PID 3316 | 1616016409716 Marionette DEBUG Setting recommended pref security.notification_enable_delay to 0
[task 2021-03-17T21:26:49.737Z] 21:26:49 INFO - PID 3316 | 1616016409717 Marionette DEBUG Setting recommended pref signon.autofillForms to false
[task 2021-03-17T21:26:49.738Z] 21:26:49 INFO - PID 3316 | 1616016409718 Marionette DEBUG Setting recommended pref signon.rememberSignons to false
[task 2021-03-17T21:26:49.738Z] 21:26:49 INFO - PID 3316 | 1616016409722 Marionette INFO Listening on port 2828
[task 2021-03-17T21:26:49.739Z] 21:26:49 INFO - PID 3316 | 1616016409722 Marionette DEBUG Marionette is listening
[task 2021-03-17T21:26:49.861Z] 21:26:49 INFO - PID 3316 | DEBUG: Adding blocker ScriptPreloader: Saving bytecode cache for phase xpcom-will-shutdown
[task 2021-03-17T21:26:49.996Z] 21:26:49 INFO - PID 3316 | 1616016409995 Marionette DEBUG Accepted connection 0 from 127.0.0.1:50373
[task 2021-03-17T21:26:49.998Z] 21:26:49 INFO - PID 3316 | 1616016409996 geckodriver::marionette DEBUG Connection to Marionette established on 127.0.0.1:2828.
[task 2021-03-17T21:26:50.003Z] 21:26:50 INFO - PID 3316 | 1616016410003 Marionette DEBUG 0 -> [0,1,"WebDriver:NewSession",{"test:extension":{"key":"value"}}]
[task 2021-03-17T21:26:50.019Z] 21:26:50 INFO - PID 3316 | 1616016410016 Marionette DEBUG 0 <- [1,1,null,{"sessionId":"85d022c4-dabf-45dc-922f-68e04e6f0b32","capabilities":{"browserName":"firefox","browserVersion":"88.0a ... downTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true,"test:extension":{"key":"value"}}}]
[task 2021-03-17T21:26:50.030Z] 21:26:50 INFO - STDOUT: PASSED
[task 2021-03-17T21:26:50.032Z] 21:26:50 INFO - PID 3316 | 1616016410027 webdriver::server DEBUG <- 200 OK {"value":{"sessionId":"85d022c4-dabf-45dc-922f-68e04e6f0b32","capabilities":{"acceptInsecureCerts":false,"browserName":"firefox","browserVersion":"88.0a1","moz:accessibilityChecks":false,"moz:buildID":"20210317205241","moz:geckodriverVersion":"0.29.0","moz:headless":false,"moz:processID":10508,"moz:profile":"C:\\Users\\task_1616015341\\AppData\\Local\\Temp\\rust_mozprofile9efMK2","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true,"pageLoadStrategy":"normal","platformName":"windows","platformVersion":"10.0","rotatable":false,"setWindowRect":true,"strictFileInteractability":false,"test:extension":{"key":"value"},"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"unhandledPromptBehavior":"dismiss and notify"}}}
[task 2021-03-17T21:26:50.033Z] 21:26:50 INFO - PID 3316 | 1616016410029 webdriver::server DEBUG -> DELETE /session/85d022c4-dabf-45dc-922f-68e04e6f0b32
[task 2021-03-17T21:26:50.033Z] 21:26:50 INFO - PID 3316 | 1616016410032 Marionette DEBUG 0 -> [0,2,"Marionette:Quit",{"flags":["eForceQuit"]}]
[task 2021-03-17T21:26:50.034Z] 21:26:50 INFO - PID 3316 | 1616016410032 Marionette INFO Stopped listening on port 2828
[task 2021-03-17T21:26:50.041Z] 21:26:50 INFO - PID 3316 | DEBUG: Adding blocker SessionStore: flushing all windows for phase quit-application-granted
[task 2021-03-17T21:26:50.042Z] 21:26:50 INFO - PID 3316 | DEBUG: Starting phase quit-application-granted
[task 2021-03-17T21:26:50.059Z] 21:26:50 INFO - PID 3316 | DEBUG: Spinning the event loop
[task 2021-03-17T21:26:50.063Z] 21:26:50 INFO - PID 3316 | DEBUG: Adding blocker Extension shutdown: wikipedia@search.mozilla.org for phase profile-change-teardown
[task 2021-03-17T21:26:50.066Z] 21:26:50 INFO - PID 3316 | DEBUG: Adding blocker Extension shutdown: webcompat@mozilla.org for phase profile-change-teardown
[task 2021-03-17T21:26:50.067Z] 21:26:50 INFO - PID 3316 | DEBUG: Adding blocker Extension shutdown: webcompat-reporter@mozilla.org for phase profile-change-teardown
[task 2021-03-17T21:26:50.069Z] 21:26:50 INFO - PID 3316 | DEBUG: Adding blocker Extension shutdown: screenshots@mozilla.org for phase profile-change-teardown
[task 2021-03-17T21:26:50.069Z] 21:26:50 INFO - PID 3316 | DEBUG: Adding blocker Extension shutdown: pictureinpicture@mozilla.org for phase profile-change-teardown
[task 2021-03-17T21:26:50.070Z] 21:26:50 INFO - PID 3316 | DEBUG: Adding blocker Extension shutdown: google@search.mozilla.org for phase profile-change-teardown
[task 2021-03-17T21:26:50.071Z] 21:26:50 INFO - PID 3316 | DEBUG: Adding blocker Extension shutdown: formautofill@mozilla.org for phase profile-change-teardown
[task 2021-03-17T21:26:50.072Z] 21:26:50 INFO - PID 3316 | DEBUG: Adding blocker Extension shutdown: doh-rollout@mozilla.org for phase profile-change-teardown
[task 2021-03-17T21:26:50.074Z] 21:26:50 INFO - PID 3316 | DEBUG: Adding blocker Extension shutdown: default-theme@mozilla.org for phase profile-change-teardown
[task 2021-03-17T21:26:50.075Z] 21:26:50 INFO - PID 3316 | DEBUG: Adding blocker Extension shutdown: ddg@search.mozilla.org for phase profile-change-teardown
[task 2021-03-17T21:26:50.079Z] 21:26:50 INFO - PID 3316 | DEBUG: Adding blocker Extension shutdown: bing@search.mozilla.org for phase profile-change-teardown
[task 2021-03-17T21:26:50.080Z] 21:26:50 INFO - PID 3316 | DEBUG: Adding blocker Extension shutdown: amazondotcom@search.mozilla.org for phase profile-change-teardown
[task 2021-03-17T21:26:50.080Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker XPIProvider shutdown for phase quit-application-granted
[task 2021-03-17T21:26:50.104Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker SessionStore: flushing all windows for phase quit-application-granted
[task 2021-03-17T21:26:50.105Z] 21:26:50 INFO - PID 3316 | DEBUG: Finished phase quit-application-granted
[task 2021-03-17T21:26:50.106Z] 21:26:50 INFO - PID 3316 | DEBUG: Adding blocker ShieldRecipeClient: Cleaning up for phase profile-before-change
[task 2021-03-17T21:26:50.107Z] 21:26:50 INFO - PID 3316 | 1616016410106 Marionette TRACE Received observer notification quit-application
[task 2021-03-17T21:26:50.111Z] 21:26:50 INFO - PID 3316 | DEBUG: Adding blocker SessionFile: Finish writing Session Restore data for phase profile-before-change
[task 2021-03-17T21:26:50.113Z] 21:26:50 INFO - PID 3316 | 1616016410112 Marionette DEBUG 0 <- [1,2,null,{"cause":"shutdown","forced":false}]
[task 2021-03-17T21:26:50.176Z] 21:26:50 INFO - PID 3316 | 1616016410174 webdriver::server DEBUG Deleting session
[task 2021-03-17T21:26:50.179Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker ShieldRecipeClient: Cleaning up for phase profile-before-change
[task 2021-03-17T21:26:50.181Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker Extension shutdown: wikipedia@search.mozilla.org for phase profile-change-teardown
[task 2021-03-17T21:26:50.182Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker Extension shutdown: webcompat@mozilla.org for phase profile-change-teardown
[task 2021-03-17T21:26:50.183Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker Extension shutdown: webcompat-reporter@mozilla.org for phase profile-change-teardown
[task 2021-03-17T21:26:50.184Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker Extension shutdown: screenshots@mozilla.org for phase profile-change-teardown
[task 2021-03-17T21:26:50.185Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker Extension shutdown: pictureinpicture@mozilla.org for phase profile-change-teardown
[task 2021-03-17T21:26:50.186Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker Extension shutdown: google@search.mozilla.org for phase profile-change-teardown
[task 2021-03-17T21:26:50.187Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker Extension shutdown: formautofill@mozilla.org for phase profile-change-teardown
[task 2021-03-17T21:26:50.188Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker Extension shutdown: doh-rollout@mozilla.org for phase profile-change-teardown
[task 2021-03-17T21:26:50.189Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker Extension shutdown: default-theme@mozilla.org for phase profile-change-teardown
[task 2021-03-17T21:26:50.190Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker Extension shutdown: ddg@search.mozilla.org for phase profile-change-teardown
[task 2021-03-17T21:26:50.191Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker Extension shutdown: bing@search.mozilla.org for phase profile-change-teardown
[task 2021-03-17T21:26:50.192Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker Extension shutdown: amazondotcom@search.mozilla.org for phase profile-change-teardown
[task 2021-03-17T21:26:50.193Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker SessionFile: Finish writing Session Restore data for phase profile-before-change
[task 2021-03-17T21:26:50.206Z] 21:26:50 INFO - PID 3316 | 1616016410205 Marionette DEBUG 0 -> [0,3,"Marionette:Quit",{"flags":["eForceQuit"]}]
[task 2021-03-17T21:26:50.207Z] 21:26:50 INFO - PID 3316 | 1616016410205 Marionette DEBUG 0 <- [1,3,{"error":"invalid session id","message":"WebDriver session does not exist, or is not active","stacktrace":"WebDriverErro ... t@chrome://marionette/content/server.js:238:9\n_onJSONObjectReady/<@chrome://marionette/content/transport.js:504:20\n"},null]
[task 2021-03-17T21:26:50.224Z] 21:26:50 INFO - PID 3316 | 1616016410222 Marionette DEBUG Closed connection 0
[task 2021-03-17T21:26:50.225Z] 21:26:50 INFO - PID 3316 | DEBUG: Starting phase profile-change-teardown
[task 2021-03-17T21:26:50.234Z] 21:26:50 INFO - PID 3316 | DEBUG: Spinning the event loop
[task 2021-03-17T21:26:50.235Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker sanitize.js: Sanitize on shutdown for phase Places Clients shutdown
[task 2021-03-17T21:26:50.236Z] 21:26:50 INFO - PID 3316 | DEBUG: Finished phase profile-change-teardown
[task 2021-03-17T21:26:50.239Z] 21:26:50 INFO - PID 3316 | DEBUG: Starting phase profile-before-change
[task 2021-03-17T21:26:50.246Z] 21:26:50 INFO - PID 3316 | DEBUG: Spinning the event loop
[task 2021-03-17T21:26:50.248Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker EnvironmentAddonBuilder for phase AddonManager: Waiting to start provider shutdown.
[task 2021-03-17T21:26:50.248Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker PageActions: purging unregistered actions from cache for phase profile-before-change
[task 2021-03-17T21:26:50.249Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker Places Expiration: shutdown for phase Places Connection shutdown
[task 2021-03-17T21:26:50.251Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker RemoteSettingsClient - finish IDB access. for phase profile-before-change
[task 2021-03-17T21:26:50.252Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker Flush AddonRepository for phase profile-before-change
[task 2021-03-17T21:26:50.253Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker JSON store: writing data for phase profile-before-change
[task 2021-03-17T21:26:50.254Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker Remote Settings profile-before-change for phase profile-before-change
[task 2021-03-17T21:26:50.255Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker JSON store: writing data for phase profile-before-change
[task 2021-03-17T21:26:50.257Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker JSON store: writing data for phase profile-before-change
[task 2021-03-17T21:26:50.260Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker DownloadAutoSaveView: writing data for phase profile-before-change
[task 2021-03-17T21:26:50.260Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker JSON store: writing data for phase profile-before-change
[task 2021-03-17T21:26:50.260Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker JSON store: writing data for phase profile-before-change
[task 2021-03-17T21:26:50.261Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker DoHController: clear state and remove observers for phase profile-before-change
[task 2021-03-17T21:26:50.262Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker places.sqlite#1: waiting for shutdown for phase Sqlite.jsm: wait until all connections are closed
[task 2021-03-17T21:26:50.264Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker ContextualIdentityService: writing data for phase profile-before-change
[task 2021-03-17T21:26:50.265Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker PlacesUtils wrapped connection closing as part of Places shutdown for phase Places Connection shutdown
[task 2021-03-17T21:26:50.266Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker PlacesUtils wrapped connection must be closed before Sqlite.jsm for phase Sqlite.jsm: wait until all clients have completed their task
[task 2021-03-17T21:26:50.267Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker JSON store: writing data for phase AddonManager: Waiting for providers to shut down.
[task 2021-03-17T21:26:50.268Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker PluginProvider for phase AddonManager: Waiting for providers to shut down.
[task 2021-03-17T21:26:50.269Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker GMPProvider for phase AddonManager: Waiting for providers to shut down.
[task 2021-03-17T21:26:50.270Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker XPIProvider for phase AddonManager: Waiting for providers to shut down.
[task 2021-03-17T21:26:50.271Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker AddonManager: shutting down. for phase profile-before-change
[task 2021-03-17T21:26:50.272Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker places.sqlite#0: waiting for shutdown for phase Sqlite.jsm: wait until all connections are closed
[task 2021-03-17T21:26:50.273Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker PlacesUtils read-only connection closing as part of Places shutdown for phase Places Connection shutdown
[task 2021-03-17T21:26:50.274Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker PlacesUtils read-only connection must be closed before Sqlite.jsm for phase Sqlite.jsm: wait until all clients have completed their task
[task 2021-03-17T21:26:50.275Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker content-prefs.sqlite#0: waiting for shutdown for phase Sqlite.jsm: wait until all connections are closed
[task 2021-03-17T21:26:50.277Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker Closing ContentPrefService2 connection. for phase Sqlite.jsm: wait until all clients have completed their task
[task 2021-03-17T21:26:50.278Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker Sqlite.jsm shutdown blocker for phase profile-before-change
[task 2021-03-17T21:26:50.279Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker CrashMonitor: Writing notifications to file after receiving profile-before-change for phase OS.File: Waiting for clients before profileBeforeChange
[task 2021-03-17T21:26:50.280Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker Search service: shutting down for phase OS.File: Waiting for clients before profileBeforeChange
[task 2021-03-17T21:26:50.281Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker Flush WebExtension StartupCache for phase profile-before-change
[task 2021-03-17T21:26:50.282Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker OS.File: flush I/O queued before profileBeforeChange for phase profile-before-change
[task 2021-03-17T21:26:50.283Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker JSON store: writing data for phase profile-before-change
[task 2021-03-17T21:26:50.284Z] 21:26:50 INFO - PID 3316 | DEBUG: Finished phase profile-before-change
[task 2021-03-17T21:26:50.306Z] 21:26:50 INFO - PID 3316 | DEBUG: Starting phase profile-before-change-telemetry
[task 2021-03-17T21:26:50.307Z] 21:26:50 INFO - PID 3316 | DEBUG: Spinning the event loop
[task 2021-03-17T21:26:50.369Z] 21:26:50 INFO - PID 3316 | DEBUG: Adding blocker Waiting for ping task for phase TelemetryController: Waiting for pending ping activity
[task 2021-03-17T21:26:50.374Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker Waiting for ping task for phase TelemetryController: Waiting for pending ping activity
[task 2021-03-17T21:26:50.382Z] 21:26:50 INFO - PID 3316 | DEBUG: Adding blocker Waiting for ping task for phase TelemetryController: Waiting for pending ping activity
[task 2021-03-17T21:26:50.390Z] 21:26:50 INFO - PID 3316 | DEBUG: Adding blocker Waiting for ping task for phase TelemetryController: Waiting for pending ping activity
[task 2021-03-17T21:26:50.393Z] 21:26:50 INFO - PID 3316 | DEBUG: Adding blocker Waiting for ping task for phase TelemetryController: Waiting for pending ping activity
[task 2021-03-17T21:26:50.400Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker Waiting for ping task for phase TelemetryController: Waiting for pending ping activity
[task 2021-03-17T21:26:50.402Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker Waiting for ping task for phase TelemetryController: Waiting for pending ping activity
[task 2021-03-17T21:26:50.405Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker Waiting for ping task for phase TelemetryController: Waiting for pending ping activity
[task 2021-03-17T21:26:50.407Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker TelemetryController: shutting down for phase profile-before-change-telemetry
[task 2021-03-17T21:26:50.408Z] 21:26:50 INFO - PID 3316 | DEBUG: Finished phase profile-before-change-telemetry
[task 2021-03-17T21:26:50.412Z] 21:26:50 INFO - PID 3316 | 1616016410412 Marionette TRACE Received observer notification xpcom-will-shutdown
[task 2021-03-17T21:26:50.414Z] 21:26:50 INFO - PID 3316 | 1616016410412 Marionette DEBUG Resetting recommended pref apz.content_response_timeout
[task 2021-03-17T21:26:50.415Z] 21:26:50 INFO - PID 3316 | 1616016410412 Marionette DEBUG Resetting recommended pref browser.contentblocking.introCount
[task 2021-03-17T21:26:50.416Z] 21:26:50 INFO - PID 3316 | 1616016410412 Marionette DEBUG Resetting recommended pref browser.download.panel.shown
[task 2021-03-17T21:26:50.417Z] 21:26:50 INFO - PID 3316 | 1616016410412 Marionette DEBUG Resetting recommended pref browser.newtabpage.enabled
[task 2021-03-17T21:26:50.418Z] 21:26:50 INFO - PID 3316 | 1616016410413 Marionette DEBUG Resetting recommended pref browser.pagethumbnails.capturing_disabled
[task 2021-03-17T21:26:50.420Z] 21:26:50 INFO - PID 3316 | 1616016410413 Marionette DEBUG Resetting recommended pref browser.search.update
[task 2021-03-17T21:26:50.421Z] 21:26:50 INFO - PID 3316 | 1616016410413 Marionette DEBUG Resetting recommended pref browser.tabs.disableBackgroundZombification
[task 2021-03-17T21:26:50.421Z] 21:26:50 INFO - PID 3316 | 1616016410413 Marionette DEBUG Resetting recommended pref browser.tabs.remote.separatePrivilegedContentProcess
[task 2021-03-17T21:26:50.422Z] 21:26:50 INFO - PID 3316 | 1616016410413 Marionette DEBUG Resetting recommended pref browser.tabs.unloadOnLowMemory
[task 2021-03-17T21:26:50.423Z] 21:26:50 INFO - PID 3316 | 1616016410413 Marionette DEBUG Resetting recommended pref browser.tabs.warnOnCloseOtherTabs
[task 2021-03-17T21:26:50.424Z] 21:26:50 INFO - PID 3316 | 1616016410414 Marionette DEBUG Resetting recommended pref browser.tabs.warnOnOpen
[task 2021-03-17T21:26:50.425Z] 21:26:50 INFO - PID 3316 | 1616016410414 Marionette DEBUG Resetting recommended pref browser.toolbars.bookmarks.visibility
[task 2021-03-17T21:26:50.426Z] 21:26:50 INFO - PID 3316 | 1616016410414 Marionette DEBUG Resetting recommended pref browser.usedOnWindows10.introURL
[task 2021-03-17T21:26:50.427Z] 21:26:50 INFO - PID 3316 | 1616016410414 Marionette DEBUG Resetting recommended pref browser.urlbar.suggest.searches
[task 2021-03-17T21:26:50.427Z] 21:26:50 INFO - PID 3316 | 1616016410415 Marionette DEBUG Resetting recommended pref datareporting.policy.dataSubmissionPolicyAccepted
[task 2021-03-17T21:26:50.428Z] 21:26:50 INFO - PID 3316 | 1616016410415 Marionette DEBUG Resetting recommended pref dom.disable_beforeunload
[task 2021-03-17T21:26:50.429Z] 21:26:50 INFO - PID 3316 | 1616016410415 Marionette DEBUG Resetting recommended pref dom.disable_open_during_load
[task 2021-03-17T21:26:50.430Z] 21:26:50 INFO - PID 3316 | 1616016410415 Marionette DEBUG Resetting recommended pref dom.file.createInChild
[task 2021-03-17T21:26:50.430Z] 21:26:50 INFO - PID 3316 | 1616016410415 Marionette DEBUG Resetting recommended pref dom.max_chrome_script_run_time
[task 2021-03-17T21:26:50.431Z] 21:26:50 INFO - PID 3316 | 1616016410415 Marionette DEBUG Resetting recommended pref dom.max_script_run_time
[task 2021-03-17T21:26:50.432Z] 21:26:50 INFO - PID 3316 | 1616016410416 Marionette DEBUG Resetting recommended pref dom.push.connection.enabled
[task 2021-03-17T21:26:50.433Z] 21:26:50 INFO - PID 3316 | 1616016410416 Marionette DEBUG Resetting recommended pref extensions.getAddons.cache.enabled
[task 2021-03-17T21:26:50.434Z] 21:26:50 INFO - PID 3316 | 1616016410416 Marionette DEBUG Resetting recommended pref extensions.getAddons.discovery.api_url
[task 2021-03-17T21:26:50.435Z] 21:26:50 INFO - PID 3316 | 1616016410416 Marionette DEBUG Resetting recommended pref network.http.prompt-temp-redirect
[task 2021-03-17T21:26:50.436Z] 21:26:50 INFO - PID 3316 | 1616016410416 Marionette DEBUG Resetting recommended pref privacy.trackingprotection.enabled
[task 2021-03-17T21:26:50.437Z] 21:26:50 INFO - PID 3316 | 1616016410416 Marionette DEBUG Resetting recommended pref prompts.contentPromptSubDialog
[task 2021-03-17T21:26:50.438Z] 21:26:50 INFO - PID 3316 | 1616016410416 Marionette DEBUG Resetting recommended pref security.fileuri.strict_origin_policy
[task 2021-03-17T21:26:50.438Z] 21:26:50 INFO - PID 3316 | 1616016410416 Marionette DEBUG Resetting recommended pref security.notification_enable_delay
[task 2021-03-17T21:26:50.439Z] 21:26:50 INFO - PID 3316 | 1616016410417 Marionette DEBUG Resetting recommended pref signon.autofillForms
[task 2021-03-17T21:26:50.440Z] 21:26:50 INFO - PID 3316 | 1616016410417 Marionette DEBUG Resetting recommended pref signon.rememberSignons
[task 2021-03-17T21:26:50.441Z] 21:26:50 INFO - PID 3316 | 1616016410418 Marionette DEBUG Marionette stopped listening
[task 2021-03-17T21:26:50.442Z] 21:26:50 INFO - PID 3316 | DEBUG: Starting phase xpcom-will-shutdown
[task 2021-03-17T21:26:50.442Z] 21:26:50 INFO - PID 3316 | DEBUG: Spinning the event loop
[task 2021-03-17T21:26:50.443Z] 21:26:50 INFO - PID 3316 | DEBUG: Completed blocker OS.File: flush pending requests, warn about unclosed files, shut down service. for phase xpcom-will-shutdown
[task 2021-03-17T21:26:50.466Z] 21:26:50 INFO - PID 3316 | DEBUG: Finished phase xpcom-will-shutdown
[task 2021-03-17T21:26:50.470Z] 21:26:50 INFO - PID 3316 |
[task 2021-03-17T21:26:50.471Z] 21:26:50 INFO - PID 3316 | ###!!! [Child][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-03-17T21:26:50.475Z] 21:26:50 INFO - PID 3316 |
[task 2021-03-17T21:26:50.475Z] 21:26:50 INFO - PID 3316 | DEBUG: Starting phase web-workers-shutdown
[task 2021-03-17T21:26:50.475Z] 21:26:50 INFO - PID 3316 | DEBUG: Spinning the event loop
[task 2021-03-17T21:26:50.476Z] 21:26:50 INFO - PID 3316 | DEBUG: Finished phase web-workers-shutdown
[task 2021-03-17T21:26:50.611Z] 21:26:50 INFO - PID 3316 | 1616016410610 geckodriver::marionette DEBUG Browser process stopped: exit code: 0
[task 2021-03-17T21:26:50.631Z] 21:26:50 INFO - PID 3316 | 1616016410628 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2021-03-17T21:26:50.633Z] 21:26:50 INFO - STDOUT: ================================== FAILURES ===================================
[task 2021-03-17T21:26:50.634Z] 21:26:50 INFO - STDOUT: _____________________ test_valid[pageLoadStrategy-normal] _____________________
[task 2021-03-17T21:26:50.635Z] 21:26:50 INFO - STDOUT: new_session = <function fixture_new_session.<locals>.new_session at 0x000002554FB1BF28>
[task 2021-03-17T21:26:50.640Z] 21:26:50 INFO -
[task 2021-03-17T21:26:50.640Z] 21:26:50 INFO - TEST-PASS | /webdriver/tests/new_session/create_firstMatch.py | test_valid[acceptInsecureCerts-False]
[task 2021-03-17T21:26:50.640Z] 21:26:50 INFO - TEST-PASS | /webdriver/tests/new_session/create_firstMatch.py | test_valid[acceptInsecureCerts-None]
[task 2021-03-17T21:26:50.640Z] 21:26:50 INFO - TEST-PASS | /webdriver/tests/new_session/create_firstMatch.py | test_valid[browserName-None]
[task 2021-03-17T21:26:50.640Z] 21:26:50 INFO - TEST-PASS | /webdriver/tests/new_session/create_firstMatch.py | test_valid[browserVersion-None]
[task 2021-03-17T21:26:50.640Z] 21:26:50 INFO - TEST-PASS | /webdriver/tests/new_session/create_firstMatch.py | test_valid[platformName-None]
[task 2021-03-17T21:26:50.641Z] 21:26:50 INFO - TEST-PASS | /webdriver/tests/new_session/create_firstMatch.py | test_valid[pageLoadStrategy-None]
[task 2021-03-17T21:26:50.641Z] 21:26:50 INFO - TEST-PASS | /webdriver/tests/new_session/create_firstMatch.py | test_valid[pageLoadStrategy-none]
[task 2021-03-17T21:26:50.641Z] 21:26:50 INFO - TEST-PASS | /webdriver/tests/new_session/create_firstMatch.py | test_valid[pageLoadStrategy-eager]
[task 2021-03-17T21:26:50.641Z] 21:26:50 INFO - TEST-UNEXPECTED-FAIL | /webdriver/tests/new_session/create_firstMatch.py | test_valid[pageLoadStrategy-normal] - AssertionError: timeout (500): No connection could be made because the target machine actively refused it. (os error 10061)
[task 2021-03-17T21:26:50.641Z] 21:26:50 INFO - new_session = <function fixture_new_session.<locals>.new_session at 0x000002554FB1BF28>
[task 2021-03-17T21:26:50.641Z] 21:26:50 INFO - add_browser_capabilities = <function fixture_add_browser_capabilities.<locals>.add_browser_capabilities at 0x000002554FB1B048>
[task 2021-03-17T21:26:50.641Z] 21:26:50 INFO - key = 'pageLoadStrategy', value = 'normal'
[task 2021-03-17T21:26:50.641Z] 21:26:50 INFO -
[task 2021-03-17T21:26:50.641Z] 21:26:50 INFO - @pytest.mark.parametrize("key,value", flatten(product(*item) for item in valid_data))
[task 2021-03-17T21:26:50.641Z] 21:26:50 INFO - def test_valid(new_session, add_browser_capabilities, key, value):
[task 2021-03-17T21:26:50.641Z] 21:26:50 INFO - response, _ = new_session({"capabilities": {
[task 2021-03-17T21:26:50.641Z] 21:26:50 INFO - "firstMatch": [add_browser_capabilities({key: value})]}})
[task 2021-03-17T21:26:50.641Z] 21:26:50 INFO - > assert_success(response)
[task 2021-03-17T21:26:50.641Z] 21:26:50 INFO -
[task 2021-03-17T21:26:50.641Z] 21:26:50 INFO - _ = None
[task 2021-03-17T21:26:50.641Z] 21:26:50 INFO - add_browser_capabilities = <function fixture_add_browser_capabilities.<locals>.add_browser_capabilities at 0x000002554FB1B048>
[task 2021-03-17T21:26:50.641Z] 21:26:50 INFO - key = 'pageLoadStrategy'
[task 2021-03-17T21:26:50.641Z] 21:26:50 INFO - new_session = <function fixture_new_session.<locals>.new_session at 0x000002554FB1BF28>
[task 2021-03-17T21:26:50.641Z] 21:26:50 INFO - response = <Response status=500 error=<TimeoutException http_status=500>>
[task 2021-03-17T21:26:50.641Z] 21:26:50 INFO - value = 'normal'
[task 2021-03-17T21:26:50.641Z] 21:26:50 INFO -
[task 2021-03-17T21:26:50.641Z] 21:26:50 INFO - tests\web-platform\tests\webdriver\tests\new_session\create_firstMatch.py:16:
[task 2021-03-17T21:26:50.642Z] 21:26:50 INFO - _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
[task 2021-03-17T21:26:50.642Z] 21:26:50 INFO -
[task 2021-03-17T21:26:50.642Z] 21:26:50 INFO - response = <Response status=500 error=<TimeoutException http_status=500>>
[task 2021-03-17T21:26:50.642Z] 21:26:50 INFO - value = None
[task 2021-03-17T21:26:50.642Z] 21:26:50 INFO -
[task 2021-03-17T21:26:50.642Z] 21:26:50 INFO - def assert_success(response, value=None):
[task 2021-03-17T21:26:50.642Z] 21:26:50 INFO - """
[task 2021-03-17T21:26:50.642Z] 21:26:50 INFO - Verify that the provided webdriver.Response instance described
[task 2021-03-17T21:26:50.642Z] 21:26:50 INFO - a valid success response as defined by `dfn-send-a-response` and
[task 2021-03-17T21:26:50.642Z] 21:26:50 INFO - the provided response value.
[task 2021-03-17T21:26:50.642Z] 21:26:50 INFO -
[task 2021-03-17T21:26:50.642Z] 21:26:50 INFO - :param response: ``webdriver.Response`` instance.
[task 2021-03-17T21:26:50.642Z] 21:26:50 INFO - :param value: Expected value of the response body, if any.
[task 2021-03-17T21:26:50.642Z] 21:26:50 INFO - """
[task 2021-03-17T21:26:50.642Z] 21:26:50 INFO - > assert response.status == 200, str(response.error)
[task 2021-03-17T21:26:50.642Z] 21:26:50 INFO - E AssertionError: timeout (500): No connection could be made because the target machine actively refused it. (os error 10061)
[task 2021-03-17T21:26:50.642Z] 21:26:50 INFO - E
[task 2021-03-17T21:26:50.642Z] 21:26:50 INFO - E assert 500 == 200
[task 2021-03-17T21:26:50.642Z] 21:26:50 INFO - E +500
[task 2021-03-17T21:26:50.642Z] 21:26:50 INFO - E -200
[task 2021-03-17T21:26:50.642Z] 21:26:50 INFO -
[task 2021-03-17T21:26:50.643Z] 21:26:50 INFO - response = <Response status=500 error=<TimeoutException http_status=500>>
[task 2021-03-17T21:26:50.643Z] 21:26:50 INFO - value = None
[task 2021-03-17T21:26:50.643Z] 21:26:50 INFO -
[task 2021-03-17T21:26:50.643Z] 21:26:50 INFO - tests\web-platform\tests\webdriver\tests\support\asserts.py:74: AssertionError
[task 2021-03-17T21:26:50.650Z] 21:26:50 INFO - ..................
[task 2021-03-17T21:26:50.650Z] 21:26:50 INFO - TEST-OK | /webdriver/tests/new_session/create_firstMatch.py | took 155190ms```
|
||
Updated•5 years ago
|
Status: NEW → RESOLVED
Closed: 5 years ago
Resolution: --- → DUPLICATE
|
||
Comment 2•3 years ago
|
||
Moving bug to Remote Protocol::Marionette component per bug 1815831.
Component: geckodriver → Marionette
Product: Testing → Remote Protocol
You need to log in
before you can comment on or make changes to this bug.
Description
•