Closed
Bug 1506245
Opened 6 years ago
Closed 6 years ago
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)
RESOLVED
INCOMPLETE
Tracking | Status | |
---|---|---|
firefox65 | --- | affected |
People
(Reporter: intermittent-bug-filer, Unassigned)
References
Details
(Keywords: intermittent-failure)
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("empty.html", null, "location=1,toolbar=1");\">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",{}]
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) |
Comment hidden (Intermittent Failures Robot) |
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?
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.
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) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Updated•6 years ago
|
Comment 11•6 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) |
Comment 13•6 years ago
|
||
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → INCOMPLETE
Updated•2 years ago
|
Product: Testing → Remote Protocol
Comment 14•2 years ago
|
||
Moving bug to Testing::Marionette Client and Harness component per bug 1815831.
Component: Marionette → Marionette Client and Harness
Product: Remote Protocol → Testing
You need to log in
before you can comment on or make changes to this bug.
Description
•