1609344 - Perma Tier 2 Windows 10 TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/delete_session/delete.py | expected OK

Status: RESOLVED DUPLICATE of bug 1608082

(Testing :: geckodriver, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: btara [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=284600558&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/UWQ_yLobTXyIfuXxEHrFqQ/runs/0/artifacts/public/logs/live_backing.log

---

[task 2020-01-13T00:28:38.989Z] 00:28:38 INFO - TEST-START | /webdriver/tests/delete_session/delete.py
[task 2020-01-13T00:28:39.048Z] 00:28:39 INFO - STDOUT: ============================= test session starts =============================
[task 2020-01-13T00:28:39.048Z] 00:28:39 INFO - STDOUT: platform win32 -- Python 2.7.15, pytest-unknown, py-1.5.2, pluggy-0.5.3.dev -- Z:\task_1578874668\build\venv\Scripts\python.exe
[task 2020-01-13T00:28:39.048Z] 00:28:39 INFO - STDOUT: rootdir: Z:\task_1578874668\build, inifile:
[task 2020-01-13T00:28:39.048Z] 00:28:39 INFO - STDOUT: collecting ...
[task 2020-01-13T00:28:39.053Z] 00:28:39 INFO - STDOUT: collected 2 items
[task 2020-01-13T00:28:39.053Z] 00:28:39 INFO - STDOUT: tests/web-platform/tests/webdriver/tests/delete_session/delete.py::test_null_response_value
[task 2020-01-13T00:28:39.063Z] 00:28:39 INFO - PID 2448 | 1578875319051 webdriver::server DEBUG -> POST /session/be76d588-5255-4530-85bc-abfeb66e927c/window/rect {"width": 800, "height": 600}
[task 2020-01-13T00:28:39.064Z] 00:28:39 INFO - PID 2448 | 1578875319053 Marionette DEBUG 0 -> [0,77,"WebDriver:SetWindowRect",{"height":600,"width":800}]
[task 2020-01-13T00:28:39.064Z] 00:28:39 INFO - PID 2448 | 1578875319055 Marionette DEBUG 0 <- [1,77,null,{"x":100,"y":100,"width":800,"height":600}]
[task 2020-01-13T00:28:39.064Z] 00:28:39 INFO - PID 2448 | 1578875319055 webdriver::server DEBUG <- 200 OK {"value":{"x":100,"y":100,"width":800,"height":600}}
[task 2020-01-13T00:28:39.064Z] 00:28:39 INFO - PID 2448 | 1578875319055 webdriver::server DEBUG -> POST /session/be76d588-5255-4530-85bc-abfeb66e927c/window/rect {"y": 100, "x": 100}
[task 2020-01-13T00:28:39.065Z] 00:28:39 INFO - PID 2448 | 1578875319058 Marionette DEBUG 0 -> [0,78,"WebDriver:SetWindowRect",{"x":100,"y":100}]
[task 2020-01-13T00:28:39.065Z] 00:28:39 INFO - PID 2448 | 1578875319059 Marionette DEBUG 0 <- [1,78,null,{"x":100,"y":100,"width":800,"height":600}]
[task 2020-01-13T00:28:39.065Z] 00:28:39 INFO - PID 2448 | 1578875319059 webdriver::server DEBUG <- 200 OK {"value":{"x":100,"y":100,"width":800,"height":600}}
[task 2020-01-13T00:28:39.065Z] 00:28:39 INFO - PID 2448 | 1578875319061 webdriver::server DEBUG -> DELETE /session/be76d588-5255-4530-85bc-abfeb66e927c
[task 2020-01-13T00:28:39.070Z] 00:28:39 INFO - PID 2448 | 1578875319063 Marionette DEBUG 0 -> [0,79,"Marionette:Quit",{"flags":["eForceQuit"]}]
[task 2020-01-13T00:28:39.070Z] 00:28:39 INFO - PID 2448 | 1578875319064 Marionette INFO Stopped listening on port 2828
[task 2020-01-13T00:28:39.172Z] 00:28:39 INFO - PID 2448 | 1578875319161 Marionette TRACE Received observer notification quit-application
[task 2020-01-13T00:28:39.183Z] 00:28:39 INFO - PID 2448 | 1578875319173 Marionette DEBUG 0 <- [1,79,null,{"cause":"shutdown"}]
[task 2020-01-13T00:28:39.254Z] 00:28:39 INFO - PID 2448 | 1578875319241 webdriver::server DEBUG Deleting session
[task 2020-01-13T00:28:39.273Z] 00:28:39 INFO - PID 2448 | 1578875319265 Marionette DEBUG 0 -> [0,80,"Marionette:Quit",{"flags":["eForceQuit"]}]
[task 2020-01-13T00:28:39.273Z] 00:28:39 INFO - PID 2448 | 1578875319266 Marionette DEBUG 0 <- [1,80,{"error":"invalid session id","message":"Tried to run command without establishing a connection","stacktrace":"WebDrive ... t@chrome://marionette/content/server.js:249:9\n_onJSONObjectReady/<@chrome://marionette/content/transport.js:501:20\n"},null]
[task 2020-01-13T00:28:39.274Z] 00:28:39 INFO - PID 2448 |
[task 2020-01-13T00:28:39.274Z] 00:28:39 INFO - PID 2448 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2020-01-13T00:28:39.274Z] 00:28:39 INFO - PID 2448 |
[task 2020-01-13T00:28:39.292Z] 00:28:39 INFO - PID 2448 |
[task 2020-01-13T00:28:39.292Z] 00:28:39 INFO - PID 2448 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2020-01-13T00:28:39.292Z] 00:28:39 INFO - PID 2448 |
[task 2020-01-13T00:28:39.293Z] 00:28:39 INFO - PID 2448 | 1578875319283 Marionette DEBUG Closed connection 0
[task 2020-01-13T00:28:39.293Z] 00:28:39 INFO - PID 2448 |
[task 2020-01-13T00:28:39.293Z] 00:28:39 INFO - PID 2448 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2020-01-13T00:28:39.293Z] 00:28:39 INFO - PID 2448 |
[task 2020-01-13T00:28:39.423Z] 00:28:39 INFO - PID 2448 |
[task 2020-01-13T00:28:39.423Z] 00:28:39 INFO - PID 2448 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2020-01-13T00:28:39.424Z] 00:28:39 INFO - PID 2448 |
[task 2020-01-13T00:28:39.809Z] 00:28:39 INFO - PID 2448 | 1578875319803 Marionette TRACE Received observer notification xpcom-will-shutdown
[task 2020-01-13T00:28:39.809Z] 00:28:39 INFO - PID 2448 | 1578875319803 Marionette DEBUG Resetting recommended pref apz.content_response_timeout
[task 2020-01-13T00:28:39.810Z] 00:28:39 INFO - PID 2448 | 1578875319803 Marionette DEBUG Resetting recommended pref browser.contentblocking.introCount
[task 2020-01-13T00:28:39.810Z] 00:28:39 INFO - PID 2448 | 1578875319804 Marionette DEBUG Resetting recommended pref browser.download.panel.shown
[task 2020-01-13T00:28:39.811Z] 00:28:39 INFO - PID 2448 | 1578875319804 Marionette DEBUG Resetting recommended pref browser.newtabpage.enabled
[task 2020-01-13T00:28:39.812Z] 00:28:39 INFO - PID 2448 | 1578875319805 Marionette DEBUG Resetting recommended pref browser.pagethumbnails.capturing_disabled
[task 2020-01-13T00:28:39.813Z] 00:28:39 INFO - PID 2448 | 1578875319805 Marionette DEBUG Resetting recommended pref browser.search.update
[task 2020-01-13T00:28:39.814Z] 00:28:39 INFO - PID 2448 | 1578875319806 Marionette DEBUG Resetting recommended pref browser.tabs.disableBackgroundZombification
[task 2020-01-13T00:28:39.814Z] 00:28:39 INFO - PID 2448 | 1578875319806 Marionette DEBUG Resetting recommended pref browser.tabs.remote.separatePrivilegedContentProcess
[task 2020-01-13T00:28:39.815Z] 00:28:39 INFO - PID 2448 | 1578875319806 Marionette DEBUG Resetting recommended pref browser.tabs.unloadOnLowMemory
[task 2020-01-13T00:28:39.816Z] 00:28:39 INFO - PID 2448 | 1578875319806 Marionette DEBUG Resetting recommended pref browser.tabs.warnOnCloseOtherTabs
[task 2020-01-13T00:28:39.816Z] 00:28:39 INFO - PID 2448 | 1578875319807 Marionette DEBUG Resetting recommended pref browser.tabs.warnOnOpen
[task 2020-01-13T00:28:39.817Z] 00:28:39 INFO - PID 2448 | 1578875319807 Marionette DEBUG Resetting recommended pref browser.usedOnWindows10.introURL
[task 2020-01-13T00:28:39.817Z] 00:28:39 INFO - PID 2448 | 1578875319807 Marionette DEBUG Resetting recommended pref browser.urlbar.suggest.searches
[task 2020-01-13T00:28:39.818Z] 00:28:39 INFO - PID 2448 | 1578875319808 Marionette DEBUG Resetting recommended pref datareporting.policy.dataSubmissionPolicyAccepted
[task 2020-01-13T00:28:39.819Z] 00:28:39 INFO - PID 2448 | 1578875319808 Marionette DEBUG Resetting recommended pref dom.disable_beforeunload
[task 2020-01-13T00:28:39.820Z] 00:28:39 INFO - PID 2448 | 1578875319809 Marionette DEBUG Resetting recommended pref dom.disable_open_during_load
[task 2020-01-13T00:28:39.820Z] 00:28:39 INFO - PID 2448 | 1578875319809 Marionette DEBUG Resetting recommended pref dom.file.createInChild
[task 2020-01-13T00:28:39.821Z] 00:28:39 INFO - PID 2448 | 1578875319809 Marionette DEBUG Resetting recommended pref dom.max_chrome_script_run_time
[task 2020-01-13T00:28:39.822Z] 00:28:39 INFO - PID 2448 | 1578875319810 Marionette DEBUG Resetting recommended pref dom.max_script_run_time
[task 2020-01-13T00:28:39.822Z] 00:28:39 INFO - PID 2448 | 1578875319811 Marionette DEBUG Resetting recommended pref dom.push.connection.enabled
[task 2020-01-13T00:28:39.823Z] 00:28:39 INFO - PID 2448 | 1578875319811 Marionette DEBUG Resetting recommended pref extensions.getAddons.cache.enabled
[task 2020-01-13T00:28:39.823Z] 00:28:39 INFO - PID 2448 | 1578875319812 Marionette DEBUG Resetting recommended pref extensions.webservice.discoverURL
[task 2020-01-13T00:28:39.824Z] 00:28:39 INFO - PID 2448 | 1578875319812 Marionette DEBUG Resetting recommended pref network.http.prompt-temp-redirect
[task 2020-01-13T00:28:39.825Z] 00:28:39 INFO - PID 2448 | 1578875319812 Marionette DEBUG Resetting recommended pref network.http.speculative-parallel-limit
[task 2020-01-13T00:28:39.825Z] 00:28:39 INFO - PID 2448 | 1578875319812 Marionette DEBUG Resetting recommended pref privacy.trackingprotection.enabled
[task 2020-01-13T00:28:39.826Z] 00:28:39 INFO - PID 2448 | 1578875319812 Marionette DEBUG Resetting recommended pref security.fileuri.strict_origin_policy
[task 2020-01-13T00:28:39.826Z] 00:28:39 INFO - PID 2448 | 1578875319813 Marionette DEBUG Resetting recommended pref security.notification_enable_delay
[task 2020-01-13T00:28:39.827Z] 00:28:39 INFO - PID 2448 | 1578875319813 Marionette DEBUG Resetting recommended pref signon.autofillForms
[task 2020-01-13T00:28:39.827Z] 00:28:39 INFO - PID 2448 | 1578875319814 Marionette DEBUG Resetting recommended pref signon.rememberSignons
[task 2020-01-13T00:28:39.827Z] 00:28:39 INFO - PID 2448 | 1578875319814 Marionette DEBUG Resetting recommended pref toolkit.cosmeticAnimations.enabled
[task 2020-01-13T00:28:39.827Z] 00:28:39 INFO - PID 2448 | 1578875319816 Marionette DEBUG Marionette stopped listening
[task 2020-01-13T00:28:39.927Z] 00:28:39 INFO - PID 2448 |
[task 2020-01-13T00:28:39.927Z] 00:28:39 INFO - PID 2448 | ###!!! [Child][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2020-01-13T00:28:39.927Z] 00:28:39 INFO - PID 2448 |
[task 2020-01-13T00:28:50.862Z] 00:28:50 INFO - PID 2448 | 1578875330835 geckodriver::marionette DEBUG Browser process stopped: exit code: 0
[task 2020-01-13T00:28:50.864Z] 00:28:50 INFO - STDOUT: PASSED
[task 2020-01-13T00:28:50.864Z] 00:28:50 INFO - PID 2448 | 1578875330859 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2020-01-13T00:28:50.864Z] 00:28:50 INFO - PID 2448 | 1578875330860 webdriver::server DEBUG -> DELETE /session/be76d588-5255-4530-85bc-abfeb66e927c
[task 2020-01-13T00:28:50.865Z] 00:28:50 INFO - PID 2448 | 1578875330860 webdriver::server DEBUG <- 404 Not Found {"value":{"error":"invalid session id","message":"Tried to run command without establishing a connection","stacktrace":""}}
[task 2020-01-13T00:28:50.867Z] 00:28:50 INFO - STDERR: Ignored exception invalid session id (404): Tried to run command without establishing a connection
[task 2020-01-13T00:28:50.868Z] 00:28:50 INFO - PID 2448 | 1578875330862 webdriver::server DEBUG -> POST /session/None/timeouts {"implicit": 0}
[task 2020-01-13T00:28:50.868Z] 00:28:50 INFO - PID 2448 | 1578875330862 webdriver::server DEBUG <- 404 Not Found {"value":{"error":"invalid session id","message":"Tried to run command without establishing a connection","stacktrace":""}}
[task 2020-01-13T00:28:50.869Z] 00:28:50 INFO - PID 2448 | 1578875330863 webdriver::server DEBUG -> POST /session {"capabilities": {"alwaysMatch": {"moz:firefoxOptions": {"binary": "Z:\task_1578874668\build\application\firefox\firefox.exe", "prefs": {"media.peerconnection.mtransport_process": false, "network.dns.localDomains": "www1.xn--n8j6ds53lwwkrqhv28a.web-platform.test,xn--lve-6lad.www1.web-platform.test,www.www2.not-web-platform.test,www2.www2.not-web-platform.test,xn--lve-6lad.www.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,www.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.www.not-web-platform.test,not-web-platform.test,www1.www.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.www1.web-platform.test,www2.not-web-platform.test,www1.not-web-platform.test,www1.www1.web-platform.test,www2.xn--lve-6lad.web-platform.test,www1.xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.xn--n8j6ds53lwwkrqhv28a.web-platform.test,www1.www2.web-platform.test,xn--lve-6lad.xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,xn--lve-6lad.xn--lve-6lad.not-web-platform.test,www2.www1.not-web-platform.test,www2.xn--n8j6ds53lwwkrqhv28a.web-platform.test,www.xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,web-platform.test,xn--n8j6ds53lwwkrqhv28a.xn--lve-6lad.not-web-platform.test,xn--lve-6lad.www.web-platform.test,www.www.web-platform.test,www1.xn--lve-6lad.web-platform.test,xn--lve-6lad.www2.web-platform.test,www.www2.web-platform.test,www2.www.web-platform.test,xn--n8j6ds53lwwkrqhv28a.www2.not-web-platform.test,www1.www.web-platform.test,www.xn--lve-6lad.web-platform.test,www.www.not-web-platform.test,xn--lve-6lad.xn--lve-6lad.web-platform.test,xn--lve-6lad.www1.not-web-platform.test,www1.www1.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.www2.web-platform.test,xn--n8j6ds53lwwkrqhv28a.www1.not-web-platform.test,www2.www2.web-platform.test,xn--lve-6lad.web-platform.test,xn--n8j6ds53lwwkrqhv28a.web-platform.test,xn--n8j6ds53lwwkrqhv28a.www.web-platform.test,xn--lve-6lad.not-web-platform.test,www2.xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,www2.xn--lve-6lad.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.xn--lve-6lad.web-platform.test,www1.xn--lve-6lad.not-web-platform.test,www1.web-platform.test,www.www1.web-platform.test,www2.web-platform.test,www.xn--lve-6lad.not-web-platform.test,www.web-platform.test,xn--lve-6lad.xn--n8j6ds53lwwkrqhv28a.web-platform.test,www1.www2.not-web-platform.test,www2.www1.web-platform.test,www.www1.not-web-platform.test,www.xn--n8j6ds53lwwkrqhv28a.web-platform.test,xn--lve-6lad.www2.not-web-platform.test,www2.www.not-web-platform.test", "network.process.enabled": false}}}}}
[task 2020-01-13T00:28:50.871Z] 00:28:50 INFO - PID 2448 | 1578875330867 mozrunner::runner INFO Running command: "Z:\task_1578874668\build\application\firefox\firefox.exe" "-marionette" "-foreground" "-no-remote" "-profile" "C:\Users\task_1578874668\AppData\Local\Temp\rust_mozprofileSVySXR"
[task 2020-01-13T00:28:50.872Z] 00:28:50 INFO - PID 2448 | 1578875330868 geckodriver::marionette DEBUG Waiting 60s to connect to browser on 127.0.0.1:2828
[task 2020-01-13T00:28:51.732Z] 00:28:51 INFO - PID 2448 | 1578875331712 [e-mail] WARN Loading extension '[e-mail]': Reading manifest: Invalid extension permission: networkStatus
[task 2020-01-13T00:28:53.063Z] 00:28:53 INFO - PID 2448 | 1578875333046 [e-mail] WARN Loading extension '[e-mail]': Reading manifest: Invalid extension permission: mozillaAddons
[task 2020-01-13T00:28:53.063Z] 00:28:53 INFO - PID 2448 | 1578875333046 [e-mail] WARN Loading extension '[e-mail]': Reading manifest: Invalid extension permission: telemetry
[task 2020-01-13T00:28:53.063Z] 00:28:53 INFO - PID 2448 | 1578875333047 [e-mail] WARN Loading extension '[e-mail]': Reading manifest: Invalid extension permission: resource://pdf.js/
[task 2020-01-13T00:28:53.064Z] 00:28:53 INFO - PID 2448 | 1578875333047 [e-mail] WARN Loading extension '[e-mail]': Reading manifest: Invalid extension permission: about:reader*
[task 2020-01-13T00:28:53.369Z] 00:28:53 INFO - PID 2448 | 1578875333356 Marionette TRACE Received observer notification profile-after-change
[task 2020-01-13T00:28:53.448Z] 00:28:53 INFO - PID 2448 | 1578875333431 Marionette TRACE Received observer notification toplevel-window-ready
[task 2020-01-13T00:28:53.506Z] 00:28:53 INFO - PID 2448 | 1578875333498 Marionette TRACE Received observer notification command-line-startup
[task 2020-01-13T00:28:53.506Z] 00:28:53 INFO - PID 2448 | 1578875333498 Marionette DEBUG Init aborted (running=false, enabled=true, finalUIStartup=false)
[task 2020-01-13T00:28:53.637Z] 00:28:53 INFO - PID 2448 | 1578875333626 Marionette TRACE Received observer notification toplevel-window-ready
[task 2020-01-13T00:28:57.532Z] 00:28:57 INFO - PID 2448 | 1578875337517 Marionette TRACE Received observer notification marionette-startup-requested
[task 2020-01-13T00:28:57.532Z] 00:28:57 INFO - PID 2448 | 1578875337518 Marionette TRACE Waiting until startup recorder finished recording startup scripts...
[task 2020-01-13T00:28:57.683Z] 00:28:57 INFO - PID 2448 | 1578875337657 Marionette TRACE All scripts recorded.
[task 2020-01-13T00:28:57.684Z] 00:28:57 INFO - PID 2448 | 1578875337657 Marionette DEBUG Setting recommended pref apz.content_response_timeout to 60000
[task 2020-01-13T00:28:57.685Z] 00:28:57 INFO - PID 2448 | 1578875337658 Marionette DEBUG Setting recommended pref browser.contentblocking.introCount to 99
[task 2020-01-13T00:28:57.685Z] 00:28:57 INFO - PID 2448 | 1578875337658 Marionette DEBUG Setting recommended pref browser.download.panel.shown to true
[task 2020-01-13T00:28:57.686Z] 00:28:57 INFO - PID 2448 | 1578875337659 Marionette DEBUG Setting recommended pref browser.newtabpage.enabled to false
[task 2020-01-13T00:28:57.687Z] 00:28:57 INFO - PID 2448 | 1578875337661 Marionette DEBUG Setting recommended pref browser.pagethumbnails.capturing_disabled to true
[task 2020-01-13T00:28:57.687Z] 00:28:57 INFO - PID 2448 | 1578875337662 Marionette DEBUG Setting recommended pref browser.search.update to false
[task 2020-01-13T00:28:57.687Z] 00:28:57 INFO - PID 2448 | 1578875337663 Marionette DEBUG Setting recommended pref browser.tabs.disableBackgroundZombification to false
[task 2020-01-13T00:28:57.687Z] 00:28:57 INFO - PID 2448 | 1578875337664 Marionette DEBUG Setting recommended pref browser.tabs.remote.separatePrivilegedContentProcess to false
[task 2020-01-13T00:28:57.687Z] 00:28:57 INFO - PID 2448 | 1578875337664 Marionette DEBUG Setting recommended pref browser.tabs.unloadOnLowMemory to false
[task 2020-01-13T00:28:57.687Z] 00:28:57 INFO - PID 2448 | 1578875337664 Marionette DEBUG Setting recommended pref browser.tabs.warnOnCloseOtherTabs to false
[task 2020-01-13T00:28:57.687Z] 00:28:57 INFO - PID 2448 | 1578875337664 Marionette DEBUG Setting recommended pref browser.tabs.warnOnOpen to false
[task 2020-01-13T00:28:57.687Z] 00:28:57 INFO - PID 2448 | 1578875337665 Marionette DEBUG Setting recommended pref browser.usedOnWindows10.introURL to
[task 2020-01-13T00:28:57.688Z] 00:28:57 INFO - PID 2448 | 1578875337665 Marionette DEBUG Setting recommended pref browser.urlbar.suggest.searches to false
[task 2020-01-13T00:28:57.688Z] 00:28:57 INFO - PID 2448 | 1578875337669 Marionette DEBUG Setting recommended pref datareporting.policy.dataSubmissionPolicyAccepted to false
[task 2020-01-13T00:28:57.688Z] 00:28:57 INFO - PID 2448 | 1578875337669 Marionette DEBUG Setting recommended pref dom.disable_beforeunload to true
[task 2020-01-13T00:28:57.688Z] 00:28:57 INFO - PID 2448 | 1578875337669 Marionette DEBUG Setting recommended pref dom.disable_open_during_load to false
[task 2020-01-13T00:28:57.688Z] 00:28:57 INFO - PID 2448 | 1578875337670 Marionette DEBUG Setting recommended pref dom.file.createInChild to true
[task 2020-01-13T00:28:57.688Z] 00:28:57 INFO - PID 2448 | 1578875337670 Marionette DEBUG Setting recommended pref dom.max_chrome_script_run_time to 0
[task 2020-01-13T00:28:57.688Z] 00:28:57 INFO - PID 2448 | 1578875337671 Marionette DEBUG Setting recommended pref dom.max_script_run_time to 0
[task 2020-01-13T00:28:57.689Z] 00:28:57 INFO - PID 2448 | 1578875337673 Marionette DEBUG Setting recommended pref dom.push.connection.enabled to false
[task 2020-01-13T00:28:57.689Z] 00:28:57 INFO - PID 2448 | 1578875337674 Marionette DEBUG Setting recommended pref extensions.getAddons.cache.enabled to false
[task 2020-01-13T00:28:57.689Z] 00:28:57 INFO - PID 2448 | 1578875337674 Marionette DEBUG Setting recommended pref extensions.webservice.discoverURL to http://%(server)s/dummy/discoveryURL
[task 2020-01-13T00:28:57.689Z] 00:28:57 INFO - PID 2448 | 1578875337674 Marionette DEBUG Setting recommended pref network.http.prompt-temp-redirect to false
[task 2020-01-13T00:28:57.689Z] 00:28:57 INFO - PID 2448 | 1578875337675 Marionette DEBUG Setting recommended pref network.http.speculative-parallel-limit to 0
[task 2020-01-13T00:28:57.689Z] 00:28:57 INFO - PID 2448 | 1578875337675 Marionette DEBUG Setting recommended pref privacy.trackingprotection.enabled to false
[task 2020-01-13T00:28:57.689Z] 00:28:57 INFO - PID 2448 | 1578875337675 Marionette DEBUG Setting recommended pref security.fileuri.strict_origin_policy to false
[task 2020-01-13T00:28:57.689Z] 00:28:57 INFO - PID 2448 | 1578875337676 Marionette DEBUG Setting recommended pref security.notification_enable_delay to 0
[task 2020-01-13T00:28:57.690Z] 00:28:57 INFO - PID 2448 | 1578875337677 Marionette DEBUG Setting recommended pref signon.autofillForms to false
[task 2020-01-13T00:28:57.690Z] 00:28:57 INFO - PID 2448 | 1578875337677 Marionette DEBUG Setting recommended pref signon.rememberSignons to false
[task 2020-01-13T00:28:57.690Z] 00:28:57 INFO - PID 2448 | 1578875337678 Marionette DEBUG Setting recommended pref toolkit.cosmeticAnimations.enabled to false
[task 2020-01-13T00:28:57.834Z] 00:28:57 INFO - PID 2448 | 1578875337819 Marionette INFO Listening on port 2828
[task 2020-01-13T00:28:57.834Z] 00:28:57 INFO - PID 2448 | 1578875337820 Marionette DEBUG Marionette is listening
[task 2020-01-13T00:28:58.018Z] 00:28:58 INFO - PID 2448 | 1578875337995 Marionette DEBUG Accepted connection 0 from 127.0.0.1:50605
[task 2020-01-13T00:28:58.018Z] 00:28:58 INFO - PID 2448 | 1578875337996 geckodriver::marionette DEBUG Connection to Marionette established on 127.0.0.1:2828.
[task 2020-01-13T00:28:58.018Z] 00:28:58 INFO - PID 2448 | 1578875338000 Marionette DEBUG 0 -> [0,1,"WebDriver:NewSession",{}]
[task 2020-01-13T00:28:58.119Z] 00:28:58 INFO - PID 2448 | 1578875338108 Marionette TRACE [21] Frame script loaded
[task 2020-01-13T00:28:58.119Z] 00:28:58 INFO - PID 2448 | 1578875338112 Marionette TRACE [21] Frame script registered
[task 2020-01-13T00:28:58.137Z] 00:28:58 INFO - PID 2448 | 1578875338128 Marionette DEBUG 0 <- [1,1,null,{"sessionId":"9cd05308-ef94-4b5e-8a86-4f4deeec6756","capabilities":{"browserName":"firefox","browserVersion":"74.0a ... \rust_mozprofileSVySXR","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}]
[task 2020-01-13T00:28:58.147Z] 00:28:58 INFO - PID 2448 | 1578875338138 webdriver::server DEBUG <- 200 OK {"value":{"sessionId":"9cd05308-ef94-4b5e-8a86-4f4deeec6756","capabilities":{"acceptInsecureCerts":false,"browserName":"firefox","browserVersion":"74.0a1","moz:accessibilityChecks":false,"moz:buildID":"20200112214546","moz:geckodriverVersion":"0.26.0","moz:headless":false,"moz:processID":5756,"moz:profile":"C:\Users\task_1578874668\AppData\Local\Temp\rust_mozprofileSVySXR","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true,"pageLoadStrategy":"normal","platformName":"windows","platformVersion":"10.0","rotatable":false,"setWindowRect":true,"strictFileInteractability":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"unhandledPromptBehavior":"dismiss and notify"}}}
[task 2020-01-13T00:28:58.147Z] 00:28:58 INFO - PID 2448 | 1578875338140 webdriver::server DEBUG -> GET /session/9cd05308-ef94-4b5e-8a86-4f4deeec6756/window
[task 2020-01-13T00:28:58.148Z] 00:28:58 INFO - PID 2448 | 1578875338144 Marionette DEBUG 0 -> [0,2,"WebDriver:GetWindowHandle",{}]
[task 2020-01-13T00:28:58.150Z] 00:28:58 INFO - PID 2448 | 1578875338145 Marionette DEBUG 0 <- [1,2,null,{"value":"21"}]
[task 2020-01-13T00:28:58.151Z] 00:28:58 INFO - PID 2448 | 1578875338147 webdriver::server DEBUG <- 200 OK {"value":"21"}
[task 2020-01-13T00:28:58.151Z] 00:28:58 INFO - PID 2448 | 1578875338149 webdriver::server DEBUG -> GET /session/9cd05308-ef94-4b5e-8a86-4f4deeec6756/window
[task 2020-01-13T00:28:58.161Z] 00:28:58 INFO - PID 2448 | 1578875338152 Marionette DEBUG 0 -> [0,3,"WebDriver:GetWindowHandle",{}]
[task 2020-01-13T00:28:58.162Z] 00:28:58 INFO - PID 2448 | 1578875338153 Marionette DEBUG 0 <- [1,3,null,{"value":"21"}]
[task 2020-01-13T00:28:58.162Z] 00:28:58 INFO - PID 2448 | 1578875338154 webdriver::server DEBUG <- 200 OK {"value":"21"}
[task 2020-01-13T00:28:58.162Z] 00:28:58 INFO - PID 2448 | 1578875338156 webdriver::server DEBUG -> GET /session/9cd05308-ef94-4b5e-8a86-4f4deeec6756/window/handles
[task 2020-01-13T00:28:58.163Z] 00:28:58 INFO - PID 2448 | 1578875338158 Marionette DEBUG 0 -> [0,4,"WebDriver:GetWindowHandles",{}]
[task 2020-01-13T00:28:58.163Z] 00:28:58 INFO - PID 2448 | 1578875338159 Marionette DEBUG 0 <- [1,4,null,["21"]]
[task 2020-01-13T00:28:58.168Z] 00:28:58 INFO - PID 2448 | 1578875338163 webdriver::server DEBUG <- 200 OK {"value":["21"]}
[task 2020-01-13T00:28:58.168Z] 00:28:58 INFO - PID 2448 | 1578875338164 webdriver::server DEBUG -> POST /session/9cd05308-ef94-4b5e-8a86-4f4deeec6756/window {"handle": "21"}
[task 2020-01-13T00:28:58.173Z] 00:28:58 INFO - PID 2448 | 1578875338167 Marionette DEBUG 0 -> [0,5,"WebDriver:SwitchToWindow",{"handle":"21","name":"21"}]
[task 2020-01-13T00:28:58.173Z] 00:28:58 INFO - PID 2448 | 1578875338169 Marionette DEBUG 0 <- [1,5,null,{"value":null}]
[task 2020-01-13T00:28:58.173Z] 00:28:58 INFO - PID 2448 | 1578875338170 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2020-01-13T00:28:58.173Z] 00:28:58 INFO - PID 2448 | 1578875338171 webdriver::server DEBUG -> POST /session/9cd05308-ef94-4b5e-8a86-4f4deeec6756/alert/dismiss {}
[task 2020-01-13T00:28:58.178Z] 00:28:58 INFO - PID 2448 | 1578875338174 Marionette DEBUG 0 -> [0,6,"WebDriver:DismissAlert",{}]
[task 2020-01-13T00:28:58.180Z] 00:28:58 INFO - PID 2448 | 1578875338176 Marionette DEBUG 0 <- [1,6,{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://marionette/content/error.js:175:5\nNoSuchAle ... t@chrome://marionette/content/server.js:249:9\n_onJSONObjectReady/<@chrome://marionette/content/transport.js:501:20\n"},null]
[task 2020-01-13T00:28:58.182Z] 00:28:58 INFO - PID 2448 | 1578875338178 webdriver::server DEBUG <- 404 Not Found {"value":{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://marionette/content/error.js:175:5\nNoSuchAlertError@chrome://marionette/content/error.js:376:5\nGeckoDriver.prototype._checkIfAlertIsPresent@chrome://marionette/content/driver.js:3376:11\nGeckoDriver.prototype.dismissDialog@chrome://marionette/content/driver.js:3289:8\ndespatch@chrome://marionette/content/server.js:305:40\nexecute@chrome://marionette/content/server.js:275:16\nonPacket/<@chrome://marionette/content/server.js:248:20\nonPacket@chrome://marionette/content/server.js:249:9\n_onJSONObjectReady/<@chrome://marionette/content/transport.js:501:20\n"}}
[task 2020-01-13T00:28:58.182Z] 00:28:58 INFO - PID 2448 | 1578875338179 webdriver::server DEBUG -> POST /session/9cd05308-ef94-4b5e-8a86-4f4deeec6756/window {"handle": "21"}
[task 2020-01-13T00:28:58.184Z] 00:28:58 INFO - PID 2448 | 1578875338182 Marionette DEBUG 0 -> [0,7,"WebDriver:SwitchToWindow",{"handle":"21","name":"21"}]
[task 2020-01-13T00:28:58.186Z] 00:28:58 INFO - PID 2448 | 1578875338184 Marionette DEBUG 0 <- [1,7,null,{"value":null}]
[task 2020-01-13T00:28:58.188Z] 00:28:58 INFO - PID 2448 | 1578875338184 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2020-01-13T00:28:58.188Z] 00:28:58 INFO - PID 2448 | 1578875338185 webdriver::server DEBUG -> GET /session/9cd05308-ef94-4b5e-8a86-4f4deeec6756/window
[task 2020-01-13T00:28:58.193Z] 00:28:58 INFO - PID 2448 | 1578875338188 Marionette DEBUG 0 -> [0,8,"WebDriver:GetWindowHandle",{}]
[task 2020-01-13T00:28:58.193Z] 00:28:58 INFO - PID 2448 | 1578875338189 Marionette DEBUG 0 <- [1,8,null,{"value":"21"}]
[task 2020-01-13T00:28:58.193Z] 00:28:58 INFO - PID 2448 | 1578875338189 webdriver::server DEBUG <- 200 OK {"value":"21"}
[task 2020-01-13T00:28:58.193Z] 00:28:58 INFO - PID 2448 | 1578875338190 webdriver::server DEBUG -> GET /session/9cd05308-ef94-4b5e-8a86-4f4deeec6756/window/handles
[task 2020-01-13T00:28:58.195Z] 00:28:58 INFO - PID 2448 | 1578875338192 Marionette DEBUG 0 -> [0,9,"WebDriver:GetWindowHandles",{}]
[task 2020-01-13T00:28:58.197Z] 00:28:58 INFO - PID 2448 | 1578875338193 Marionette DEBUG 0 <- [1,9,null,["21"]]
[task 2020-01-13T00:28:58.197Z] 00:28:58 INFO - PID 2448 | 1578875338194 webdriver::server DEBUG <- 200 OK {"value":["21"]}
[task 2020-01-13T00:28:58.197Z] 00:28:58 INFO - PID 2448 | 1578875338194 webdriver::server DEBUG -> POST /session/9cd05308-ef94-4b5e-8a86-4f4deeec6756/window {"handle": "21"}
[task 2020-01-13T00:28:58.199Z] 00:28:58 INFO - PID 2448 | 1578875338196 Marionette DEBUG 0 -> [0,10,"WebDriver:SwitchToWindow",{"handle":"21","name":"21"}]
[task 2020-01-13T00:28:58.201Z] 00:28:58 INFO - PID 2448 | 1578875338198 Marionette DEBUG 0 <- [1,10,null,{"value":null}]
[task 2020-01-13T00:28:58.203Z] 00:28:58 INFO - PID 2448 | 1578875338199 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2020-01-13T00:28:58.203Z] 00:28:58 INFO - PID 2448 | 1578875338200 webdriver::server DEBUG -> POST /session/9cd05308-ef94-4b5e-8a86-4f4deeec6756/window/rect {"width": 800, "height": 600}
[task 2020-01-13T00:28:58.205Z] 00:28:58 INFO - PID 2448 | 1578875338203 Marionette DEBUG 0 -> [0,11,"WebDriver:SetWindowRect",{"height":600,"width":800}]
[task 2020-01-13T00:28:58.326Z] 00:28:58 INFO - PID 2448 | 1578875338310 Marionette DEBUG 0 <- [1,11,null,{"x":4,"y":4,"width":800,"height":600}]
[task 2020-01-13T00:28:58.327Z] 00:28:58 INFO - PID 2448 | 1578875338314 webdriver::server DEBUG <- 200 OK {"value":{"x":4,"y":4,"width":800,"height":600}}
[task 2020-01-13T00:28:58.327Z] 00:28:58 INFO - PID 2448 | 1578875338315 webdriver::server DEBUG -> POST /session/9cd05308-ef94-4b5e-8a86-4f4deeec6756/frame {"id": null}
[task 2020-01-13T00:28:58.327Z] 00:28:58 INFO - PID 2448 | 1578875338319 Marionette DEBUG 0 -> [0,12,"WebDriver:SwitchToFrame",{"id":null}]
[task 2020-01-13T00:28:58.332Z] 00:28:58 INFO - PID 2448 | 1578875338324 Marionette DEBUG 0 <- [1,12,null,{"value":null}]
[task 2020-01-13T00:28:58.332Z] 00:28:58 INFO - PID 2448 | 1578875338324 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2020-01-13T00:28:58.332Z] 00:28:58 INFO - STDOUT: tests/web-platform/tests/webdriver/tests/delete_session/delete.py::test_dismissed_beforeunload_prompt
[task 2020-01-13T00:28:58.337Z] 00:28:58 INFO - PID 2448 | 1578875338330 webdriver::server DEBUG -> POST /session/9cd05308-ef94-4b5e-8a86-4f4deeec6756/window/rect {"width": 800, "height": 600}
[task 2020-01-13T00:28:58.338Z] 00:28:58 INFO - PID 2448 | 1578875338332 Marionette DEBUG 0 -> [0,13,"WebDriver:SetWindowRect",{"height":600,"width":800}]
[task 2020-01-13T00:28:58.338Z] 00:28:58 INFO - PID 2448 | 1578875338333 Marionette DEBUG 0 <- [1,13,null,{"x":4,"y":4,"width":800,"height":600}]
[task 2020-01-13T00:28:58.338Z] 00:28:58 INFO - PID 2448 | 1578875338333 webdriver::server DEBUG <- 200 OK {"value":{"x":4,"y":4,"width":800,"height":600}}
[task 2020-01-13T00:28:58.338Z] 00:28:58 INFO - PID 2448 | 1578875338335 webdriver::server DEBUG -> POST /session/9cd05308-ef94-4b5e-8a86-4f4deeec6756/window/rect {"y": 100, "x": 100}
[task 2020-01-13T00:28:58.339Z] 00:28:58 INFO - PID 2448 | 1578875338336 Marionette DEBUG 0 -> [0,14,"WebDriver:SetWindowRect",{"x":100,"y":100}]
[task 2020-01-13T00:28:58.369Z] 00:28:58 INFO - PID 2448 | 1578875338359 Marionette DEBUG 0 <- [1,14,null,{"x":100,"y":100,"width":800,"height":600}]
[task 2020-01-13T00:28:58.369Z] 00:28:58 INFO - PID 2448 | 1578875338360 webdriver::server DEBUG <- 200 OK {"value":{"x":100,"y":100,"width":800,"height":600}}
[task 2020-01-13T00:28:58.369Z] 00:28:58 INFO - PID 2448 | 1578875338363 webdriver::server DEBUG -> POST /session/9cd05308-ef94-4b5e-8a86-4f4deeec6756/url {"url": "http://web-platform.test:8000/webdriver/tests/support/inline.py?doc=%3C%21doctype+html%3E%0A%3Cmeta+charset%3DUTF-8%3E%0A%0A++++++%3Cinput+type%3D%22text%22%3E%0A++++++%3Cscript%3E%0A++++++++window.addEventListener%28%22beforeunload%22%2C+function+%28event%29+%7B%0A++++++++++event.preventDefault%28%29%3B%0A++++++++%7D%29%3B%0A++++++%3C%2Fscript%3E%0A++++&charset=UTF-8&mime=text%2Fhtml"}
[task 2020-01-13T00:28:58.369Z] 00:28:58 INFO - PID 2448 | 1578875338364 Marionette DEBUG 0 -> [0,15,"WebDriver:Navigate",{"url":"http://web-platform.test:8000/webdriver/tests/support/inline.py?doc=%3C%21doctype+html%3E% ... A++++++++++event.preventDefault%28%29%3B%0A++++++++%7D%29%3B%0A++++++%3C%2Fscript%3E%0A++++&charset=UTF-8&mime=text%2Fhtml"}]
[task 2020-01-13T00:28:58.388Z] 00:28:58 INFO - PID 2448 | 1578875338377 Marionette TRACE [21] Received DOM event beforeunload for about:blank
[task 2020-01-13T00:28:58.694Z] 00:28:58 INFO - PID 2448 | 1578875338674 Marionette TRACE [21] Received DOM event pagehide for about:blank
[task 2020-01-13T00:28:58.723Z] 00:28:58 INFO - PID 2448 | 1578875338709 Marionette TRACE [21] Received DOM event DOMContentLoaded for http://web-platform.test:8000/webdriver/tests/support/inline.py?doc=%3C%21doctype+html%3E%0A%3Cmeta+charset%3DUTF-8%3E%0A%0A+ ... B%0A++++++++++event.preventDefault%28%29%3B%0A++++++++%7D%29%3B%0A++++++%3C%2Fscript%3E%0A++++&charset=UTF-8&mime=text%2Fhtml
[task 2020-01-13T00:28:58.785Z] 00:28:58 INFO - PID 2448 | 1578875338764 Marionette TRACE [21] Received DOM event pageshow for http://web-platform.test:8000/webdriver/tests/support/inline.py?doc=%3C%21doctype+html%3E%0A%3Cmeta+charset%3DUTF-8%3E%0A%0A+ ... B%0A++++++++++event.preventDefault%28%29%3B%0A++++++++%7D%29%3B%0A++++++%3C%2Fscript%3E%0A++++&charset=UTF-8&mime=text%2Fhtml
[task 2020-01-13T00:28:58.785Z] 00:28:58 INFO - PID 2448 | 1578875338782 Marionette DEBUG 0 <- [1,15,null,{"value":null}]
[task 2020-01-13T00:28:58.811Z] 00:28:58 INFO - PID 2448 | 1578875338801 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2020-01-13T00:28:58.811Z] 00:28:58 INFO - PID 2448 | 1578875338802 webdriver::server DEBUG -> POST /session/9cd05308-ef94-4b5e-8a86-4f4deeec6756/element {"using": "css selector", "value": "input"}
[task 2020-01-13T00:28:58.837Z] 00:28:58 INFO - PID 2448 | 1578875338832 Marionette DEBUG 0 -> [0,16,"WebDriver:FindElement",{"using":"css selector","value":"input"}]
[task 2020-01-13T00:28:58.846Z] 00:28:58 INFO - PID 2448 | 1578875338840 Marionette DEBUG 0 <- [1,16,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"37929c6c-c5b2-46ea-a3b0-61255249905a"}}]
[task 2020-01-13T00:28:58.856Z] 00:28:58 INFO - PID 2448 | 1578875338846 webdriver::server DEBUG <- 200 OK {"value":{"element-6066-11e4-a52e-4f735466cecf":"37929c6c-c5b2-46ea-a3b0-61255249905a"}}
[task 2020-01-13T00:28:58.856Z] 00:28:58 INFO - PID 2448 | 1578875338848 webdriver::server DEBUG -> POST /session/9cd05308-ef94-4b5e-8a86-4f4deeec6756/element/37929c6c-c5b2-46ea-a3b0-61255249905a/value {"text": "foo"}
[task 2020-01-13T00:28:58.856Z] 00:28:58 INFO - PID 2448 | 1578875338854 Marionette DEBUG 0 -> [0,17,"WebDriver:ElementSendKeys",{"id":"37929c6c-c5b2-46ea-a3b0-61255249905a","text":"foo","value":["f","o","o"]}]
[task 2020-01-13T00:28:58.921Z] 00:28:58 INFO - PID 2448 | 1578875338910 Marionette DEBUG 0 <- [1,17,null,{"value":null}]
[task 2020-01-13T00:28:58.921Z] 00:28:58 INFO - PID 2448 | 1578875338911 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2020-01-13T00:28:58.921Z] 00:28:58 INFO - PID 2448 | 1578875338912 webdriver::server DEBUG -> DELETE /session/9cd05308-ef94-4b5e-8a86-4f4deeec6756
[task 2020-01-13T00:28:58.922Z] 00:28:58 INFO - PID 2448 | 1578875338913 Marionette DEBUG 0 -> [0,18,"Marionette:Quit",{"flags":["eForceQuit"]}]
[task 2020-01-13T00:28:58.922Z] 00:28:58 INFO - PID 2448 | 1578875338914 Marionette INFO Stopped listening on port 2828
[task 2020-01-13T00:28:59.053Z] 00:28:59 INFO - PID 2448 | 1578875339045 Marionette TRACE Received observer notification quit-application
[task 2020-01-13T00:28:59.072Z] 00:28:59 INFO - PID 2448 | 1578875339057 Marionette DEBUG 0 <- [1,18,null,{"cause":"shutdown"}]
[task 2020-01-13T00:28:59.154Z] 00:28:59 INFO - PID 2448 | 1578875339134 webdriver::server DEBUG Deleting session
[task 2020-01-13T00:28:59.173Z] 00:28:59 INFO - PID 2448 | 1578875339162 Marionette DEBUG 0 -> [0,19,"Marionette:Quit",{"flags":["eForceQuit"]}]
[task 2020-01-13T00:28:59.173Z] 00:28:59 INFO - PID 2448 | 1578875339164 Marionette DEBUG 0 <- [1,19,{"error":"invalid session id","message":"Tried to run command without establishing a connection","stacktrace":"WebDrive ... t@chrome://marionette/content/server.js:249:9\n_onJSONObjectReady/<@chrome://marionette/content/transport.js:501:20\n"},null]
[task 2020-01-13T00:28:59.174Z] 00:28:59 INFO - PID 2448 |
[task 2020-01-13T00:28:59.174Z] 00:28:59 INFO - PID 2448 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2020-01-13T00:28:59.174Z] 00:28:59 INFO - PID 2448 |
[task 2020-01-13T00:28:59.192Z] 00:28:59 INFO - PID 2448 |
[task 2020-01-13T00:28:59.192Z] 00:28:59 INFO - PID 2448 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2020-01-13T00:28:59.192Z] 00:28:59 INFO - PID 2448 |
[task 2020-01-13T00:28:59.203Z] 00:28:59 INFO - PID 2448 | 1578875339190 Marionette DEBUG Closed connection 0
[task 2020-01-13T00:28:59.323Z] 00:28:59 INFO - PID 2448 |
[task 2020-01-13T00:28:59.323Z] 00:28:59 INFO - PID 2448 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2020-01-13T00:28:59.324Z] 00:28:59 INFO - PID 2448 |
[task 2020-01-13T00:28:59.689Z] 00:28:59 INFO - PID 2448 | 1578875339678 Marionette TRACE Received observer notification xpcom-will-shutdown
[task 2020-01-13T00:28:59.689Z] 00:28:59 INFO - PID 2448 | 1578875339678 Marionette DEBUG Resetting recommended pref apz.content_response_timeout
[task 2020-01-13T00:28:59.689Z] 00:28:59 INFO - PID 2448 | 1578875339679 Marionette DEBUG Resetting recommended pref browser.contentblocking.introCount
[task 2020-01-13T00:28:59.689Z] 00:28:59 INFO - PID 2448 | 1578875339679 Marionette DEBUG Resetting recommended pref browser.download.panel.shown
[task 2020-01-13T00:28:59.690Z] 00:28:59 INFO - PID 2448 | 1578875339680 Marionette DEBUG Resetting recommended pref browser.newtabpage.enabled
[task 2020-01-13T00:28:59.690Z] 00:28:59 INFO - PID 2448 | 1578875339681 Marionette DEBUG Resetting recommended pref browser.pagethumbnails.capturing_disabled
[task 2020-01-13T00:28:59.690Z] 00:28:59 INFO - PID 2448 | 1578875339681 Marionette DEBUG Resetting recommended pref browser.search.update
[task 2020-01-13T00:28:59.690Z] 00:28:59 INFO - PID 2448 | 1578875339682 Marionette DEBUG Resetting recommended pref browser.tabs.disableBackgroundZombification
[task 2020-01-13T00:28:59.690Z] 00:28:59 INFO - PID 2448 | 1578875339682 Marionette DEBUG Resetting recommended pref browser.tabs.remote.separatePrivilegedContentProcess
[task 2020-01-13T00:28:59.690Z] 00:28:59 INFO - PID 2448 | 1578875339682 Marionette DEBUG Resetting recommended pref browser.tabs.unloadOnLowMemory
[task 2020-01-13T00:28:59.690Z] 00:28:59 INFO - PID 2448 | 1578875339682 Marionette DEBUG Resetting recommended pref browser.tabs.warnOnCloseOtherTabs
[task 2020-01-13T00:28:59.691Z] 00:28:59 INFO - PID 2448 | 1578875339683 Marionette DEBUG Resetting recommended pref browser.tabs.warnOnOpen
[task 2020-01-13T00:28:59.691Z] 00:28:59 INFO - PID 2448 | 1578875339683 Marionette DEBUG Resetting recommended pref browser.usedOnWindows10.introURL
[task 2020-01-13T00:28:59.691Z] 00:28:59 INFO - PID 2448 | 1578875339683 Marionette DEBUG Resetting recommended pref browser.urlbar.suggest.searches
[task 2020-01-13T00:28:59.693Z] 00:28:59 INFO - PID 2448 | 1578875339685 Marionette DEBUG Resetting recommended pref datareporting.policy.dataSubmissionPolicyAccepted
[task 2020-01-13T00:28:59.693Z] 00:28:59 INFO - PID 2448 | 1578875339685 Marionette DEBUG Resetting recommended pref dom.disable_beforeunload
[task 2020-01-13T00:28:59.694Z] 00:28:59 INFO - PID 2448 | 1578875339685 Marionette DEBUG Resetting recommended pref dom.disable_open_during_load
[task 2020-01-13T00:28:59.694Z] 00:28:59 INFO - PID 2448 | 1578875339685 Marionette DEBUG Resetting recommended pref dom.file.createInChild
[task 2020-01-13T00:28:59.695Z] 00:28:59 INFO - PID 2448 | 1578875339686 Marionette DEBUG Resetting recommended pref dom.max_chrome_script_run_time
[task 2020-01-13T00:28:59.695Z] 00:28:59 INFO - PID 2448 | 1578875339686 Marionette DEBUG Resetting recommended pref dom.max_script_run_time
[task 2020-01-13T00:28:59.696Z] 00:28:59 INFO - PID 2448 | 1578875339687 Marionette DEBUG Resetting recommended pref dom.push.connection.enabled
[task 2020-01-13T00:28:59.697Z] 00:28:59 INFO - PID 2448 | 1578875339688 Marionette DEBUG Resetting recommended pref extensions.getAddons.cache.enabled
[task 2020-01-13T00:28:59.697Z] 00:28:59 INFO - PID 2448 | 1578875339688 Marionette DEBUG Resetting recommended pref extensions.webservice.discoverURL
[task 2020-01-13T00:28:59.698Z] 00:28:59 INFO - PID 2448 | 1578875339688 Marionette DEBUG Resetting recommended pref network.http.prompt-temp-redirect
[task 2020-01-13T00:28:59.698Z] 00:28:59 INFO - PID 2448 | 1578875339688 Marionette DEBUG Resetting recommended pref network.http.speculative-parallel-limit
[task 2020-01-13T00:28:59.698Z] 00:28:59 INFO - PID 2448 | 1578875339688 Marionette DEBUG Resetting recommended pref privacy.trackingprotection.enabled
[task 2020-01-13T00:28:59.698Z] 00:28:59 INFO - PID 2448 | 1578875339688 Marionette DEBUG Resetting recommended pref security.fileuri.strict_origin_policy
[task 2020-01-13T00:28:59.698Z] 00:28:59 INFO - PID 2448 | 1578875339689 Marionette DEBUG Resetting recommended pref security.notification_enable_delay
[task 2020-01-13T00:28:59.698Z] 00:28:59 INFO - PID 2448 | 1578875339689 Marionette DEBUG Resetting recommended pref signon.autofillForms
[task 2020-01-13T00:28:59.698Z] 00:28:59 INFO - PID 2448 | 1578875339689 Marionette DEBUG Resetting recommended pref signon.rememberSignons
[task 2020-01-13T00:28:59.698Z] 00:28:59 INFO - PID 2448 | 1578875339690 Marionette DEBUG Resetting recommended pref toolkit.cosmeticAnimations.enabled
[task 2020-01-13T00:28:59.699Z] 00:28:59 INFO - PID 2448 | 1578875339691 Marionette DEBUG Marionette stopped listening
[task 2020-01-13T00:28:59.783Z] 00:28:59 INFO - PID 2448 |
[task 2020-01-13T00:28:59.784Z] 00:28:59 INFO - PID 2448 | ###!!! [Child][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2020-01-13T00:28:59.784Z] 00:28:59 INFO - PID 2448 |
[task 2020-01-13T00:29:09.001Z] 00:29:09 INFO - TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/delete_session/delete.py | expected OK
[task 2020-01-13T00:29:09.001Z] 00:29:09 INFO - TEST-INFO took 30008ms
[task 2020-01-13T00:29:09.046Z] 00:29:09 INFO - Closing logging queue