1506245 - Intermittent testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py TestWindowRect.test_resize_while_fullscreen | TimeoutException:

Reporter

Description

•

6 years ago

treeherder

Filed by: apavel [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=210871173&repo=autoland

https://queue.taskcluster.net/v1/task/YAgPWi7tTTWYFcSOIthSEg/runs/0/artifacts/public/logs/live_backing.log

11:00:43     INFO - TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py TestWindowRect.test_resize_while_fullscreen
11:00:43     INFO -  1541790043722	Marionette	TRACE	103 <- [1,12,null,{"value":null}]
11:00:43     INFO -  1541790043724	Marionette	DEBUG	Closed connection 103
11:00:43     INFO -  1541790043725	Marionette	DEBUG	Accepted connection 104 from 127.0.0.1:51747
11:00:43     INFO -  1541790043726	Marionette	TRACE	104 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
11:00:43     INFO -  1541790043727	Marionette	DEBUG	[8589934608] Frame script loaded
11:00:43     INFO -  1541790043727	Marionette	DEBUG	[2147483905] Frame script loaded
11:00:43     INFO -  1541790043728	Marionette	DEBUG	[8589934608] Frame script registered
11:00:43     INFO -  1541790043728	Marionette	DEBUG	[2147483905] Frame script registered
11:00:43     INFO -  1541790043729	Marionette	TRACE	104 <- [1,1,null,{"sessionId":"b48c74dd-e82f-064a-913a-8240b41981d2","capabilities":{"browserName":"firefox","browserVersion":"65.0a ... /T/tmpJ5jf6z.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}]
11:00:43     INFO -  1541790043731	Marionette	TRACE	104 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}]
11:00:43     INFO -  1541790043732	Marionette	TRACE	104 <- [1,2,null,{"value":null}]
11:00:43     INFO -  1541790043732	Marionette	TRACE	104 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}]
11:00:43     INFO -  1541790043733	Marionette	TRACE	104 <- [1,3,null,{"value":null}]
11:00:43     INFO -  1541790043733	Marionette	TRACE	104 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}]
11:00:43     INFO -  1541790043734	Marionette	TRACE	104 <- [1,4,null,{"value":null}]
11:00:43     INFO -  1541790043734	Marionette	TRACE	104 -> [0,5,"WebDriver:GetWindowRect",{}]
11:00:43     INFO -  1541790043735	Marionette	TRACE	104 <- [1,5,null,{"x":4,"y":23,"width":1280,"height":1009,"state":"normal"}]
11:00:43     INFO -  1541790043736	Marionette	TRACE	104 -> [0,6,"WebDriver:ExecuteScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"tests/testing/marionette/harness ... width: window.screen.availWidth,\n              height: window.screen.availHeight,\n            }","sandbox":null,"line":22}]
11:00:43     INFO -  1541790043739	Marionette	TRACE	104 <- [1,6,null,{"value":{"width":1600,"height":1097}}]
11:00:43     INFO -  1541790043740	Marionette	TRACE	104 -> [0,7,"WebDriver:SetWindowRect",{"y":null,"x":null,"width":1280,"height":1009}]
11:00:43     INFO -  1541790043741	Marionette	TRACE	104 <- [1,7,null,{"x":4,"y":23,"width":1280,"height":1009,"state":"normal"}]
11:00:43     INFO -  1541790043742	Marionette	TRACE	104 -> [0,8,"WebDriver:FullscreenWindow",{}]
11:00:45     INFO -  1541790045067	Marionette	TRACE	104 <- [1,8,null,{"x":0,"y":0,"width":1600,"height":1200,"state":"fullscreen"}]
11:00:45     INFO -  1541790045068	Marionette	TRACE	104 -> [0,9,"WebDriver:SetWindowRect",{"y":null,"x":null,"width":1500,"height":997}]
11:00:46     INFO -  1541790046570	Marionette	TRACE	104 <- [1,9,{"error":"timeout","message":"","stacktrace":"WebDriverError@chrome://marionette/content/error.js:179:5\nTimeoutError@chrome://marionette/content/error.js:446:5\nbail@chrome://marionette/content/sync.js:193:19\n"},null]
11:00:46     INFO -  1541790046572	Marionette	TRACE	104 -> [0,10,"Marionette:GetContext",{}]
11:00:46     INFO -  1541790046572	Marionette	TRACE	104 <- [1,10,null,{"value":"content"}]
11:00:46     INFO -  1541790046573	Marionette	TRACE	104 -> [0,11,"Marionette:SetContext",{"value":"chrome"}]
11:00:46     INFO -  1541790046573	Marionette	TRACE	104 <- [1,11,null,{"value":null}]
11:00:46     INFO -  1541790046574	Marionette	TRACE	104 -> [0,12,"WebDriver:TakeScreenshot",{"highlights":null,"full":true,"hash":false,"id":null,"scroll":true}]
11:00:46     INFO -  1541790046612	Marionette	TRACE	104 <- [1,12,null,{"value":"iVBORw0KGgoAAAANSUhEUgAABQAAAAPxCAYAAACl+gBxAAAgAElEQVR4nOzdXWyV953o+3UuRto6c7Okfbk10mgu9qgX7pzqeM90OkLZ ... Kq7R2W8pS77b9PnsL8+wiAAAAAAK+LAPjKvXil4npRs9nVs6sPfxcBEAAAAOB1EQD5pQRAAAAAgNdFAOSXEgABAAAAXpf/AXWv0KH3dZxYAAAAAElFTkSuQmCC"}]
11:00:46     INFO -  1541790046613	Marionette	TRACE	104 -> [0,13,"Marionette:SetContext",{"value":"content"}]
11:00:46     INFO -  1541790046614	Marionette	TRACE	104 <- [1,13,null,{"value":null}]
11:00:46     INFO -  1541790046615	Marionette	TRACE	104 -> [0,14,"Marionette:GetContext",{}]
11:00:46     INFO -  1541790046615	Marionette	TRACE	104 <- [1,14,null,{"value":"content"}]
11:00:46     INFO -  1541790046616	Marionette	TRACE	104 -> [0,15,"Marionette:SetContext",{"value":"content"}]
11:00:46     INFO -  1541790046616	Marionette	TRACE	104 <- [1,15,null,{"value":null}]
11:00:46     INFO -  1541790046616	Marionette	TRACE	104 -> [0,16,"WebDriver:GetPageSource",{}]
11:00:46     INFO - TEST-UNEXPECTED-ERROR | testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py TestWindowRect.test_resize_while_fullscreen | TimeoutException: 
11:00:46     INFO - stacktrace:
11:00:46     INFO - 	WebDriverError@chrome://marionette/content/error.js:179:5
11:00:46     INFO - 	TimeoutError@chrome://marionette/content/error.js:446:5
11:00:46     INFO - 	bail@chrome://marionette/content/sync.js:193:19
11:00:46     INFO - Traceback (most recent call last):
11:00:46     INFO -   File "/Users/cltbld/tasks/task_1541789757/build/venv/lib/python2.7/site-packages/marionette_harness/marionette_test/testcases.py", line 159, in run
11:00:46     INFO -     testMethod()
11:00:46     INFO -   File "/Users/cltbld/tasks/task_1541789757/build/tests/marionette/tests/testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py", line 223, in test_resize_while_fullscreen
11:00:46     INFO -     height=self.max["height"] - 100)
11:00:46     INFO -   File "/Users/cltbld/tasks/task_1541789757/build/venv/lib/python2.7/site-packages/marionette_driver/marionette.py", line 1386, in set_window_rect
11:00:46     INFO -     body)
11:00:46     INFO -   File "/Users/cltbld/tasks/task_1541789757/build/venv/lib/python2.7/site-packages/marionette_driver/decorators.py", line 26, in _
11:00:46     INFO -     return func(*args, **kwargs)
11:00:46     INFO -   File "/Users/cltbld/tasks/task_1541789757/build/venv/lib/python2.7/site-packages/marionette_driver/marionette.py", line 764, in _send_message
11:00:46     INFO -     self._handle_error(err)
11:00:46     INFO -   File "/Users/cltbld/tasks/task_1541789757/build/venv/lib/python2.7/site-packages/marionette_driver/marionette.py", line 784, in _handle_error
11:00:46     INFO -     raise errors.lookup(error)(message, stacktrace=stacktrace)
11:00:46     INFO - TEST-INFO took 2896ms
11:00:46     INFO -  1541790046618	Marionette	TRACE	104 <- [1,16,null,{"value":"<html><head>\n<title>Marionette New Tab Link</title>\n</head>\n<body>\n  <a href=\"empty.html\" id=\"new ... javascript:window.open(&quot;empty.html&quot;, null, &quot;location=1,toolbar=1&quot;);\">New Window</a>\n\n</body></html>"}]
11:00:46     INFO -  1541790046619	Marionette	TRACE	104 -> [0,17,"Marionette:SetContext",{"value":"content"}]
11:00:46     INFO -  1541790046619	Marionette	TRACE	104 <- [1,17,null,{"value":null}]
11:00:46     INFO -  1541790046622	Marionette	TRACE	104 -> [0,18,"WebDriver:SetWindowRect",{"y":23,"x":4,"width":1280,"height":1009}]
11:00:46     INFO -  1541790046623	Marionette	TRACE	104 <- [1,18,null,{"x":4,"y":23,"width":1280,"height":1009,"state":"normal"}]
11:00:46     INFO -  1541790046625	Marionette	TRACE	104 -> [0,19,"WebDriver:ExecuteScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"tests/testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py","script":"return document.fullscreenElement;","sandbox":null,"line":41}]
11:00:46     INFO -  1541790046628	Marionette	TRACE	104 <- [1,19,null,{"value":null}]
11:00:46     INFO -  1541790046628	Marionette	TRACE	104 -> [0,20,"WebDriver:DeleteSession",{}]

Henrik Skupin [:whimboo][⌚️UTC+1]

Comment 1

•

6 years ago

SetWindowRect times out, which is now a new behavior since bug 1492499 is fixed.

status-firefox65: --- → affected

Depends on: 1492499

Comment hidden (Intermittent Failures Robot)

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

Repository breakdown:
* autoland: 1

Platform breakdown:
* osx-10-10: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1506245&startday=2018-11-05&endday=2018-11-11&tree=all

Comment hidden (Intermittent Failures Robot)

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

Repository breakdown:
* mozilla-central: 1

Platform breakdown:
* windows10-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1506245&startday=2018-11-12&endday=2018-11-18&tree=all

Andreas Tolfsen ❲:ato❳

Comment 4

•

6 years ago

Like https://bugzilla.mozilla.org/show_bug.cgi?id=1509224, it seems
to happen very frequently, almost to the point where reproducing
it on try I would suspect is like finding a needle in a haystack.

There seems to be a pattern that it manifests on Windows 10 x64 and
osx-10-10, however I can’t tell from OF if it is for headless or
not.  Is this information available through OF?

Henrik Skupin [:whimboo][⌚️UTC+1]

Comment 5

•

6 years ago

You will have to click the OF graph at the top of the bug, and check the `Test Suite` column of the table.

Andreas Tolfsen ❲:ato❳

Comment 6

•

6 years ago

So the last OF report three days ago in
https://bugzilla.mozilla.org/show_bug.cgi?id=1506245#c3 is a mochitest
failure with the failure message:

> TEST-UNEXPECTED-TIMEOUT | automation.py | application timed out after 370 seconds with no output

It seems to be about a hang during startup:

> 23:00:48     INFO - GECKO(6448) | 1542495648146	Marionette	DEBUG	Received observer notification profile-after-change
> 23:00:48     INFO - GECKO(6448) | 1542495648204	Marionette	DEBUG	Received observer notification toplevel-window-ready
> 23:00:48     INFO - GECKO(6448) | 1542495648238	Marionette	DEBUG	Received observer notification command-line-startup
> 23:00:48     INFO - GECKO(6448) | 1542495648238	Marionette	DEBUG	Received observer notification nsPref:changed
> 23:00:48     INFO - GECKO(6448) | 1542495648238	Marionette	DEBUG	Init aborted (running=false, enabled=true, finalUIStartup=false)
> 23:03:47     INFO - runtests.py | Waiting for browser...
> 23:06:58     INFO - Buffered messages finished
> 23:06:58    ERROR - TEST-UNEXPECTED-TIMEOUT | automation.py | application timed out after 370 seconds with no output

The one ten days ago in
https://bugzilla.mozilla.org/show_bug.cgi?id=1506245#c2 is osx-10-10
related; the same as original report.

OS: Unspecified → Mac OS X

Hardware: Unspecified → x86_64

Comment hidden (Intermittent Failures Robot)

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

Repository breakdown:
* autoland: 1

Platform breakdown:
* osx-10-10: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1506245&startday=2018-12-10&endday=2018-12-16&tree=all

Comment hidden (Intermittent Failures Robot)

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

Repository breakdown:
* mozilla-inbound: 1

Platform breakdown:
* osx-10-10: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1506245&startday=2018-12-17&endday=2018-12-23&tree=all

Comment hidden (Intermittent Failures Robot)

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

Repository breakdown:
* mozilla-inbound: 1

Platform breakdown:
* osx-10-10: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1506245&startday=2018-12-31&endday=2019-01-06&tree=all

Comment hidden (Intermittent Failures Robot)

Henrik Skupin [:whimboo][⌚️UTC+1]

Updated

•

5 years ago

Updated

•

5 years ago

Depends on: 1519777

Henrik Skupin [:whimboo][⌚️UTC+1]

Comment 11

•

5 years ago

Recent failures show timeouts when switching into fullscreen mode:

02:47:41 INFO - 1547117261987 Marionette DEBUG 105 -> [0,8,"WebDriver:FullscreenWindow",{}]
02:47:43 INFO - 1547117263493 Marionette WARN TimedPromise timed out after 1500 ms: stacktrace:
02:47:43 INFO - bail@chrome://marionette/content/sync.js:196:64

I filed bug 1519777.

Comment hidden (Intermittent Failures Robot)

Firefox Bug Husbandry Bot

Comment 13

•

5 years ago

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Status: NEW → RESOLVED

Closed: 5 years ago

Resolution: --- → INCOMPLETE

BMO Automation

Updated

•

1 year ago

Product: Testing → Remote Protocol

BMO Automation

Comment 14

•

1 year ago

Moving bug to Testing::Marionette Client and Harness component per bug 1815831.

Component: Marionette → Marionette Client and Harness

Product: Remote Protocol → Testing

Bugzilla

Quick Search

Intermittent testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py TestWindowRect.test_resize_while_fullscreen | TimeoutException:

Categories

(Testing :: Marionette Client and Harness, defect, P5)

Tracking

(firefox65 affected)

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure)

Crash Data

Security

(public)

User Story

Description

Comment 1

Comment 2

Comment 3

Comment 4

Comment 5

Comment 6

Comment 7

Comment 8

Comment 9

Comment 10

Updated

Updated

Comment 11

Comment 12

Comment 13

Updated

Comment 14