1606292 - Intermittent TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/delete_cookie/user_prompts.py | expected OK [Exiting due to channel error]

Status: RESOLVED DUPLICATE of bug 1569480

(Remote Protocol :: Marionette, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2019-12-30T06:00:23.038Z] 06:00:23 INFO - PID 6100 | 1577685622992 webdriver::server DEBUG <- 200 OK {"value":{"sessionId":"ff032960-dbd0-4272-9d20-d00d89eb82f3","capabilities":{"acceptInsecureCerts":false,"browserName":"firefox","browserVersion":"73.0a1","moz:accessibilityChecks":false,"moz:buildID":"20191230024824","moz:geckodriverVersion":"0.26.0","moz:headless":true,"moz:processID":3248,"moz:profile":"C:\Users\task_1577683051\AppData\Local\Temp\rust_mozprofileCKTAs9","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true,"pageLoadStrategy":"normal","platformName":"windows","platformVersion":"6.1","rotatable":false,"setWindowRect":true,"strictFileInteractability":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"unhandledPromptBehavior":"dismiss and notify"}}}
[task 2019-12-30T06:00:23.041Z] 06:00:23 INFO - PID 6100 | 1577685623026 webdriver::server DEBUG -> POST /session/ff032960-dbd0-4272-9d20-d00d89eb82f3/window/rect {"width": 800, "height": 600}
[task 2019-12-30T06:00:23.092Z] 06:00:23 INFO - PID 6100 | 1577685623059 Marionette DEBUG 0 -> [0,2,"WebDriver:SetWindowRect",{"height":600,"width":800}]
[task 2019-12-30T06:00:23.863Z] 06:00:23 INFO - PID 6100 | 1577685623833 Marionette DEBUG 0 <- [1,2,null,{"x":4,"y":4,"width":800,"height":600}]
[task 2019-12-30T06:00:23.865Z] 06:00:23 INFO - PID 6100 | 1577685623840 webdriver::server DEBUG <- 200 OK {"value":{"x":4,"y":4,"width":800,"height":600}}
[task 2019-12-30T06:00:23.865Z] 06:00:23 INFO - PID 6100 | 1577685623852 webdriver::server DEBUG -> POST /session/ff032960-dbd0-4272-9d20-d00d89eb82f3/window/rect {"y": 100, "x": 100}
[task 2019-12-30T06:00:23.866Z] 06:00:23 INFO - PID 6100 | 1577685623852 Marionette DEBUG 0 -> [0,3,"WebDriver:SetWindowRect",{"x":100,"y":100}]
[task 2019-12-30T06:00:23.947Z] 06:00:23 INFO - PID 6100 | 1577685623928 Marionette DEBUG 0 <- [1,3,null,{"x":100,"y":100,"width":800,"height":600}]
[task 2019-12-30T06:00:23.948Z] 06:00:23 INFO - PID 6100 | 1577685623935 webdriver::server DEBUG <- 200 OK {"value":{"x":100,"y":100,"width":800,"height":600}}
[task 2019-12-30T06:00:23.967Z] 06:00:23 INFO - PID 6100 | 1577685623951 webdriver::server DEBUG -> POST /session/ff032960-dbd0-4272-9d20-d00d89eb82f3/url {"url": "http://web-platform.test:8000/common/blank.html"}
[task 2019-12-30T06:00:23.968Z] 06:00:23 INFO - PID 6100 | 1577685623949 Marionette DEBUG 0 -> [0,4,"WebDriver:Navigate",{"url":"http://web-platform.test:8000/common/blank.html"}]
[task 2019-12-30T06:00:23.996Z] 06:00:23 INFO - PID 6100 | 1577685623980 Marionette TRACE [21] Received DOM event beforeunload for about:blank
[task 2019-12-30T06:00:24.117Z] 06:00:24 INFO - PID 6100 | 1577685624091 Marionette TRACE [21] Received DOM event pagehide for about:blank
[task 2019-12-30T06:00:24.156Z] 06:00:24 INFO - PID 6100 | 1577685624137 Marionette TRACE [21] Received DOM event DOMContentLoaded for http://web-platform.test:8000/common/blank.html
[task 2019-12-30T06:00:24.339Z] 06:00:24 INFO - PID 6100 | 1577685624315 Marionette TRACE [21] Received DOM event pageshow for http://web-platform.test:8000/common/blank.html
[task 2019-12-30T06:00:24.451Z] 06:00:24 INFO - PID 6100 | 1577685624412 Marionette DEBUG 0 <- [1,4,null,{"value":null}]
[task 2019-12-30T06:00:24.490Z] 06:00:24 INFO - TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/delete_cookie/user_prompts.py | expected OK
[task 2019-12-30T06:00:24.491Z] 06:00:24 INFO - TEST-INFO took 185032ms
[task 2019-12-30T06:00:24.727Z] 06:00:24 INFO - PID 6100 | Exiting due to channel error.
[task 2019-12-30T06:00:24.729Z] 06:00:24 INFO - PID 6100 | Exiting due to channel error.
[task 2019-12-30T06:00:24.730Z] 06:00:24 INFO - PID 6100 | Exiting due to channel error.
[task 2019-12-30T06:00:24.732Z] 06:00:24 INFO - Closing logging queue
[task 2019-12-30T06:00:24.734Z] 06:00:24 INFO - queue closed
[task 2019-12-30T06:00:24.737Z] 06:00:24 INFO - Starting runner
[task 2019-12-30T06:00:28.190Z] 06:00:28 INFO - PID 3012 | 1577685628152 geckodriver DEBUG Listening on 127.0.0.1:50343
[task 2019-12-30T06:00:28.577Z] 06:00:28 INFO - WebDriver HTTP server listening at http://127.0.0.1:50343/
[task 2019-12-30T06:00:28.579Z] 06:00:28 INFO - TEST-START | /webdriver/tests/delete_session/delete.py
[task 2019-12-30T06:00:30.536Z] 06:00:30 INFO - STDOUT: ============================= test session starts =============================
[task 2019-12-30T06:00:30.538Z] 06:00:30 INFO - STDOUT: platform win32 -- Python 2.7.11, pytest-unknown, py-1.5.2, pluggy-0.5.3.dev -- Z:\task_1577683051\build\venv\Scripts\python.exe
[task 2019-12-30T06:00:30.539Z] 06:00:30 INFO - STDOUT: rootdir: Z:\task_1577683051\build, inifile:
[task 2019-12-30T06:00:30.540Z] 06:00:30 INFO - STDOUT: collecting ...
[task 2019-12-30T06:00:30.616Z] 06:00:30 INFO - STDOUT: collected 2 items
[task 2019-12-30T06:00:30.616Z] 06:00:30 INFO - STDOUT: tests/web-platform/tests/webdriver/tests/delete_session/delete.py::test_null_response_value

Comment 2

[Intermittent Failures Robot]

1 failures in 1862 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform breakdown:

• windows7-32-shippable: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1606292&startday=2019-12-30&endday=2020-01-05&tree=all

Comment 3

[BMO Automation]

Moving bug to Remote Protocol::Marionette component per bug 1815831.