Closed Bug 1506095 Opened 6 years ago Closed 5 years ago

Intermittent /webdriver/tests/set_window_rect/set.py | test_x_y - AssertionError: assert {'height': 60...: 50, 'y': 50} == {'height': 600...: 60, 'y': 60}

Categories

(Remote Protocol :: Marionette, defect, P5)

Version 3
defect

Tracking

(firefox65 fixed, firefox66 fixed)

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

People

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

References

(Depends on 1 open bug)

Details

(Keywords: intermittent-failure)

Filed by: ebalazs [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=210778165&repo=mozilla-central

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

TEST-PASS | /webdriver/tests/set_window_rect/set.py | test_height_width_as_current 
[task 2018-11-09T11:16:38.537Z] 11:16:38     INFO - TEST-UNEXPECTED-FAIL | /webdriver/tests/set_window_rect/set.py | test_x_y - AssertionError: assert {'height': 60...: 50, 'y': 50} == {'height': 600...: 60, 'y': 60}
[task 2018-11-09T11:16:38.537Z] 11:16:38     INFO - session = <Session 842506c9-ee1d-44e5-a5cb-b945d02787b0>
[task 2018-11-09T11:16:38.537Z] 11:16:38     INFO - 
[task 2018-11-09T11:16:38.538Z] 11:16:38     INFO -     def test_x_y(session):
[task 2018-11-09T11:16:38.538Z] 11:16:38     INFO -         original = session.window.rect
[task 2018-11-09T11:16:38.538Z] 11:16:38     INFO -         response = set_window_rect(session, {
[task 2018-11-09T11:16:38.539Z] 11:16:38     INFO -             "x": original["x"] + 10,
[task 2018-11-09T11:16:38.539Z] 11:16:38     INFO -             "y": original["y"] + 10
[task 2018-11-09T11:16:38.539Z] 11:16:38     INFO -         })
[task 2018-11-09T11:16:38.539Z] 11:16:38     INFO -         assert_success(response, {
[task 2018-11-09T11:16:38.539Z] 11:16:38     INFO -             "x": original["x"] + 10,
[task 2018-11-09T11:16:38.540Z] 11:16:38     INFO -             "y": original["y"] + 10,
[task 2018-11-09T11:16:38.541Z] 11:16:38     INFO -             "width": original["width"],
[task 2018-11-09T11:16:38.541Z] 11:16:38     INFO - >           "height": original["height"]
[task 2018-11-09T11:16:38.541Z] 11:16:38     INFO -         })
[task 2018-11-09T11:16:38.541Z] 11:16:38     INFO - 
[task 2018-11-09T11:16:38.542Z] 11:16:38     INFO - original   = {'height': 600, 'width': 800, 'x': 50, 'y': 50}
[task 2018-11-09T11:16:38.542Z] 11:16:38     INFO - response   = <Responsetatus=200 body={"value": {"y": 50, "x": 50, "height": 600, "width": 800}}>
[task 2018-11-09T11:16:38.542Z] 11:16:38     INFO - session    = <Session 842506c9-ee1d-44e5-a5cb-b945d02787b0>
[task 2018-11-09T11:16:38.542Z] 11:16:38     INFO - 
[task 2018-11-09T11:16:38.543Z] 11:16:38     INFO - tests/web-platform/tests/webdriver/tests/set_window_rect/set.py:228: 
[task 2018-11-09T11:16:38.543Z] 11:16:38     INFO - _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
[task 2018-11-09T11:16:38.544Z] 11:16:38     INFO - 
[task 2018-11-09T11:16:38.544Z] 11:16:38     INFO - response = <Responsetatus=200 body={"value": {"y": 50, "x": 50, "height": 600, "width": 800}}>
[task 2018-11-09T11:16:38.544Z] 11:16:38     INFO - value = {'height': 600, 'width': 800, 'x': 60, 'y': 60}
[task 2018-11-09T11:16:38.544Z] 11:16:38     INFO - 
[task 2018-11-09T11:16:38.544Z] 11:16:38     INFO -     def assert_success(response, value=None):
[task 2018-11-09T11:16:38.544Z] 11:16:38     INFO -         """
[task 2018-11-09T11:16:38.544Z] 11:16:38     INFO -         Verify that the provided webdriver.Response instance described
[task 2018-11-09T11:16:38.544Z] 11:16:38     INFO -         a valid error response as defined by `dfn-send-an-error` and
[task 2018-11-09T11:16:38.544Z] 11:16:38     INFO -         the provided error code.
[task 2018-11-09T11:16:38.544Z] 11:16:38     INFO -     
[task 2018-11-09T11:16:38.545Z] 11:16:38     INFO -         :param response: ``webdriver.Response`` instance.
[task 2018-11-09T11:16:38.545Z] 11:16:38     INFO -         :param value: Expected value of the response body, if any.
[task 2018-11-09T11:16:38.545Z] 11:16:38     INFO -         """
[task 2018-11-09T11:16:38.545Z] 11:16:38     INFO -         assert response.status == 200, str(response.error)
[task 2018-11-09T11:16:38.545Z] 11:16:38     INFO -     
[task 2018-11-09T11:16:38.545Z] 11:16:38     INFO -         if value is not None:
[task 2018-11-09T11:16:38.545Z] 11:16:38     INFO - >           assert response.body["value"] == value
[task 2018-11-09T11:16:38.546Z] 11:16:38     INFO - E           AssertionError: assert {'height': 60...: 50, 'y': 50} == {'height': 600...: 60, 'y': 60}
[task 2018-11-09T11:16:38.546Z] 11:16:38     INFO - E             Common items:
[task 2018-11-09T11:16:38.548Z] 11:16:38     INFO - E             {'height': 600, 'width': 800}
[task 2018-11-09T11:16:38.550Z] 11:16:38     INFO - E             Differing items:
[task 2018-11-09T11:16:38.554Z] 11:16:38     INFO - E             {'y': 50} != {'y': 60}
[task 2018-11-09T11:16:38.554Z] 11:16:38     INFO - E             {'x': 50} != {'x': 60}
[task 2018-11-09T11:16:38.554Z] 11:16:38     INFO - E             Full diff:
[task 2018-11-09T11:16:38.554Z] 11:16:38     INFO - E             - {u'height': 600, u'width': 800, u'x': 50, u'y': 50}
[task 2018-11-09T11:16:38.555Z] 11:16:38     INFO - E             ?  -               -              -     ^   -     ^
[task 2018-11-09T11:16:38.555Z] 11:16:38     INFO - E             + {'height': 600, 'width': 800, 'x': 60, 'y': 60}
[task 2018-11-09T11:16:38.555Z] 11:16:38     INFO - E             ?                                    ^        ^
[task 2018-11-09T11:16:38.555Z] 11:16:38     INFO - 
[task 2018-11-09T11:16:38.556Z] 11:16:38     INFO - response   = <Responsetatus=200 body={"value": {"y": 50, "x": 50, "height": 600, "width": 800}}>
[task 2018-11-09T11:16:38.556Z] 11:16:38     INFO - value      = {'height': 600, 'width': 800, 'x': 60, 'y': 60}
[task 2018-11-09T11:16:38.556Z] 11:16:38     INFO - 
[task 2018-11-09T11:16:38.557Z] 11:16:38     INFO - tests/web-platform/tests/webdriver/tests/support/asserts.py:69: AssertionError
[task 2018-11-09T11:16:38.557Z] 11:16:38     INFO - ........
[task 2018-11-09T11:16:38.558Z] 11:16:38     INFO - TEST-OK | /webdriver/tests/set_window_rect/set.py | took 32780ms
[task 2018-11-09T11:16:38.579Z] 11:16:38     INFO - Closing logging queue
[task 2018-11-09T11:16:38.580Z] 11:16:38     INFO - queue closed
[task 2018-11-09T11:16:38.582Z] 11:16:38     INFO - Starting runner
[task 2018-11-09T11:16:38.614Z] 11:16:38     INFO - PID 24819 | 1541762198608	webdriver::httpapi	DEBUG	Creating routes
[task 2018-11-09T11:16:38.623Z] 11:16:38     INFO - PID 24819 | 1541762198614	geckodriver	DEBUG	Listening on 127.0.0.1:4444
[task 2018-11-09T11:16:39.111Z] 11:16:39     INFO - WebDriver HTTP server listening at http://127.0.0.1:4444/
Looks like the command returned before the window got resized at all. Maybe our debounce callback method should expect at least a single `resize` event before it returns?

Andreas, can you please take a look at this bug?
Depends on: 1492499
Flags: needinfo?(ato)
(In reply to Henrik Skupin (:whimboo) from comment #1)
> Looks like the command returned before the window got resized at all. Maybe
> our debounce callback method should expect at least a single `resize` event
> before it returns?

DebounceCallback does not resolve before there has been at least one resize event:
https://searchfox.org/mozilla-central/rev/7f7c353e969e61a6a85201cc8ad3c3de12ac30d8/testing/marionette/sync.js#345

It is likely an outer TimedPromise that is causing the resolve.
Flags: needinfo?(ato)
I wonder if we should add some debug or trace log entries for entering/leaving special window states like fullscreen, minimized, and maximized.
It's all about moving the window. So some more logging of the window events might help which gets done through bug 1510940.
Depends on: 1510940
See Also: → 1516975
Depends on: 1517414

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
Depends on: 1478358
Resolution: --- → FIXED
Target Milestone: --- → mozilla66
Moving bug to Remote Protocol::Marionette component per bug 1815831.
Component: geckodriver → Marionette
Product: Testing → Remote Protocol
You need to log in before you can comment on or make changes to this bug.