Closed Bug 1695946 Opened 4 years ago Closed 4 years ago

Intermittent TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/execute_script/collections.py | expected OK

Categories

(Remote Protocol :: Marionette, defect, P5)

defect

Tracking

(Not tracked)

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

Filed by: archaeopteryx [at] coole-files.de
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=331739799&repo=try
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/GZo2lkYeRke3l12uy-xSFg/runs/0/artifacts/public/logs/live_backing.log


[task 2021-03-02T13:05:26.226Z] 13:05:26     INFO - STDOUT: PASSED
[task 2021-03-02T13:05:26.227Z] 13:05:26     INFO - PID 1664 | 1614690326223	webdriver::server	DEBUG	<- 200 OK {"value":[{"element-6066-11e4-a52e-4f735466cecf":"940959cf-8d72-4fc3-8a10-ff6fa870feb6"},{"element-6066-11e4-a52e-4f735466cecf":"2941915f-8d99-40d9-be94-e3191eb77642"}]}
[task 2021-03-02T13:05:26.228Z] 13:05:26     INFO - PID 1664 | 1614690326225	webdriver::server	DEBUG	-> POST /session/301bad4a-ef2f-4a4f-92fc-9d0858baffc1/timeouts {"implicit": 0}
[task 2021-03-02T13:05:26.230Z] 13:05:26     INFO - PID 1664 | 1614690326218	Marionette	DEBUG	0 -> [0,142,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2021-03-02T13:05:26.232Z] 13:05:26     INFO - PID 1664 | 1614690326218	Marionette	DEBUG	0 <- [1,142,null,{"value":null}]
[task 2021-03-02T13:05:26.232Z] 13:05:26     INFO - PID 1664 | 1614690326226	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2021-03-02T13:05:26.233Z] 13:05:26     INFO - PID 1664 | 1614690326227	webdriver::server	DEBUG	-> POST /session/301bad4a-ef2f-4a4f-92fc-9d0858baffc1/timeouts {"pageLoad": 300000}
[task 2021-03-02T13:05:26.234Z] 13:05:26     INFO - PID 1664 | 1614690326221	Marionette	DEBUG	0 -> [0,143,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2021-03-02T13:05:26.235Z] 13:05:26     INFO - PID 1664 | 1614690326221	Marionette	DEBUG	0 <- [1,143,null,{"value":null}]
[task 2021-03-02T13:05:26.236Z] 13:05:26     INFO - PID 1664 | 1614690326229	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2021-03-02T13:05:26.237Z] 13:05:26     INFO - PID 1664 | 1614690326230	webdriver::server	DEBUG	-> POST /session/301bad4a-ef2f-4a4f-92fc-9d0858baffc1/timeouts {"script": 30000}
[task 2021-03-02T13:05:26.239Z] 13:05:26     INFO - PID 1664 | 1614690326227	Marionette	DEBUG	0 -> [0,144,"WebDriver:SetTimeouts",{"script":30000}]
[task 2021-03-02T13:05:26.240Z] 13:05:26     INFO - PID 1664 | 1614690326228	Marionette	DEBUG	0 <- [1,144,null,{"value":null}]
[task 2021-03-02T13:05:26.241Z] 13:05:26     INFO - PID 1664 | 1614690326236	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2021-03-02T13:05:26.242Z] 13:05:26     INFO - PID 1664 | 1614690326237	webdriver::server	DEBUG	-> GET /session/301bad4a-ef2f-4a4f-92fc-9d0858baffc1/window
[task 2021-03-02T13:05:34.517Z] 13:05:34     INFO - TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/execute_script/collections.py | expected OK```

There is a slow running navigation which finally caused the test to timeout:

https://treeherder.mozilla.org/logviewer?job_id=331739799&repo=try&lineNumber=20211-20216

[task 2021-03-02T13:05:15.994Z] 13:05:15     INFO - PID 1664 | 1614690315989	Marionette	DEBUG	0 -> [0,139,"WebDriver:Navigate",{"url":"http://web-platform.test:8000/webdriver/tests/support/inline.py?doc=%3C%21doctype+html%3E%0A%3Cmeta+charset%3DUTF-8%3E%0A%0A++++++++%3Cp%3Efoo%0A++++++++%3Cp%3Ebar%0A++++++++&mime=text%2Fhtml&charset=UTF-8"}]
[task 2021-03-02T13:05:17.729Z] 13:05:17     INFO - PID 1664 | 1614690317722	Marionette	TRACE	Received event beforeunload for http://web-platform.test:8000/webdriver/tests/support/inline.py?doc=%3C%21doctype+html%3E%0A%3Cmeta+charset%3DUTF-8%3E%0A%0A+ ... %3E%0A++++++++++++%3Coption%3E%0A++++++++++++%3Coption%3E%0A++++++++%3C%2Fselect%3E%0A++++++++&mime=text%2Fhtml&charset=UTF-8
[task 2021-03-02T13:05:26.185Z] 13:05:26     INFO - PID 1664 | 1614690326175	Marionette	TRACE	Received event pagehide for http://web-platform.test:8000/webdriver/tests/support/inline.py?doc=%3C%21doctype+html%3E%0A%3Cmeta+charset%3DUTF-8%3E%0A%0A+ ... %3E%0A++++++++++++%3Coption%3E%0A++++++++++++%3Coption%3E%0A++++++++%3C%2Fselect%3E%0A++++++++&mime=text%2Fhtml&charset=UTF-8
[task 2021-03-02T13:05:26.189Z] 13:05:26     INFO - PID 1664 | 1614690326180	Marionette	TRACE	[17] MarionetteEvents actor created for window id 2147483655
[task 2021-03-02T13:05:26.197Z] 13:05:26     INFO - PID 1664 | 1614690326187	Marionette	TRACE	Received 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++++++++%3Cp%3Efoo%0A++++++++%3Cp%3Ebar%0A++++++++&mime=text%2Fhtml&charset=UTF-8
[task 2021-03-02T13:05:26.202Z] 13:05:26     INFO - PID 1664 | 1614690326192	Marionette	TRACE	Received 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++++++++%3Cp%3Efoo%0A++++++++%3Cp%3Ebar%0A++++++++&mime=text%2Fhtml&charset=UTF-8
Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → INCOMPLETE
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.