Closed Bug 1600391 Opened 5 years ago Closed 2 years ago

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

Categories

(Remote Protocol :: Marionette, defect, P5)

Version 3
defect

Tracking

(Not tracked)

RESOLVED WORKSFORME

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Blocks 1 open bug)

Details

Attachments

(2 files)

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


suite: marionette

context:
[task 2019-11-28T21:12:55.835Z] 21:12:55 INFO - TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py TestWindowRect.test_set_position_and_size
[task 2019-11-28T21:12:55.837Z] 21:12:55 INFO - 1574975575831 Marionette DEBUG 85 <- [1,13,null,{"value":null}]
[task 2019-11-28T21:12:55.837Z] 21:12:55 INFO - 1574975575835 Marionette DEBUG Accepted connection 86 from 127.0.0.1:45736
[task 2019-11-28T21:12:55.841Z] 21:12:55 INFO - 1574975575837 Marionette DEBUG Closed connection 85
[task 2019-11-28T21:12:55.842Z] 21:12:55 INFO - 1574975575840 Marionette DEBUG 86 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2019-11-28T21:12:55.845Z] 21:12:55 INFO - 1574975575841 Marionette TRACE [128] Frame script loaded
[task 2019-11-28T21:12:55.846Z] 21:12:55 INFO - 1574975575843 Marionette TRACE [128] Frame script registered
[task 2019-11-28T21:12:55.846Z] 21:12:55 INFO - 1574975575844 Marionette DEBUG 86 <- [1,1,null,{"sessionId":"6370505b-8035-4d3a-a352-727e76190054","capabilities":{"browserName":"firefox","browserVersion":"72.0a ... mp/tmpMPKcmX.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}]
[task 2019-11-28T21:12:55.850Z] 21:12:55 INFO - 1574975575847 Marionette DEBUG 86 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}]
[task 2019-11-28T21:12:55.850Z] 21:12:55 INFO - 1574975575847 Marionette DEBUG 86 <- [1,2,null,{"value":null}]
[task 2019-11-28T21:12:55.851Z] 21:12:55 INFO - 1574975575848 Marionette DEBUG 86 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2019-11-28T21:12:55.853Z] 21:12:55 INFO - 1574975575848 Marionette DEBUG 86 <- [1,3,null,{"value":null}]
[task 2019-11-28T21:12:55.853Z] 21:12:55 INFO - 1574975575849 Marionette DEBUG 86 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2019-11-28T21:12:55.854Z] 21:12:55 INFO - 1574975575850 Marionette DEBUG 86 <- [1,4,null,{"value":null}]
[task 2019-11-28T21:12:55.855Z] 21:12:55 INFO - 1574975575852 Marionette DEBUG 86 -> [0,5,"WebDriver:GetWindowRect",{}]
[task 2019-11-28T21:12:55.856Z] 21:12:55 INFO - 1574975575854 Marionette DEBUG 86 <- [1,5,null,{"x":0,"y":27,"width":1280,"height":1040}]
[task 2019-11-28T21:12:55.865Z] 21:12:55 INFO - 1574975575859 Marionette DEBUG 86 -> [0,6,"WebDriver:ExecuteScript",{"script":"return {\n width: window.screen.availWidth,\n height: win ... [],"filename":"tests/testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py","sandbox":null,"line":22}]
[task 2019-11-28T21:12:55.873Z] 21:12:55 INFO - 1574975575867 Marionette DEBUG 86 <- [1,6,null,{"value":{"width":1600,"height":1173}}]
[task 2019-11-28T21:12:55.873Z] 21:12:55 INFO - 1574975575867 Marionette DEBUG 86 -> [0,7,"WebDriver:SetWindowRect",{"y":null,"x":null,"width":1280,"height":1040}]
[task 2019-11-28T21:12:55.874Z] 21:12:55 INFO - 1574975575869 Marionette DEBUG 86 <- [1,7,null,{"x":0,"y":27,"width":1280,"height":1040}]
[task 2019-11-28T21:12:55.874Z] 21:12:55 INFO - 1574975575869 Marionette DEBUG 86 -> [0,8,"WebDriver:GetWindowRect",{}]
[task 2019-11-28T21:12:55.874Z] 21:12:55 INFO - 1574975575869 Marionette DEBUG 86 <- [1,8,null,{"x":0,"y":27,"width":1280,"height":1040}]
[task 2019-11-28T21:12:55.875Z] 21:12:55 INFO - 1574975575870 Marionette DEBUG 86 -> [0,9,"WebDriver:SetWindowRect",{"y":37,"x":10,"width":1230,"height":990}]
[task 2019-11-28T21:12:55.942Z] 21:12:55 INFO - 1574975575937 Marionette DEBUG 86 <- [1,9,null,{"x":0,"y":27,"width":1230,"height":990}]
[task 2019-11-28T21:12:55.943Z] 21:12:55 INFO - 1574975575938 Marionette DEBUG 86 -> [0,10,"WebDriver:GetWindowRect",{}]
[task 2019-11-28T21:12:55.944Z] 21:12:55 INFO - 1574975575939 Marionette DEBUG 86 <- [1,10,null,{"x":0,"y":27,"width":1230,"height":990}]
[task 2019-11-28T21:12:55.945Z] 21:12:55 INFO - 1574975575940 Marionette DEBUG 86 -> [0,11,"Marionette:GetContext",{}]
[task 2019-11-28T21:12:55.945Z] 21:12:55 INFO - 1574975575940 Marionette DEBUG 86 <- [1,11,null,{"value":"content"}]
[task 2019-11-28T21:12:55.945Z] 21:12:55 INFO - 1574975575941 Marionette DEBUG 86 -> [0,12,"Marionette:SetContext",{"value":"chrome"}]
[task 2019-11-28T21:12:55.946Z] 21:12:55 INFO - 1574975575941 Marionette DEBUG 86 <- [1,12,null,{"value":null}]
[task 2019-11-28T21:12:55.946Z] 21:12:55 INFO - 1574975575942 Marionette DEBUG 86 -> [0,13,"WebDriver:TakeScreenshot",{"full":true,"hash":false,"id":null,"scroll":true}]
[task 2019-11-28T21:12:56.027Z] 21:12:56 INFO - 1574975576018 Marionette DEBUG 86 <- [1,13,null,{"value":"iVBORw0KGgoAAAANSUhEUgAABM4AAAPeCAYAAAD0+FZAAAAgAElEQVR4nOzdfZAc9H3fcf7oTP9vp+lM26Sd6WTSPNRJmsStbRoHx3E6 ... AAQ5wBAAAAwBBnAAAAADDEGQAAAAAMcQYAAAAAQ5wBAAAAwBBnAAAAADDEGQAAAAAMcQYAAAAAQ5wBAAAAwBBnAAAAADAC0EJFmdZZoXsAAAAASUVORK5CYII="}]
[task 2019-11-28T21:12:56.027Z] 21:12:56 INFO - 1574975576020 Marionette DEBUG 86 -> [0,14,"Marionette:SetContext",{"value":"content"}]
[task 2019-11-28T21:12:56.027Z] 21:12:56 INFO - 1574975576020 Marionette DEBUG 86 <- [1,14,null,{"value":null}]
[task 2019-11-28T21:12:56.043Z] 21:12:56 INFO - 1574975576034 Marionette DEBUG 86 -> [0,15,"Marionette:GetContext",{}]
[task 2019-11-28T21:12:56.043Z] 21:12:56 INFO - 1574975576035 Marionette DEBUG 86 <- [1,15,null,{"value":"content"}]
[task 2019-11-28T21:12:56.043Z] 21:12:56 INFO - 1574975576035 Marionette DEBUG 86 -> [0,16,"Marionette:SetContext",{"value":"content"}]
[task 2019-11-28T21:12:56.043Z] 21:12:56 INFO - 1574975576036 Marionette DEBUG 86 <- [1,16,null,{"value":null}]
[task 2019-11-28T21:12:56.043Z] 21:12:56 INFO - 1574975576036 Marionette DEBUG 86 -> [0,17,"WebDriver:GetPageSource",{}]
[task 2019-11-28T21:12:56.079Z] 21:12: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 2019-11-28T21:12:56.080Z] 21:12:56 INFO - Traceback (most recent call last):
[task 2019-11-28T21:12:56.081Z] 21:12:56 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_harness/marionette_test/testcases.py", line 159, in run
[task 2019-11-28T21:12:56.082Z] 21:12:56 INFO - testMethod()
[task 2019-11-28T21:12:56.082Z] 21:12: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 2019-11-28T21:12:56.083Z] 21:12:56 INFO - self.assertEqual(new_rect["x"], wanted_rect["x"])
[task 2019-11-28T21:12:56.084Z] 21:12:56 INFO - TEST-INFO took 221ms

Similar to bug 1600389, which seems to be related to a menu bar displayed at the top of the screen. Maybe we should account a number of pixels on all sides to not being used for tests.

Edwin, does changing the initial position of the window in this line to eg (50/50) fix the issue for you (just add x and y as first arguments)?

https://searchfox.org/mozilla-central/rev/073b138dcba41cd3f858522e5f0a9ee73e39afa0/testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py#33

Otherwise using https://developer.mozilla.org/en-US/docs/Web/API/Screen/availTop (and availLeft) could also be an option here.

Flags: needinfo?(egao)
See Also: → 1600389

I've pushed to try with the call changed to:
self.marionette.set_window_rect(x=50, y=50, height=start_size["height"], width=start_size["width"])

The push is at https://treeherder.mozilla.org/#/jobs?repo=try&revision=9d524881b28a2180980cd8f6b9c1bdad8af07998.

Flags: needinfo?(egao)

The changes does not appear to have resolved the issue. The expected values simply increment by however many the x/y coordinates are set by.

eg. TEST-UNEXPECTED-FAIL | testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py TestWindowRect.test_set_position_and_size | AssertionError: 50 != 60
This used to be 0 != 10, now it is 50 != 60.

I will try pushing the x, y = (50, 50) change in conjunction with removing the top menu bar and see if that changes anything.

There is clearly a problem with Webdriver:SetWindowRect:

[task 2019-12-02T20:27:55.597Z] 20:27:55     INFO -  1575318475594	Marionette	DEBUG	86 -> [0,9,"WebDriver:SetWindowRect",{"y":60,"x":60,"width":1230,"height":990}]
[task 2019-12-02T20:27:55.657Z] 20:27:55     INFO -  1575318475653	Marionette	DEBUG	86 <- [1,9,null,{"x":50,"y":50,"width":1230,"height":990}]

Could you check (maybe locally) if moveTo() gets called here with the correct target coordinates?

https://searchfox.org/mozilla-central/rev/04d8e7629354bab9e6a285183e763410860c5006/testing/marionette/driver.js#1532

You can add a dump() line, and run the marionette test with -vv --gecko-log - to see the output in the console.

On my macosx1015 workstation:

  0:28.62 TEST_START: testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py TestWindowRect.test_set_position_and_size
x coordinate: 4y coordinate: 231575411665964	Marionette	DEBUG	11 <- [1,11,null,{"x":4,"y":23,"width":1280,"height":1062}]
1575411665965	Marionette	DEBUG	11 -> [0,12,"WebDriver:ExecuteScript",{"script":"return document.fullscreenElement;","newSandbox":true,"args":[],"filename":"testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py","sandbox":null,"line":41}]
1575411665967	Marionette	DEBUG	11 <- [1,12,null,{"value":null}]
1575411665968	Marionette	DEBUG	11 -> [0,13,"WebDriver:DeleteSession",{}]
1575411665969	Marionette	DEBUG	11 <- [1,13,null,{"value":null}]
1575411665972	Marionette	DEBUG	Closed connection 11
1575411665973	Marionette	DEBUG	Accepted connection 12 from 127.0.0.1:65348
1575411665974	Marionette	DEBUG	12 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
1575411665976	Marionette	TRACE	[6] Frame script loaded
1575411665977	Marionette	TRACE	[6] Frame script registered
1575411665978	Marionette	DEBUG	12 <- [1,1,null,{"sessionId":"828930cd-c0d7-1c43-9adb-07406acf5a2f","capabilities":{"browserName":"firefox","browserVersion":"73.0a ... /T/tmpCmXW6A.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}]
1575411665980	Marionette	DEBUG	12 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}]
1575411665980	Marionette	DEBUG	12 <- [1,2,null,{"value":null}]
1575411665983	Marionette	DEBUG	12 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}]
1575411665983	Marionette	DEBUG	12 <- [1,3,null,{"value":null}]
1575411665986	Marionette	DEBUG	12 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}]
1575411665986	Marionette	DEBUG	12 <- [1,4,null,{"value":null}]
1575411665987	Marionette	DEBUG	12 -> [0,5,"WebDriver:GetWindowRect",{}]
1575411665988	Marionette	DEBUG	12 <- [1,5,null,{"x":4,"y":23,"width":1280,"height":1062}]
1575411665990	Marionette	DEBUG	12 -> [0,6,"WebDriver:ExecuteScript",{"script":"return {\n              width: window.screen.availWidth,\n              height: win ... args":[],"filename":"testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py","sandbox":null,"line":22}]
1575411665994	Marionette	DEBUG	12 <- [1,6,null,{"value":{"width":3840,"height":2108}}]
1575411665996	Marionette	DEBUG	12 -> [0,7,"WebDriver:SetWindowRect",{"y":50,"x":50,"width":1280,"height":1062}]
x coordinate: 50y coordinate: 501575411666113	Marionette	DEBUG	12 <- [1,7,null,{"x":50,"y":50,"width":1280,"height":1062}]
1575411666114	Marionette	DEBUG	12 -> [0,8,"WebDriver:GetWindowRect",{}]
1575411666115	Marionette	DEBUG	12 <- [1,8,null,{"x":50,"y":50,"width":1280,"height":1062}]
1575411666116	Marionette	DEBUG	12 -> [0,9,"WebDriver:SetWindowRect",{"y":60,"x":60,"width":1230,"height":1012}]
x coordinate: 60y coordinate: 601575411666164	Marionette	DEBUG	12 <- [1,9,null,{"x":60,"y":60,"width":1230,"height":1012}]
1575411666165	Marionette	DEBUG	12 -> [0,10,"WebDriver:GetWindowRect",{}]
1575411666165	Marionette	DEBUG	12 <- [1,10,null,{"x":60,"y":60,"width":1230,"height":1012}]
1575411666167	Marionette	DEBUG	12 -> [0,11,"WebDriver:SetWindowRect",{"y":23,"x":4,"width":1280,"height":1062}]
 0:28.85 TEST_END: PASS

On my ubuntu1804 virtual machine with no changes made to the theme or desktop environment:

0:11.69 TEST_START: testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py TestWindowRect.test_set_position_and_size
1575412079103	Marionette	DEBUG	11 <- [1,13,null,{"value":null}]
1575412079107	Marionette	DEBUG	Closed connection 11
1575412079111	Marionette	DEBUG	Accepted connection 12 from 127.0.0.1:58232
1575412079115	Marionette	DEBUG	12 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
1575412079120	Marionette	TRACE	[4] Frame script loaded
1575412079121	Marionette	TRACE	[4] Frame script registered
1575412079128	Marionette	DEBUG	12 <- [1,1,null,{"sessionId":"1ba6902c-f1e3-44d6-a7e8-4a35a404edd9","capabilities":{"browserName":"firefox","browserVersion":"73.0a ... mp/tmpVn7nP7.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}]
1575412079141	Marionette	DEBUG	12 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}]
1575412079142	Marionette	DEBUG	12 <- [1,2,null,{"value":null}]
1575412079142	Marionette	DEBUG	12 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}]
1575412079145	Marionette	DEBUG	12 <- [1,3,null,{"value":null}]
1575412079151	Marionette	DEBUG	12 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}]
1575412079152	Marionette	DEBUG	12 <- [1,4,null,{"value":null}]
1575412079159	Marionette	DEBUG	12 -> [0,5,"WebDriver:GetWindowRect",{}]
1575412079160	Marionette	DEBUG	12 <- [1,5,null,{"x":67,"y":27,"width":1280,"height":1040}]
1575412079171	Marionette	DEBUG	12 -> [0,6,"WebDriver:ExecuteScript",{"script":"return {\n              width: window.screen.availWidth,\n              height: win ... args":[],"filename":"testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py","sandbox":null,"line":22}]
1575412079178	Marionette	DEBUG	12 <- [1,6,null,{"value":{"width":1556,"height":1374}}]
1575412079198	Marionette	DEBUG	12 -> [0,7,"WebDriver:SetWindowRect",{"y":50,"x":50,"width":1280,"height":1040}]
x coordinate: 50y coordinate: 501575412079223	Marionette	DEBUG	12 <- [1,7,null,{"x":67,"y":27,"width":1280,"height":1040}]
1575412079224	Marionette	DEBUG	12 -> [0,8,"WebDriver:GetWindowRect",{}]
1575412079225	Marionette	DEBUG	12 <- [1,8,null,{"x":67,"y":27,"width":1280,"height":1040}]
1575412079226	Marionette	DEBUG	12 -> [0,9,"WebDriver:SetWindowRect",{"y":37,"x":77,"width":1230,"height":990}]
x coordinate: 77y coordinate: 371575412079303	Marionette	DEBUG	12 <- [1,9,null,{"x":67,"y":27,"width":1230,"height":990}]
1575412079304	Marionette	DEBUG	12 -> [0,10,"WebDriver:GetWindowRect",{}]
1575412079311	Marionette	DEBUG	12 <- [1,10,null,{"x":67,"y":27,"width":1230,"height":990}]
1575412079313	Marionette	DEBUG	12 -> [0,11,"Marionette:GetContext",{}]
1575412079313	Marionette	DEBUG	12 <- [1,11,null,{"value":"content"}]
1575412079314	Marionette	DEBUG	12 -> [0,12,"Marionette:SetContext",{"value":"chrome"}]
1575412079314	Marionette	DEBUG	12 <- [1,12,null,{"value":null}]
1575412079330	Marionette	DEBUG	12 -> [0,13,"WebDriver:TakeScreenshot",{"full":true,"hash":false,"id":null,"scroll":true}]
1575412079422	Marionette	DEBUG	12 <- [1,13,null,{"value":"iVBORw0KGgoAAAANSUhEUgAABM4AAAPeCAYAAAD0+FZAAAAgAElEQVR4nOzd6XfU9d3/8f5HlWq9fu3VXu1pXapGoKKyKpBIihtYKhCQ ... AAADDEGQAAAAAMcQYAAAAAQ5wBAAAAwBBnAAAAADDEGQAAAAAMcQYAAAAAQ5wBAAAAwBBnAAAAADDEGQAAAAAMcQYAAAAAI+8ynq5dFKqOAAAAAElFTkSuQmCC"}]
1575412079428	Marionette	DEBUG	12 -> [0,14,"Marionette:SetContext",{"value":"content"}]
1575412079428	Marionette	DEBUG	12 <- [1,14,null,{"value":null}]
1575412079434	Marionette	DEBUG	12 -> [0,15,"Marionette:GetContext",{}]
1575412079434	Marionette	DEBUG	12 <- [1,15,null,{"value":"content"}]
1575412079439	Marionette	DEBUG	12 -> [0,16,"Marionette:SetContext",{"value":"content"}]
1575412079443	Marionette	DEBUG	12 <- [1,16,null,{"value":null}]
1575412079444	Marionette	DEBUG	12 -> [0,17,"WebDriver:GetPageSource",{}]
1575412079445	Marionette	DEBUG	12 <- [1,17,null,{"value":"<html><head></head><body></body></html>"}]
 0:12.03 TEST_END: FAIL, expected PASS - AssertionError: 67 != 77
Traceback (most recent call last):
  File "/home/worker/mozilla-central/testing/marionette/harness/marionette_harness/marionette_test/testcases.py", line 159, in run
    testMethod()
  File "/home/worker/mozilla-central/testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py", line 111, in test_set_position_and_size
    self.assertEqual(new_rect["x"], wanted_rect["x"])

1575412079448	Marionette	DEBUG	12 -> [0,18,"Marionette:SetContext",{"value":"content"}]
1575412079448	Marionette	DEBUG	12 <- [1,18,null,{"value":null}]
1575412079467	Marionette	DEBUG	12 -> [0,19,"WebDriver:SetWindowRect",{"y":27,"x":67,"width":1280,"height":1040}]
x coordinate: 67y coordinate: 271575412079545	Marionette	DEBUG	12 <- [1,19,null,{"x":67,"y":27,"width":1280,"height":1040}]
1575412079562	Marionette	DEBUG	12 -> [0,20,"WebDriver:ExecuteScript",{"script":"return document.fullscreenElement;","newSandbox":true,"args":[],"filename":"testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py","sandbox":null,"line":41}]
1575412079577	Marionette	DEBUG	12 <- [1,20,null,{"value":null}]
1575412079595	Marionette	DEBUG	12 -> [0,21,"WebDriver:DeleteSession",{}]
1575412079601	Marionette	DEBUG	12 <- [1,21,null,{"value":null}]

I ran the test again, but this time with the top menu bar removed, and the dock moved from its default position on left to the bottom.

0:15.60 TEST_START: testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py TestWindowRect.test_set_position_and_size
1575413141244	Marionette	DEBUG	Closed connection 11
1575413141251	Marionette	DEBUG	Accepted connection 12 from 127.0.0.1:59784
1575413141253	Marionette	DEBUG	12 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
1575413141260	Marionette	TRACE	[4] Frame script loaded
1575413141267	Marionette	TRACE	[4] Frame script registered
1575413141269	Marionette	DEBUG	12 <- [1,1,null,{"sessionId":"16b7b5bd-c9d2-4afd-ad2d-84fbeef1576c","capabilities":{"browserName":"firefox","browserVersion":"73.0a ... mp/tmpws6gH2.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}]
1575413141271	Marionette	DEBUG	12 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}]
1575413141271	Marionette	DEBUG	12 <- [1,2,null,{"value":null}]
1575413141275	Marionette	DEBUG	12 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}]
1575413141279	Marionette	DEBUG	12 <- [1,3,null,{"value":null}]
1575413141282	Marionette	DEBUG	12 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}]
1575413141283	Marionette	DEBUG	12 <- [1,4,null,{"value":null}]
1575413141284	Marionette	DEBUG	12 -> [0,5,"WebDriver:GetWindowRect",{}]
1575413141288	Marionette	DEBUG	12 <- [1,5,null,{"x":50,"y":50,"width":1280,"height":1040}]
1575413141290	Marionette	DEBUG	12 -> [0,6,"WebDriver:ExecuteScript",{"script":"return {\n              width: window.screen.availWidth,\n              height: win ... args":[],"filename":"testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py","sandbox":null,"line":22}]
1575413141317	Marionette	DEBUG	12 <- [1,6,null,{"value":{"width":1623,"height":1352}}]
1575413141332	Marionette	DEBUG	12 -> [0,7,"WebDriver:SetWindowRect",{"y":50,"x":50,"width":1280,"height":1040}]
1575413141333	Marionette	DEBUG	12 <- [1,7,null,{"x":50,"y":50,"width":1280,"height":1040}]
1575413141336	Marionette	DEBUG	12 -> [0,8,"WebDriver:GetWindowRect",{}]
1575413141337	Marionette	DEBUG	12 <- [1,8,null,{"x":50,"y":50,"width":1280,"height":1040}]
1575413141338	Marionette	DEBUG	12 -> [0,9,"WebDriver:SetWindowRect",{"y":60,"x":60,"width":1230,"height":990}]
x coordinate: 60y coordinate: 601575413141448	Marionette	DEBUG	12 <- [1,9,null,{"x":50,"y":50,"width":1230,"height":990}]
1575413141449	Marionette	DEBUG	12 -> [0,10,"WebDriver:GetWindowRect",{}]
1575413141452	Marionette	DEBUG	12 <- [1,10,null,{"x":50,"y":50,"width":1230,"height":990}]
1575413141454	Marionette	DEBUG	12 -> [0,11,"Marionette:GetContext",{}]
1575413141459	Marionette	DEBUG	12 <- [1,11,null,{"value":"content"}]
1575413141472	Marionette	DEBUG	12 -> [0,12,"Marionette:SetContext",{"value":"chrome"}]
1575413141473	Marionette	DEBUG	12 <- [1,12,null,{"value":null}]
1575413141477	Marionette	DEBUG	12 -> [0,13,"WebDriver:TakeScreenshot",{"full":true,"hash":false,"id":null,"scroll":true}]
1575413141629	Marionette	DEBUG	12 <- [1,13,null,{"value":"iVBORw0KGgoAAAANSUhEUgAABM4AAAPeCAYAAAD0+FZAAAAgAElEQVR4nOzd6XfU9d3/8f5HlWq9fu3VXu1pXapGoKKyKpBIihtYKhCQ ... AAADDEGQAAAAAMcQYAAAAAQ5wBAAAAwBBnAAAAADDEGQAAAAAMcQYAAAAAQ5wBAAAAwBBnAAAAADDEGQAAAAAMcQYAAAAAI+8ynq5dFKqOAAAAAElFTkSuQmCC"}]
1575413141652	Marionette	DEBUG	12 -> [0,14,"Marionette:SetContext",{"value":"content"}]
1575413141653	Marionette	DEBUG	12 <- [1,14,null,{"value":null}]
1575413141663	Marionette	DEBUG	12 -> [0,15,"Marionette:GetContext",{}]
1575413141664	Marionette	DEBUG	12 <- [1,15,null,{"value":"content"}]
1575413141671	Marionette	DEBUG	12 -> [0,16,"Marionette:SetContext",{"value":"content"}]
1575413141672	Marionette	DEBUG	12 <- [1,16,null,{"value":null}]
1575413141673	Marionette	DEBUG	12 -> [0,17,"WebDriver:GetPageSource",{}]
1575413141676	Marionette	DEBUG	12 <- [1,17,null,{"value":"<html><head></head><body></body></html>"}]
1575413141677	Marionette	DEBUG	12 -> [0,18,"Marionette:SetContext",{"value":"content"}]
1575413141677	Marionette	DEBUG	12 <- [1,18,null,{"value":null}]
 0:16.05 TEST_END: FAIL, expected PASS - AssertionError: 50 != 60
Traceback (most recent call last):
  File "/home/worker/mozilla-central/testing/marionette/harness/marionette_harness/marionette_test/testcases.py", line 159, in run
    testMethod()
  File "/home/worker/mozilla-central/testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py", line 111, in test_set_position_and_size
    self.assertEqual(new_rect["x"], wanted_rect["x"])

1575413141682	Marionette	DEBUG	12 -> [0,19,"WebDriver:SetWindowRect",{"y":50,"x":50,"width":1280,"height":1040}]
x coordinate: 50y coordinate: 501575413141936	Marionette	DEBUG	12 <- [1,19,null,{"x":50,"y":50,"width":1280,"height":1040}]
1575413141937	Marionette	DEBUG	12 -> [0,20,"WebDriver:ExecuteScript",{"script":"return document.fullscreenElement;","newSandbox":true,"args":[],"filename":"testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py","sandbox":null,"line":41}]
1575413141954	Marionette	DEBUG	12 <- [1,20,null,{"value":null}]
1575413141969	Marionette	DEBUG	12 -> [0,21,"WebDriver:DeleteSession",{}]
1575413141972	Marionette	DEBUG	12 <- [1,21,null,{"value":null}]

I was able to get the test run to pass intermittently, but with some extensive changes to the desktop environment.

The following changes were made:

  • (x, y) = (50, 50) initial change reverted
  • all other test cases except test_window_rect.py TestWindowRect.test_set_position_and_size removed from test file
  • top menu bar hidden
  • dock moved to the bottom of screen (this appears to be the environment the docker image provides, so strictly speaking this isn't a modification)

With these changes, the test run produces an alternating PASS and FAIL results - each run seems to affect the next run's window position, despite the harness starting up from scratch each time. It may be a coincidence though.

When the test is run in a bash loop for 15 times, it produced a PASS result approximately 25% of the time.
I am suspecting if there's something to do with timing of the runs that's causing this failure, even if the desktop environment is adjusted to hide any other elements.

PASS cases have the expected (x, y) value of (38, 38).
FAIL cases have the expected (x, y) value of (38, 38) as well, but the actual reported coordinates are (28, 28) every time.

Dock on left, top menu bar present

worker@worker-VirtualBox:~/mozilla-central$ for i in {0..10}; do ./mach marionette-test testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py -vv --gecko-log - | grep TEST_END | tee results_dock_left_top_bar_hidden.txt; sleep 5; done
 0:06.60 TEST_END: FAIL, expected PASS - AssertionError: 95 != 105
 0:08.00 TEST_END: FAIL, expected PASS - AssertionError: 95 != 105
 0:06.78 TEST_END: FAIL, expected PASS - AssertionError: 95 != 105
 0:11.96 TEST_END: FAIL, expected PASS - AssertionError: 95 != 105
 0:07.17 TEST_END: FAIL, expected PASS - AssertionError: 95 != 105
 0:07.34 TEST_END: FAIL, expected PASS - AssertionError: 95 != 105
 0:08.45 TEST_END: FAIL, expected PASS - AssertionError: 95 != 105
 0:08.61 TEST_END: FAIL, expected PASS - AssertionError: 95 != 105
 0:11.24 TEST_END: FAIL, expected PASS - AssertionError: 95 != 105
 0:06.66 TEST_END: FAIL, expected PASS - AssertionError: 95 != 105
 0:07.26 TEST_END: FAIL, expected PASS - AssertionError: 95 != 105

Dock moved to bottom, top menu bar present

worker@worker-VirtualBox:~/mozilla-central$ for i in {0..10}; do ./mach marionette-test testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py -vv --gecko-log - | grep TEST_END | tee results_dock_left_top_bar_hidden.txt; sleep 5; done
 0:07.03 TEST_END: FAIL, expected PASS - AssertionError: 0 != 10
 0:06.55 TEST_END: FAIL, expected PASS - AssertionError: 0 != 10
 0:13.13 TEST_END: FAIL, expected PASS - AssertionError: 0 != 10
 0:07.44 TEST_END: FAIL, expected PASS - AssertionError: 0 != 10
 0:07.80 TEST_END: FAIL, expected PASS - AssertionError: 0 != 10
 0:07.38 TEST_END: FAIL, expected PASS - AssertionError: 0 != 10
 0:06.92 TEST_END: FAIL, expected PASS - AssertionError: 0 != 10
 0:10.23 TEST_END: PASS
 0:06.50 TEST_END: PASS
 0:06.62 TEST_END: PASS
 0:13.40 TEST_END: FAIL, expected PASS - AssertionError: 0 != 10

Dock moved to bottom, top menu bar removed

worker@worker-VirtualBox:~/mozilla-central$ for i in {0..10}; do ./mach marionette-test testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py -vv --gecko-log - | grep TEST_END | tee results_dock_left_top_bar_hidden.txt; sleep 5; done
 0:07.56 TEST_END: FAIL, expected PASS - AssertionError: 50 != 60
 0:07.11 TEST_END: FAIL, expected PASS - AssertionError: 50 != 60
 0:06.74 TEST_END: FAIL, expected PASS - AssertionError: 50 != 60
 0:07.39 TEST_END: FAIL, expected PASS - AssertionError: 50 != 60
 0:06.98 TEST_END: FAIL, expected PASS - AssertionError: 50 != 60
 0:07.68 TEST_END: FAIL, expected PASS - AssertionError: 50 != 60
 0:06.25 TEST_END: PASS
 0:07.45 TEST_END: FAIL, expected PASS - AssertionError: 50 != 60
 0:06.50 TEST_END: FAIL, expected PASS - AssertionError: 50 != 60
 0:06.76 TEST_END: FAIL, expected PASS - AssertionError: 50 != 60
 0:09.84 TEST_END: FAIL, expected PASS - AssertionError: 50 != 60

I'm honestly not sure what the issue here is, the results are all over the place and not what I would have expected.

I started up my ubuntu1804 VM with a second monitor attached, which means no top menu bar, no dock, etc to hide, more accurately reproducing the environment the previous docker images would have ran under.

In this new environment with 1600x1200 fully available to the test window:

-----------------
FAIL testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py TestWindowRect.test_resize_larger_than_screen - AssertionError: 1170 not greater than or equal to 1200
Traceback (most recent call last):
  File "/home/worker/mozilla-central/testing/marionette/harness/marionette_harness/marionette_test/testcases.py", line 159, in run
    testMethod()
  File "/home/worker/mozilla-central/testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py", line 208, in test_resize_larger_than_screen
    self.assertGreaterEqual(new_size["height"], self.max["height"])
FAIL testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py TestWindowRect.test_resize_to_available_screen_size - AssertionError: 1170 not greater than or equal to 1200
Traceback (most recent call last):
  File "/home/worker/mozilla-central/testing/marionette/harness/marionette_harness/marionette_test/testcases.py", line 159, in run
    testMethod()
  File "/home/worker/mozilla-central/testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py", line 218, in test_resize_to_available_screen_size
    self.assertGreaterEqual(expected_size["height"], self.max["height"])
1575447296082	Marionette	DEBUG	Closed connection 15

So something is still preventing the window max size to be registered as 1170 instead of 1200. The dock is set to 48px, so not sure where the 30px discrepancy is coming from.

I suspect that this issue with pixel position/count in the marionette harness is causing various suites that rely on marionette to also report failures, so I'm quite eager to investigate and arrive at a fix for this.

Thanks Edwin that you had a look at that! As it looks like there might be different things to check/do:

  1. Find a proper default location and size of the window for setUp / tearDown to reduce the risk of affecting following tests

  2. Could it be that moving the window by 10px only is below a specific threshold that is preventing the window manager to actually move the window? What happens when you increase that value to 25px or even more? If that is the problem we might have to talk to someone from GFX.

  3. Trying to make the tests more stable for all the environments by taking possible docker or menu bars into account. Especially when those are located at the left or top of the screen

I was following my bugmail and in https://bugzilla.mozilla.org/show_bug.cgi?id=1600809#c4, Julian mentioned in his investigations that it appears ubuntu1804 window resize/move appears more async than previous platforms.

While I am not 100% sure if this is the cause for the failures, it may explain nicely why we're seeing discrepancy in the expected and actual coordinates not align during the test cases.

What I need to pin down, is if adding ~0.1s delays and re-checking the window position could make the discrepancy disappear.

What that doesn't solve is the pixel discrepancy between 1200 and 1170; that remains unexplained.

I think I have my answer for the reason for the pixel count being reported as 1170 in the marionette harness.

Take a look at the screenshot attached.

In ubuntu1604, the output of window.outerHeight and window.screen.availHeight are identical, at 1176 in the case of the VM.
In ubuntu1804, the output of window.outerHeight and window.screen.availHeight are different - first reports 1172, second reports 1200.

So when marionette goes to compare the two values, 1172 <= 1200 so we have failures in tests that expect both values to match.

The window.screen.availTop value is reported as 22, so when tests require moving to either (0, 0) or a negative coordinate, the 22px top padding is blocking the move, and tests fail since 0 != 22.

As proof of concept on my ubuntu1804 virtual machine, I was able to get the test_window_rect.py tests to all pass with the following changes:

diff -r d1001fea6e4c testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py
--- a/testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py      Tue Dec 03 19:06:29 2019 +0100
+++ b/testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py      Wed Dec 04 11:41:26 2019 -0800
@@ -17,8 +17,8 @@
 
         self.max = self.marionette.execute_script("""
             return {
-              width: window.screen.availWidth,
-              height: window.screen.availHeight,
+              width: window.outerWidth,
+              height: window.outerHeight,
             }""", sandbox=None)
 
         # WebDriver spec says a resize cannot result in window being
 
@@ -180,8 +186,10 @@
         # assume a window can be moved to (0,0) or less.
         elif os == "linux":
             # certain WMs prohibit windows from being moved off-screen
+           top_margin = self.marionette.execute_script("""
+               return {top_margin: window.screen.availTop}""", sandbox=None)
             self.assertLessEqual(new_position["x"], 0)
-            self.assertLessEqual(new_position["y"], 0)
+            self.assertLessEqual(new_position["y"], top_margin)
 
         # On macOS, windows can only be moved off the screen on the
         # horizontal axis.  The system menu bar also blocks windows from
1575488612328	Marionette	DEBUG	15 -> [0,6,"WebDriver:ExecuteScript",{"script":"return {\n              width: window.outerWidth,\n              height: window.out ... args":[],"filename":"testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py","sandbox":null,"line":22}]
1575488612333	Marionette	DEBUG	15 <- [1,6,null,{"value":{"width":1280,"height":1040}}]
1575488612334	Marionette	DEBUG	15 -> [0,7,"WebDriver:SetWindowRect",{"y":null,"x":null,"width":1270,"height":1030}]
THIS IS AN ALERT12801270104010301575488612384	Marionette	DEBUG	15 <- [1,7,null,{"x":28,"y":50,"width":1270,"height":1030}]
1575488612385	Marionette	DEBUG	15 -> [0,8,"WebDriver:SetWindowRect",{"y":50,"x":28,"width":1280,"height":1040}]
THIS IS AN ALERT12701280103010401575488612445	Marionette	DEBUG	15 <- [1,8,null,{"x":28,"y":50,"width":1280,"height":1040}]
1575488612447	Marionette	DEBUG	15 -> [0,9,"WebDriver:ExecuteScript",{"script":"return document.fullscreenElement;","newSandbox":true,"args":[],"filename":"testing/marionette/harness/marionette_harness/tests/unit/test_window_rect.py","sandbox":null,"line":41}]
1575488612456	Marionette	DEBUG	15 <- [1,9,null,{"value":null}]
1575488612457	Marionette	DEBUG	15 -> [0,10,"WebDriver:DeleteSession",{}]
 0:12.52 TEST_END: PASS
 0:12.52 INFO 
SUMMARY
-------
 0:12.52 INFO passed: 13
 0:12.52 INFO failed: 0
 0:12.52 INFO todo: 0
 0:12.52 SUITE_END

marionette-test
~~~~~~~~~~~~~~~
Ran 13 checks (13 tests)
Expected results: 13
Unexpected results: 0
OK

So, the challenge now is to incorporate this to the core driver.js so on ubuntu1804 the expectations is to take into account window.screen.availTop into the height pixel calculation that would work in all situations.

(In reply to Edwin Takahashi (:egao, :etakahashi) from comment #11)

In ubuntu1604, the output of window.outerHeight and window.screen.availHeight are identical, at 1176 in the case of the VM.
In ubuntu1804, the output of window.outerHeight and window.screen.availHeight are different - first reports 1172, second reports 1200.

This is strange! Karl, could you please have a look at that? Do you have any ideas why this difference exists on Ubuntu 18.04 now? Basically for a maximized window those values should still be equal, right?

The window.screen.availTop value is reported as 22, so when tests require moving to either (0, 0) or a negative coordinate, the 22px top padding is blocking the move, and tests fail since 0 != 22.

Yes, that is what I mentioned above. This fix I'm happy to review a patch for, but for the former issue we still need clarification.

Karl, can you please have a look at my last comment regarding the difference between window.outerHeight and window.screen.availHeight? Thanks

Flags: needinfo?(karlt)

As an addendum, I re-enabled the top menu bar for the ubuntu1804 virtual machine (it had been disabled and hidden for the screenshot in comment 13). This would bring the testing scenario closer to ubuntu1604 which has an unremovable top bar.

With the top bar restored:
window.outerHeight produced 1145
window.screen.availHeight produced 1173

I suspect that window.outerHeight on GNOME isn't including the title bar of the chrome itself. This wasn't a problem in Unity because the title bar and the top bar was unified. I could be totally wrong since this is not my area of expertise.

(In reply to Edwin Takahashi (:egao, :etakahashi) from comment #16)

I suspect that window.outerHeight on GNOME isn't including the title bar of the chrome itself. This wasn't a problem in Unity because the title bar and the top bar was unified.

That's correct. https://bugzilla.mozilla.org/show_bug.cgi?id=581863

And yes, on Unity, there wasn't really a titlebar on maximized windows.

Flags: needinfo?(karlt)

Aside from the difference in the values, the more async nature of the window move/resize in ubuntu1804/gnome is still causing issues and I am not sure how to resolve it.

I've looked into driver.js and mucked around to make it less async, that did not work.
I've tried to enforce order in marionette.py > set_window_rect but haven't been able to come up with anything that works.

As mentioned earlier moveTo() is synchronous or at least should be when you also check the [source of mozilla-central](https://searchfox.org/mozilla-central/search?q=window.moveTo(&case=false&regexp=false&path=). If it has an asynchronous behavior now, shouldn't this be a regression in Core : DOM?

(In reply to Henrik Skupin (:whimboo) [⌚️UTC+2] from comment #20)

As mentioned earlier moveTo() is synchronous or at least should be when you also check the [source of mozilla-central](https://searchfox.org/mozilla-central/search?q=window.moveTo(&case=false&regexp=false&path=). If it has an asynchronous behavior now, shouldn't this be a regression in Core : DOM?

I am not sure what is true anymore, to be honest. The test case passes without issue when run in the VM after my tweaks (from comment 13) are applied, so to me it doesn't seem like the marionette driver has issues.

But on the other hand I can't get marionette to pass reliably in CI, and other tests that rely on marionette like wdspec also experience either positioning, window size or similar failures.

The most ideal scenario would be for me to reproduce the xvfb configuration that CI runs, but I'm not sure how to do that.

I found that if I replace the default gnome desktop environment with just the compiz window manager, then all tests (including this one) pass reliably.

see try: https://treeherder.mozilla.org/#/jobs?repo=try&group_state=expanded&selectedJob=279931219&revision=a5c059e5668e3db07165855f67038f3c8a07866d

Having compiz also fixes a bunch of other tests that implicitly relied on it, resulting in fewer unexpected failures. Which is good.

But, as I was about to put up a patch to use compiz window manager full-time in bug 1601828, it was brought to attention that this is modifying the environment for sake of the test, so I have decided against replacing gnome with compiz for the time being. Which means tests will continue to fail.

So, it's definitely something to do with the gnome desktop environment that is causing this async-iness to occur when repositioning and resizing windows. Why this happens, I still don't know, and I'm running out of ideas to try.

Note that I filed bug 1602387 to further investigate this problem for Ubuntu 18.04.

No more failures within the last year. Closing as WFM.

Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → WORKSFORME
Product: Testing → Remote Protocol
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: