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

Reporter

Description

•

6 years ago

treeherder

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}]

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

Assignee

Comment 1

•

6 years ago

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.

Blocks: 1492499

status-firefox64: --- → unaffected

status-firefox65: --- → affected

Comment hidden (Intermittent Failures Robot)

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

Repository breakdown:
* mozilla-inbound: 1
* mozilla-central: 2
* try: 1

Platform breakdown:
* linux32: 3
* windows10-64: 1

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

Andreas Tolfsen ❲:ato❳

Comment 3

•

6 years ago

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.

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

Assignee

Comment 4

•

6 years ago

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.

Comment hidden (Intermittent Failures Robot)

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

Repository breakdown:
* mozilla-inbound: 1
* autoland: 1

Platform breakdown:
* linux64: 2

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

Comment hidden (Intermittent Failures Robot)

14 failures in 2808 pushes (0.005 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 6
* autoland: 7
* mozilla-central: 1

Platform breakdown:
* linux32: 9
* linux64: 5

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

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

Assignee

Updated

•

5 years ago

Depends on: 1510940

Comment hidden (Intermittent Failures Robot)

3 failures in 1862 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 2
* autoland: 1

Platform breakdown:
* linux64: 3

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

Comment hidden (Intermittent Failures Robot)

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

Repository breakdown:
* autoland: 1
* mozilla-inbound: 1

Platform breakdown:
* linux64: 2

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

Comment hidden (Intermittent Failures Robot)

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

Repository breakdown:
* mozilla-central: 3
* mozilla-beta: 1
* mozilla-inbound: 3
* autoland: 6

Platform breakdown:
* linux64: 9
* linux32: 4

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

Comment hidden (Intermittent Failures Robot)

6 failures in 1008 pushes (0.006 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 2
* autoland: 4

Platform breakdown:
* linux64: 4
* linux32: 2

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

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

Assignee

Updated

•

5 years ago

Updated

•

5 years ago

Depends on: 1517414

Comment hidden (Intermittent Failures Robot)

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

Repository breakdown:
* try: 1
* mozilla-inbound: 8
* autoland: 2
* mozilla-central: 2

Platform breakdown:
* linux32: 3
* linux64: 8
* linux32-nightly: 1
* linux64-devedition: 1

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

Comment hidden (Intermittent Failures Robot)

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

Assignee

Comment 14

•

5 years ago

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: 5 years ago

status-firefox65: affected → fixed

status-firefox66: --- → fixed

Resolution: --- → FIXED

Target Milestone: --- → mozilla66

BMO Automation

Updated

•

1 year ago

Product: Testing → Remote Protocol

BMO Automation

Comment 15

•

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_set_position_and_size | AssertionError: 0 != 10

Categories

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

Tracking

(firefox64 unaffected, firefox65 fixed, firefox66 fixed)

People

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

References

(Depends on 1 open bug)

Details

(Keywords: intermittent-failure)

Crash Data

Security

(public)

User Story

Description

Comment 1

Comment 2

Comment 3

Comment 4

Comment 5

Comment 6

Updated

Comment 7

Comment 8

Comment 9

Comment 10

Updated

Updated

Comment 11

Comment 12

Comment 13

Comment 14

Updated

Comment 15