Closed Bug 1421878 Opened 7 years ago Closed 7 years ago

Intermittent /webdriver/tests/actions/mouse.py | mouse.py::test_click_element_center

Categories

(Remote Protocol :: Marionette, defect, P5)

Product:
Remote Protocol
Component:
Marionette
Version:
Version 3
Platform:
All
Linux
Type:
defect

Tracking

(firefox59 fixed, firefox60 fixed)

Status:
RESOLVED FIXED
Milestone:
mozilla60
Tracking Flags:
Tracking Status
firefox59 --- fixed
firefox60 --- fixed

People

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

References

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell unknown])

Attachments

(1 file)

Bug 1421878 - Reset Marionette's click state on document unload;
59 bytes, text/x-review-board-request
whimboo
: review+
Details
[task 2017-11-29T21:07:18.140Z] 21:07:18 INFO - TEST-UNEXPECTED-FAIL | /webdriver/tests/actions/mouse.py | mouse.py::test_click_element_center [task 2017-11-29T21:07:18.140Z] 21:07:18 INFO - session = <webdriver.client.Session object at 0x7f7e4bd73550> [task 2017-11-29T21:07:18.141Z] 21:07:18 INFO - test_actions_page = None [task 2017-11-29T21:07:18.141Z] 21:07:18 INFO - mouse_chain = <webdriver.client.ActionSequence object at 0x7f7e4bd73a50> [task 2017-11-29T21:07:18.141Z] 21:07:18 INFO - [task 2017-11-29T21:07:18.141Z] 21:07:18 INFO - def test_click_element_center(session, test_actions_page, mouse_chain): [task 2017-11-29T21:07:18.142Z] 21:07:18 INFO - outer = session.find.css("#outer", all=False) [task 2017-11-29T21:07:18.142Z] 21:07:18 INFO - center = get_center(outer.rect) [task 2017-11-29T21:07:18.142Z] 21:07:18 INFO - mouse_chain.click(element=outer).perform() [task 2017-11-29T21:07:18.142Z] 21:07:18 INFO - events = get_events(session) [task 2017-11-29T21:07:18.142Z] 21:07:18 INFO - > assert len(events) == 4 [task 2017-11-29T21:07:18.143Z] 21:07:18 INFO - E assert 5 == 4 [task 2017-11-29T21:07:18.143Z] 21:07:18 INFO - E + where 5 = len([{'altKey': False, 'button': 0, 'buttons': 0, 'ctrlKey': False, ...}, {'altKey': False, 'button': 0, 'buttons': 1, 'ct...'button': 0, 'buttons': 0, 'ctrlKey': False, ...}, {'altKey': False, 'button': 0, 'buttons': 0, 'ctrlKey': False, ...}]) [task 2017-11-29T21:07:18.143Z] 21:07:18 INFO - [task 2017-11-29T21:07:18.143Z] 21:07:18 INFO - center = {'x': 58.0, 'y': 190.6666717529297} [task 2017-11-29T21:07:18.144Z] 21:07:18 INFO - events = [{'altKey': False, 'button': 0, 'buttons': 0, 'ctrlKey': False, ...}, {'altKey': False, 'button': 0, 'buttons': 1, 'ct...'button': 0, 'buttons': 0, 'ctrlKey': False, ...}, {'altKey': False, 'button': 0, 'buttons': 0, 'ctrlKey': False, ...}] [task 2017-11-29T21:07:18.144Z] 21:07:18 INFO - mouse_chain = <webdriver.client.ActionSequence object at 0x7f7e4bd73a50> [task 2017-11-29T21:07:18.144Z] 21:07:18 INFO - outer = <webdriver.client.Element object at 0x7f7e4bd73590> [task 2017-11-29T21:07:18.144Z] 21:07:18 INFO - session = <webdriver.client.Session object at 0x7f7e4bd73550> [task 2017-11-29T21:07:18.144Z] 21:07:18 INFO - test_actions_page = None Maja, is that related to any of the latest mouse changes to actions?
Flags: needinfo?(mjzffr)
I suspect that the extra event is a dblclick, which can happen if two consecutive tests click in quick succession -- as a result of Bug 1385476 just landing. The solution is to start a new session for each test, but that can also introduce intermittents (since the session sometimes doesn't start). Let's see how often this click failure happens.
Flags: needinfo?(mjzffr)
There have been 34 failures in the last 7 days. The most failures are occurring on the Linux platform, but there also some occurring on Linux x64 and linux64-ccov. The most affected build type is debug with 28 failures. There are also 6 failure occurring on opt. Here is a recent log: https://treeherder.mozilla.org/logviewer.html#?repo=autoland&job_id=150898573&lineNumber=2239 And a relevant snippet from it: [task 2017-12-08T21:39:08.984Z] 21:39:08 INFO - TEST-PASS | /webdriver/tests/actions/mouse.py | mouse.py::test_click_at_coordinates 2238 [task 2017-12-08T21:39:08.984Z] 21:39:08 INFO - TEST-PASS | /webdriver/tests/actions/mouse.py | mouse.py::test_context_menu_at_coordinates 2239 [task 2017-12-08T21:39:08.985Z] 21:39:08 INFO - TEST-UNEXPECTED-FAIL | /webdriver/tests/actions/mouse.py | mouse.py::test_click_element_center 2240 [task 2017-12-08T21:39:08.985Z] 21:39:08 INFO - session = <webdriver.client.Session object at 0x7fbe14cf49d0> 2241 [task 2017-12-08T21:39:08.986Z] 21:39:08 INFO - test_actions_page = None 2242 [task 2017-12-08T21:39:08.986Z] 21:39:08 INFO - mouse_chain = <webdriver.client.ActionSequence object at 0x7fbe14cf4c90> 2243 [task 2017-12-08T21:39:08.987Z] 21:39:08 INFO - 2244 [task 2017-12-08T21:39:08.987Z] 21:39:08 INFO - def test_click_element_center(session, test_actions_page, mouse_chain): 2245 [task 2017-12-08T21:39:08.988Z] 21:39:08 INFO - outer = session.find.css("#outer", all=False) 2246 [task 2017-12-08T21:39:08.988Z] 21:39:08 INFO - center = get_center(outer.rect) 2247 [task 2017-12-08T21:39:08.989Z] 21:39:08 INFO - mouse_chain.click(element=outer).perform() 2248 [task 2017-12-08T21:39:08.989Z] 21:39:08 INFO - events = get_events(session) 2249 [task 2017-12-08T21:39:08.989Z] 21:39:08 INFO - > assert len(events) == 4 2250 [task 2017-12-08T21:39:08.989Z] 21:39:08 INFO - E assert 5 == 4 2251 [task 2017-12-08T21:39:08.990Z] 21:39:08 INFO - E + where 5 = len([{'altKey': False, 'button': 0, 'buttons': 0, 'ctrlKey': False, ...}, {'altKey': False, 'button': 0, 'buttons': 1, 'ct...'button': 0, 'buttons': 0, 'ctrlKey': False, ...}, {'altKey': False, 'button': 0, 'buttons': 0, 'ctrlKey': False, ...}]) 2252 [task 2017-12-08T21:39:08.990Z] 21:39:08 INFO - 2253 [task 2017-12-08T21:39:08.990Z] 21:39:08 INFO - center = {'x': 58.0, 'y': 190.6666717529297} 2254 [task 2017-12-08T21:39:08.991Z] 21:39:08 INFO - events = [{'altKey': False, 'button': 0, 'buttons': 0, 'ctrlKey': False, ...}, {'altKey': False, 'button': 0, 'buttons': 1, 'ct...'button': 0, 'buttons': 0, 'ctrlKey': False, ...}, {'altKey': False, 'button': 0, 'buttons': 0, 'ctrlKey': False, ...}] 2255 [task 2017-12-08T21:39:08.991Z] 21:39:08 INFO - mouse_chain = <webdriver.client.ActionSequence object at 0x7fbe14cf4c90> 2256 [task 2017-12-08T21:39:08.991Z] 21:39:08 INFO - outer = <webdriver.client.Element object at 0x7fbe14cf4990> 2257 [task 2017-12-08T21:39:08.992Z] 21:39:08 INFO - session = <webdriver.client.Session object at 0x7fbe14cf49d0> 2258 [task 2017-12-08T21:39:08.992Z] 21:39:08 INFO - test_actions_page = None 2259 [task 2017-12-08T21:39:08.992Z] 21:39:08 INFO - 2260 [task 2017-12-08T21:39:08.993Z] 21:39:08 INFO - tests/web-platform/tests/webdriver/tests/actions/mouse.py:73: AssertionError
Flags: needinfo?(hskupin)
Whiteboard: [stockwell needswork]
There have been 33 failures in the last 7 days. For failure pattern, please see Comment 4 A recent log: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-central&job_id=152611829&lineNumber=2503
Whiteboard: [stockwell unknown] → [stockwell needswork]
Maja this test fails a lot. Would you have the time to check what we can do here?
Flags: needinfo?(hskupin) → needinfo?(mjzffr)
OS: Unspecified → Linux
Hardware: Unspecified → All
I'll take a look this week. Leaving the n-i on so I don't forget.
Whiteboard: [stockwell unknown] → [stockwell needswork]
Flags: needinfo?(mjzffr)
Assignee: nobody → mjzffr
Comment on attachment 8942387 [details] Bug 1421878 - Reset Marionette's click state on document unload; https://reviewboard.mozilla.org/r/212672/#review218532 This patch mixes up two different issues. Lets really only focus on the extra pause on this bug. ::: commit-message-ac93f:15 (Diff revision 1) > +independent, let's add a pause after tests that involve a click. > + > +If this works well for fixing the intermittent we're seeing, I > +could also use this pause for dblclick and modifier-click tests > +as an alternative to starting a new session between each test. > + Great. But also lets make sure we continue on what we discussed last week. Finishing an action chain it might make sense to reset this flag - which would most likely need a discussion in a WebDriver spec issue.
Attachment #8942387 - Flags: review?(hskupin) → review-
Comment on attachment 8942387 [details] Bug 1421878 - Reset Marionette's click state on document unload; https://reviewboard.mozilla.org/r/212672/#review218532 Sorry, Henrik, I don't understand. What else is this patch doing, besides adding a pause, in your view? What is being mixed up? > Great. But also lets make sure we continue on what we discussed last week. Finishing an action chain it might make sense to reset this flag - which would most likely need a discussion in a WebDriver spec issue. I filed https://github.com/w3c/webdriver/issues/1197 but I don't think that should delay us from landing this tentative fix.
Comment on attachment 8942387 [details] Bug 1421878 - Reset Marionette's click state on document unload; https://reviewboard.mozilla.org/r/212672/#review218532 I was referring to the changes for the approx helper, and the move of the drag and drop test, which doesn't seem to belong here. > I filed https://github.com/w3c/webdriver/issues/1197 but I don't think that should delay us from landing this tentative fix. No it doesnt. I just don't want that we forget about it.
Comment on attachment 8942387 [details] Bug 1421878 - Reset Marionette's click state on document unload; https://reviewboard.mozilla.org/r/212672/#review218532 I need to move the drag and drop because it will hit a timeout with the new pauses otherwise. I need to move the approx helper so that I can be shared across both test files.
I see. So I talked with Andreas in our chit chat today about this issue, and he mentioned to me that this might not happen if a different input device would be used by each test. In such a case we should not retain the state from a former click. Also we won't need a sleep at all. Would you mind to check that?
(In reply to Henrik Skupin (:whimboo) from comment #23) > I see. So I talked with Andreas in our chit chat today about this issue, and > he mentioned to me that this might not happen if a different input device > would be used by each test. In such a case we should not retain the state > from a former click. Also we won't need a sleep at all. > > Would you mind to check that? I got a better idea from https://bugzilla.mozilla.org/show_bug.cgi?id=1430851#c2 -- reset the click timer on document unload. Regarding using different input devices, I don't think it would be correct to use that to avoid "extra dblclicks". For example, I looked at the events emitted by Firefox (outside of automation, i.e. real life) by clicking with my track pad and my mouse in quick succession: Firefox still sees that as a dblclick even though the individual clicks were triggered by different devices.
Comment on attachment 8942387 [details] Bug 1421878 - Reset Marionette's click state on document unload; https://reviewboard.mozilla.org/r/212672/#review219854 Removing review request to wait for the new idea. :) It sounds better, yes.
Attachment #8942387 - Flags: review?(hskupin)
Comment on attachment 8942387 [details] Bug 1421878 - Reset Marionette's click state on document unload; https://reviewboard.mozilla.org/r/212672/#review220160 Yes, that looks way better! If that works we can even remove the restarts, without having to add sleeps or whatever else.
Attachment #8942387 - Flags: review?(hskupin) → review+
Pushed by hskupin@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/87986a428a98 Reset Marionette's click state on document unload; r=whimboo
https://hg.mozilla.org/mozilla-central/rev/87986a428a98
Status: NEW → RESOLVED
Closed: 7 years ago
status-firefox60: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla60
Blocks: 1432773
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.

Attachment

General

Creator:
Created:
Updated:
Size: