Closed Bug 1506894 Opened 1 year ago Closed 1 year ago

Intermittent testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py TestWindowRect.test_set_position_and_size | AssertionError: 0 != 10

Categories

(Testing :: Marionette, defect, P5)

Version 3
defect

Tracking

(firefox64 unaffected, firefox65 fixed, firefox66 fixed)

RESOLVED FIXED
mozilla66
Tracking Status
firefox64 --- unaffected
firefox65 --- fixed
firefox66 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: whimboo)

References

(Depends on 1 open bug)

Details

(Keywords: intermittent-failure)

Filed by: nerli [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=211425526&repo=try

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

[task 2018-11-13T14:02:56.173Z] 14:02:56     INFO - TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py TestWindowRect.test_set_position_and_size
[task 2018-11-13T14:02:56.175Z] 14:02:56     INFO -  1542117776164	Marionette	TRACE	105 <- [1,13,null,{"value":null}]
[task 2018-11-13T14:02:56.178Z] 14:02:56     INFO -  1542117776168	Marionette	DEBUG	Closed connection 105
[task 2018-11-13T14:02:56.179Z] 14:02:56     INFO -  1542117776173	Marionette	DEBUG	Accepted connection 106 from 127.0.0.1:38548
[task 2018-11-13T14:02:56.182Z] 14:02:56     INFO -  1542117776178	Marionette	TRACE	106 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2018-11-13T14:02:56.240Z] 14:02:56     INFO -  1542117776231	Marionette	DEBUG	[2147483905] Frame script loaded
[task 2018-11-13T14:02:56.241Z] 14:02:56     INFO -  1542117776233	Marionette	DEBUG	[2147483905] Frame script registered
[task 2018-11-13T14:02:56.242Z] 14:02:56     INFO -  --DOMWINDOW == 51 (0xdddd5000) [pid = 2473] [serial = 248] [outer = (nil)] [url = about:blank]
[task 2018-11-13T14:02:56.243Z] 14:02:56     INFO -  --DOMWINDOW == 50 (0xdfdcbc00) [pid = 2473] [serial = 232] [outer = (nil)] [url = about:blank]
[task 2018-11-13T14:02:56.244Z] 14:02:56     INFO -  --DOMWINDOW == 49 (0xe04bd800) [pid = 2473] [serial = 230] [outer = (nil)] [url = about:blank]
[task 2018-11-13T14:02:56.245Z] 14:02:56     INFO -  --DOMWINDOW == 48 (0xdfad4400) [pid = 2473] [serial = 246] [outer = (nil)] [url = chrome://marionette/content/test2.xul]
[task 2018-11-13T14:02:56.246Z] 14:02:56     INFO -  --DOMWINDOW == 47 (0xe149b400) [pid = 2473] [serial = 244] [outer = (nil)] [url = chrome://marionette/content/test2.xul]
[task 2018-11-13T14:02:56.247Z] 14:02:56     INFO -  --DOMWINDOW == 46 (0xdddd8c00) [pid = 2473] [serial = 240] [outer = (nil)] [url = about:blank]
[task 2018-11-13T14:02:56.255Z] 14:02:56     INFO -  1542117776248	Marionette	TRACE	106 <- [1,1,null,{"sessionId":"9fd6f3a7-f274-4d20-bf81-fd3c8d28103d","capabilities":{"browserName":"firefox","browserVersion":"65.0" ... mp/tmpWHUOin.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}]
[task 2018-11-13T14:02:56.256Z] 14:02:56     INFO -  --DOMWINDOW == 45 (0xdfdc8400) [pid = 2473] [serial = 228] [outer = (nil)] [url = about:blank]
[task 2018-11-13T14:02:56.257Z] 14:02:56     INFO -  --DOMWINDOW == 44 (0xe310d000) [pid = 2473] [serial = 235] [outer = (nil)] [url = about:blank]
[task 2018-11-13T14:02:56.257Z] 14:02:56     INFO -  --DOMWINDOW == 43 (0xe3052800) [pid = 2473] [serial = 251] [outer = (nil)] [url = about:blank]
[task 2018-11-13T14:02:56.262Z] 14:02:56     INFO -  1542117776259	Marionette	TRACE	106 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}]
[task 2018-11-13T14:02:56.263Z] 14:02:56     INFO -  1542117776260	Marionette	TRACE	106 <- [1,2,null,{"value":null}]
[task 2018-11-13T14:02:56.265Z] 14:02:56     INFO -  1542117776264	Marionette	TRACE	106 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2018-11-13T14:02:56.269Z] 14:02:56     INFO -  1542117776266	Marionette	TRACE	106 <- [1,3,null,{"value":null}]
[task 2018-11-13T14:02:56.270Z] 14:02:56     INFO -  1542117776269	Marionette	TRACE	106 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2018-11-13T14:02:56.274Z] 14:02:56     INFO -  1542117776272	Marionette	TRACE	106 <- [1,4,null,{"value":null}]
[task 2018-11-13T14:02:56.279Z] 14:02:56     INFO -  1542117776274	Marionette	TRACE	106 -> [0,5,"WebDriver:GetWindowRect",{}]
[task 2018-11-13T14:02:56.283Z] 14:02:56     INFO -  1542117776278	Marionette	TRACE	106 <- [1,5,null,{"x":0,"y":0,"width":1280,"height":1040,"state":"normal"}]
[task 2018-11-13T14:02:56.284Z] 14:02:56     INFO -  1542117776282	Marionette	TRACE	106 -> [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}]
[task 2018-11-13T14:02:56.306Z] 14:02:56     INFO -  1542117776292	Marionette	TRACE	106 <- [1,6,null,{"value":{"width":1600,"height":1200}}]
[task 2018-11-13T14:02:56.307Z] 14:02:56     INFO -  1542117776294	Marionette	TRACE	106 -> [0,7,"WebDriver:SetWindowRect",{"y":null,"x":null,"width":1280,"height":1040}]
[task 2018-11-13T14:02:56.308Z] 14:02:56     INFO -  1542117776299	Marionette	TRACE	106 <- [1,7,null,{"x":0,"y":0,"width":1280,"height":1040,"state":"normal"}]
[task 2018-11-13T14:02:56.309Z] 14:02:56     INFO -  1542117776301	Marionette	TRACE	106 -> [0,8,"WebDriver:GetWindowRect",{}]
[task 2018-11-13T14:02:56.311Z] 14:02:56     INFO -  1542117776304	Marionette	TRACE	106 <- [1,8,null,{"x":0,"y":0,"width":1280,"height":1040,"state":"normal"}]
[task 2018-11-13T14:02:56.313Z] 14:02:56     INFO -  1542117776308	Marionette	TRACE	106 -> [0,9,"WebDriver:SetWindowRect",{"y":10,"x":10,"width":1230,"height":990}]
[task 2018-11-13T14:02:56.373Z] 14:02:56     INFO -  --DOMWINDOW == 42 (0xe3102800) [pid = 2473] [serial = 253] [outer = (nil)] [url = about:blank]
[task 2018-11-13T14:02:56.374Z] 14:02:56     INFO -  --DOMWINDOW == 41 (0xe3105000) [pid = 2473] [serial = 254] [outer = (nil)] [url = about:blank]
[task 2018-11-13T14:02:56.375Z] 14:02:56     INFO -  --DOMWINDOW == 40 (0xdf916c00) [pid = 2473] [serial = 245] [outer = (nil)] [url = chrome://marionette/content/test_nested_iframe.xul]
[task 2018-11-13T14:02:56.377Z] 14:02:56     INFO -  --DOMWINDOW == 39 (0xe31a3800) [pid = 2473] [serial = 237] [outer = (nil)] [url = about:blank]
[task 2018-11-13T14:02:56.378Z] 14:02:56     INFO -  --DOMWINDOW == 38 (0xe31aa800) [pid = 2473] [serial = 238] [outer = (nil)] [url = about:blank]
[task 2018-11-13T14:02:56.581Z] 14:02:56     INFO -  1542117776577	Marionette	TRACE	106 <- [1,9,null,{"x":0,"y":0,"width":1230,"height":990,"state":"normal"}]
[task 2018-11-13T14:02:56.590Z] 14:02:56     INFO -  1542117776584	Marionette	TRACE	106 -> [0,10,"WebDriver:GetWindowRect",{}]
[task 2018-11-13T14:02:56.591Z] 14:02:56     INFO -  1542117776587	Marionette	TRACE	106 <- [1,10,null,{"x":10,"y":10,"width":1230,"height":990,"state":"normal"}]
[task 2018-11-13T14:02:56.594Z] 14:02:56     INFO -  1542117776590	Marionette	TRACE	106 -> [0,11,"Marionette:GetContext",{}]
[task 2018-11-13T14:02:56.594Z] 14:02:56     INFO -  1542117776592	Marionette	TRACE	106 <- [1,11,null,{"value":"content"}]
[task 2018-11-13T14:02:56.602Z] 14:02:56     INFO -  1542117776597	Marionette	TRACE	106 -> [0,12,"Marionette:SetContext",{"value":"chrome"}]
[task 2018-11-13T14:02:56.603Z] 14:02:56     INFO -  1542117776598	Marionette	TRACE	106 <- [1,12,null,{"value":null}]
[task 2018-11-13T14:02:56.603Z] 14:02:56     INFO -  1542117776600	Marionette	TRACE	106 -> [0,13,"WebDriver:TakeScreenshot",{"highlights":null,"full":true,"hash":false,"id":null,"scroll":true}]
[task 2018-11-13T14:02:56.620Z] 14:02:56     INFO -  [Parent 2473, Main Thread] WARNING: Remote iframe not rendered: file /builds/worker/workspace/build/src/layout/ipc/RenderFrame.cpp, line 297
[task 2018-11-13T14:02:56.667Z] 14:02:56     INFO -  1542117776666	Marionette	TRACE	106 <- [1,13,null,{"value":"iVBORw0KGgoAAAANSUhEUgAABM4AAAPeCAYAAAD0+FZAAAAgAElEQVR4nOzd729U953ocR6u1P+jEqut1Kqr3Eit1F2ttA+iSLvNg6aq ... AAAEOcAQAAAMAQZwAAAAAwxBkAAAAADHEGAAAAAEOcAQAAAMAQZwAAAAAwxBkAAAAADHEGAAAAAEOcAQAAAMAQZwAAAAAwAg79sJDZU67PAAAAAElFTkSuQmCC"}]
[task 2018-11-13T14:02:56.677Z] 14:02:56     INFO -  1542117776671	Marionette	TRACE	106 -> [0,14,"Marionette:SetContext",{"value":"content"}]
[task 2018-11-13T14:02:56.679Z] 14:02:56     INFO -  1542117776672	Marionette	TRACE	106 <- [1,14,null,{"value":null}]
[task 2018-11-13T14:02:56.680Z] 14:02:56     INFO -  1542117776674	Marionette	TRACE	106 -> [0,15,"Marionette:GetContext",{}]
[task 2018-11-13T14:02:56.681Z] 14:02:56     INFO -  1542117776675	Marionette	TRACE	106 <- [1,15,null,{"value":"content"}]
[task 2018-11-13T14:02:56.684Z] 14:02:56     INFO -  1542117776678	Marionette	TRACE	106 -> [0,16,"Marionette:SetContext",{"value":"content"}]
[task 2018-11-13T14:02:56.685Z] 14:02:56     INFO -  1542117776681	Marionette	TRACE	106 <- [1,16,null,{"value":null}]
[task 2018-11-13T14:02:56.689Z] 14:02:56     INFO -  1542117776684	Marionette	TRACE	106 -> [0,17,"WebDriver:GetPageSource",{}]
[task 2018-11-13T14:02:56.692Z] 14:02:56     INFO -  1542117776691	Marionette	TRACE	106 <- [1,17,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>"}]
[task 2018-11-13T14:02:56.699Z] 14:02:56     INFO -  1542117776694	Marionette	TRACE	106 -> [0,18,"Marionette:SetContext",{"value":"content"}]
[task 2018-11-13T14:02:56.717Z] 14:02:56     INFO - TEST-UNEXPECTED-FAIL | testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py TestWindowRect.test_set_position_and_size | AssertionError: 0 != 10
[task 2018-11-13T14:02:56.720Z] 14:02:56     INFO - Traceback (most recent call last):
[task 2018-11-13T14:02:56.721Z] 14:02:56     INFO -   File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_harness/marionette_test/testcases.py", line 159, in run
[task 2018-11-13T14:02:56.722Z] 14:02:56     INFO -     testMethod()
[task 2018-11-13T14:02:56.723Z] 14:02:56     INFO -   File "/builds/worker/workspace/build/tests/marionette/tests/testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py", line 111, in test_set_position_and_size
[task 2018-11-13T14:02:56.724Z] 14:02:56     INFO -     self.assertEqual(new_rect["x"], wanted_rect["x"])
[task 2018-11-13T14:02:56.725Z] 14:02:56     INFO - TEST-INFO took 530ms
[task 2018-11-13T14:02:56.727Z] 14:02:56     INFO -  1542117776695	Marionette	TRACE	106 <- [1,18,null,{"value":null}]
[task 2018-11-13T14:02:56.728Z] 14:02:56     INFO -  1542117776699	Marionette	TRACE	106 -> [0,19,"WebDriver:SetWindowRect",{"y":0,"x":0,"width":1280,"height":1040}]
[task 2018-11-13T14:02:56.984Z] 14:02:56     INFO -  1542117776974	Marionette	TRACE	106 <- [1,19,null,{"x":0,"y":0,"width":1280,"height":1040,"state":"normal"}]
[task 2018-11-13T14:02:56.985Z] 14:02:56     INFO -  1542117776976	Marionette	TRACE	106 -> [0,20,"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}]
[task 2018-11-13T14:02:56.994Z] 14:02:56     INFO -  1542117776989	Marionette	TRACE	106 <- [1,20,null,{"value":null}]
[task 2018-11-13T14:02:56.996Z] 14:02:56     INFO -  1542117776991	Marionette	TRACE	106 -> [0,21,"WebDriver:DeleteSession",{}]
[task 2018-11-13T14:02:57.004Z] 14:02:57     INFO -  1542117776997	Marionette	TRACE	106 <- [1,21,null,{"value":null}]
Here the except:

https://treeherder.mozilla.org/logviewer.html#?job_id=211425526&repo=try&lineNumber=32215-32225

> 1542117776301  Marionette  TRACE   106 -> [0,8,"WebDriver:GetWindowRect",{}]
> 1542117776304  Marionette  TRACE   106 <- [1,8,null,{"x":0,"y":0,"width":1280,"height":1040,"state":"normal"}]
> 1542117776308  Marionette  TRACE   106 -> [0,9,"WebDriver:SetWindowRect",{"y":10,"x":10,"width":1230,"height":990}]
> 1542117776577  Marionette  TRACE   106 <- [1,9,null,{"x":0,"y":0,"width":1230,"height":990,"state":"normal"}]
> 1542117776584  Marionette  TRACE   106 -> [0,10,"WebDriver:GetWindowRect",{}]
> 1542117776587  Marionette  TRACE   106 <- [1,10,null,{"x":10,"y":10,"width":1230,"height":990,"state":"normal"}]

As it looks like the `WebDriver:SetWindowRect` command returns too early. The requested size has been set, but the position hasn't been reached yet.

Given that I have never seen this failure before, and bug 1492499 landed recently, this might be a regression. But so far it's only that single failure, and I also cannot reproduce locally on MacOS.
This is reminiscent of the DOM property propagation woes we had in
the past.  The response from SetWindowRect {x: 10, y: 10} reports
the X/Y position as (0,0) where we would expect (10,10), then the
next call to GetWindowRect reports (10,10).

This presumably means SetWindowRect doesn’t wait long enough for
the window to reach the requested position.  We can’t await the
position to reach (10,10) because we can never be sure it will ever
reach that due to the uniqueness of the system and its window
manager.

On the other hand, the checks in
https://searchfox.org/mozilla-central/rev/8f89901f2d69d9783f946a7458a6d7ee70635a94/testing/marionette/driver.js#1485-1488
are pretty weak for moving the window’s position.  However, I don’t
have any great ideas for how to improve it.
Maybe we should avoid using positions near the sides/edges of the screen for most of the position and size tests, by lets say having a border of 50px for safety? As we don't know what window managers will do, I feel this is the safest bet.

With bug 1478358 landed the "WebDriver:SetWindowRect" command no longer uses a timed promise to wait for a resize event. I also can no longer see this failure classified via Treeherder. So it should hopefully be fixed.

Assignee: nobody → hskupin
Status: NEW → RESOLVED
Closed: 1 year ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla66
You need to log in before you can comment on or make changes to this bug.