Closed Bug 1529649 Opened 5 years ago Closed 5 years ago

Intermittent TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/perform_actions/pointer_pause_dblclick.py | expected OK

Categories

(Remote Protocol :: Marionette, defect, P5)

Product:
Remote Protocol
Component:
Marionette
Version:
Version 3
Type:
defect

Tracking

(firefox-esr60 unaffected, firefox65 unaffected, firefox66 unaffected, firefox67 fixed)

Status:
RESOLVED FIXED
Milestone:
mozilla67
Tracking Flags:
Tracking Status
firefox-esr60 --- unaffected
firefox65 --- unaffected
firefox66 --- unaffected
firefox67 --- fixed

People

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

References

Details

(Keywords: intermittent-failure, regression, Whiteboard: [stockwell needswork:owner])

#[markdown(off)]
Filed by: cbrindusan [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=229679300&repo=autoland

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

[task 2019-02-21T17:09:52.569Z] 17:09:52 INFO - TEST-START | /webdriver/tests/perform_actions/pointer_pause_dblclick.py
[task 2019-02-21T17:09:52.605Z] 17:09:52 INFO - STDOUT: ============================= test session starts ==============================
[task 2019-02-21T17:09:52.606Z] 17:09:52 INFO - STDOUT: platform linux2 -- Python 2.7.12, pytest-unknown, py-1.5.2, pluggy-0.5.3.dev -- /builds/worker/workspace/build/venv/bin/python
[task 2019-02-21T17:09:52.607Z] 17:09:52 INFO - STDOUT: rootdir: /builds/worker/workspace/build, inifile:
[task 2019-02-21T17:09:52.607Z] 17:09:52 INFO - STDOUT: collecting ...
[task 2019-02-21T17:09:52.624Z] 17:09:52 INFO - STDOUT: collected 2 items
[task 2019-02-21T17:09:52.624Z] 17:09:52 INFO - STDOUT: tests/web-platform/tests/webdriver/tests/perform_actions/pointer_pause_dblclick.py::test_dblclick_with_pause_after_second_pointerdown
[task 2019-02-21T17:09:52.625Z] 17:09:52 INFO - PID 25389 | 1550768992617 webdriver::server DEBUG -> POST /session/590c644b-2883-46b6-9cab-8476ecf22367/window/rect {"width": 800, "height": 600}
[task 2019-02-21T17:09:52.625Z] 17:09:52 INFO - PID 25389 | 1550768992618 Marionette DEBUG 0 -> [0,3699,"WebDriver:SetWindowRect",{"height":600,"width":800}]
[task 2019-02-21T17:09:52.625Z] 17:09:52 INFO - PID 25389 | 1550768992621 Marionette DEBUG 0 <- [1,3699,null,{"x":100,"y":100,"width":800,"height":600}]
[task 2019-02-21T17:09:52.627Z] 17:09:52 INFO - PID 25389 | 1550768992621 webdriver::server DEBUG <- 200 OK {"value":{"x":100,"y":100,"width":800,"height":600}}
[task 2019-02-21T17:09:52.629Z] 17:09:52 INFO - PID 25389 | 1550768992623 webdriver::server DEBUG -> POST /session/590c644b-2883-46b6-9cab-8476ecf22367/window/rect {"y": 100, "x": 100}
[task 2019-02-21T17:09:52.630Z] 17:09:52 INFO - PID 25389 | 1550768992624 Marionette DEBUG 0 -> [0,3700,"WebDriver:SetWindowRect",{"x":100,"y":100}]
[task 2019-02-21T17:09:52.637Z] 17:09:52 INFO - PID 25389 | 1550768992630 Marionette DEBUG 0 <- [1,3700,null,{"x":100,"y":100,"width":800,"height":600}]
[task 2019-02-21T17:09:52.638Z] 17:09:52 INFO - PID 25389 | 1550768992630 webdriver::server DEBUG <- 200 OK {"value":{"x":100,"y":100,"width":800,"height":600}}
[task 2019-02-21T17:09:52.640Z] 17:09:52 INFO - PID 25389 | 1550768992632 webdriver::server DEBUG -> POST /session/590c644b-2883-46b6-9cab-8476ecf22367/url {"url": "http://web-platform.test:8000/webdriver/tests/perform_actions/support/test_actions_wdspec.html"}
[task 2019-02-21T17:09:52.641Z] 17:09:52 INFO - PID 25389 | 1550768992633 Marionette DEBUG 0 -> [0,3701,"WebDriver:Navigate",{"url":"http://web-platform.test:8000/webdriver/tests/perform_actions/support/test_actions_wdspec.html"}]
[task 2019-02-21T17:09:52.642Z] 17:09:52 INFO - PID 25389 | 1550768992636 Marionette TRACE [4294967297] Received DOM event beforeunload for http://web-platform.test:8000/webdriver/tests/support/inline.py?doc=%0A++++++%3Cdiv+id%3D%22outer%22+style%3D%22%22%0A+++++++ ... B+left%3A+-200px%3B+top%3A+-100px%3B%22%3E%3C%2Fdiv%3E%0A++++++%3C%2Fdiv%3E%0A++++&content-type=text%2Fhtml%3Bcharset%3Dutf-8
[task 2019-02-21T17:09:52.660Z] 17:09:52 INFO - PID 25389 | 1550768992646 Marionette TRACE [4294967297] Received DOM event pagehide for http://web-platform.test:8000/webdriver/tests/support/inline.py?doc=%0A++++++%3Cdiv+id%3D%22outer%22+style%3D%22%22%0A+++++++ ... B+left%3A+-200px%3B+top%3A+-100px%3B%22%3E%3C%2Fdiv%3E%0A++++++%3C%2Fdiv%3E%0A++++&content-type=text%2Fhtml%3Bcharset%3Dutf-8
[task 2019-02-21T17:09:52.661Z] 17:09:52 INFO - PID 25389 | 1550768992656 Marionette TRACE [4294967297] Received DOM event DOMContentLoaded for http://web-platform.test:8000/webdriver/tests/perform_actions/support/test_actions_wdspec.html
[task 2019-02-21T17:09:52.678Z] 17:09:52 INFO - PID 25389 | 1550768992665 Marionette TRACE [4294967297] Received DOM event pageshow for http://web-platform.test:8000/webdriver/tests/perform_actions/support/test_actions_wdspec.html
[task 2019-02-21T17:09:52.678Z] 17:09:52 INFO - PID 25389 | 1550768992666 Marionette DEBUG 0 <- [1,3701,null,{"value":null}]
[task 2019-02-21T17:09:52.679Z] 17:09:52 INFO - PID 25389 | 1550768992667 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2019-02-21T17:09:52.680Z] 17:09:52 INFO - PID 25389 | 1550768992670 webdriver::server DEBUG -> POST /session/590c644b-2883-46b6-9cab-8476ecf22367/element {"using": "css selector", "value": "#outer"}
[task 2019-02-21T17:09:52.681Z] 17:09:52 INFO - PID 25389 | 1550768992674 Marionette DEBUG 0 -> [0,3702,"WebDriver:FindElement",{"using":"css selector","value":"#outer"}]
[task 2019-02-21T17:09:52.682Z] 17:09:52 INFO - PID 25389 | 1550768992677 Marionette DEBUG 0 <- [1,3702,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"4f52dbb2-be79-4465-98c0-9b0338f51e2c"}}]
[task 2019-02-21T17:09:52.683Z] 17:09:52 INFO - PID 25389 | 1550768992677 webdriver::server DEBUG <- 200 OK {"value":{"element-6066-11e4-a52e-4f735466cecf":"4f52dbb2-be79-4465-98c0-9b0338f51e2c"}}
[task 2019-02-21T17:09:52.685Z] 17:09:52 INFO - PID 25389 | 1550768992679 webdriver::server DEBUG -> GET /session/590c644b-2883-46b6-9cab-8476ecf22367/element/4f52dbb2-be79-4465-98c0-9b0338f51e2c/rect
[task 2019-02-21T17:09:52.686Z] 17:09:52 INFO - PID 25389 | 1550768992680 Marionette DEBUG 0 -> [0,3703,"WebDriver:GetElementRect",{"id":"4f52dbb2-be79-4465-98c0-9b0338f51e2c"}]
[task 2019-02-21T17:09:52.690Z] 17:09:52 INFO - PID 25389 | 1550768992684 Marionette DEBUG 0 <- [1,3703,null,{"x":8,"y":165.6666717529297,"width":100,"height":50}]
[task 2019-02-21T17:09:52.691Z] 17:09:52 INFO - PID 25389 | 1550768992684 webdriver::server DEBUG <- 200 OK {"value":{"x":8.0,"y":165.6666717529297,"width":100.0,"height":50.0}}
[task 2019-02-21T17:09:52.693Z] 17:09:52 INFO - PID 25389 | 1550768992687 webdriver::server DEBUG -> POST /session/590c644b-2883-46b6-9cab-8476ecf22367/execute/sync {"args": [], "script": "\n return {\n height: window.innerHeight || document.documentElement.clientHeight,\n width: window.innerWidth || document.documentElement.clientWidth,\n };\n "}
[task 2019-02-21T17:09:52.694Z] 17:09:52 INFO - PID 25389 | 1550768992689 Marionette DEBUG 0 -> [0,3704,"WebDriver:ExecuteScript",{"args":[],"script":"\n return {\n height: window.innerHeight || document.d ... cumentElement.clientHeight,\n width: window.innerWidth || document.documentElement.clientWidth,\n };\n "}]
[task 2019-02-21T17:09:52.696Z] 17:09:52 INFO - PID 25389 | 1550768992692 Marionette DEBUG 0 <- [1,3704,null,{"value":{"height":526,"width":800}}]
[task 2019-02-21T17:09:52.696Z] 17:09:52 INFO - PID 25389 | 1550768992692 webdriver::server DEBUG <- 200 OK {"value":{"height":526,"width":800}}
[task 2019-02-21T17:09:52.700Z] 17:09:52 INFO - PID 25389 | 1550768992695 webdriver::server DEBUG -> POST /session/590c644b-2883-46b6-9cab-8476ecf22367/actions {"actions": [{"parameters": {"pointerType": "mouse"}, "type": "pointer", "id": "pointer_id", "actions": [{"y": 190, "x": 58, "type": "pointerMove"}, {"button": 0, "type": "pointerDown"}, {"button": 0, "type": "pointerUp"}, {"button": 0, "type": "pointerDown"}, {"duration": 650, "type": "pause"}, {"button": 0, "type": "pointerUp"}]}]}
[task 2019-02-21T17:09:52.700Z] 17:09:52 INFO - PID 25389 | 1550768992696 Marionette DEBUG 0 -> [0,3705,"WebDriver:PerformActions",{"actions":[{"actions":[{"origin":"viewport","type":"pointerMove","x":58,"y":190},{"button ... ,"type":"pause"},{"button":0,"type":"pointerUp"}],"id":"pointer_id","parameters":{"pointerType":"mouse"},"type":"pointer"}]}]
[task 2019-02-21T17:10:22.570Z] 17:10:22 INFO - TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/perform_actions/pointer_pause_dblclick.py | expected OK

I wonder if that is a side effect from my patch on bug 1529516 which modified Sleep() to use a normal Promise and not TimedPromise anymore. And that would mean that the used timer instance never fires.

Whiteboard: [stockwell needswork:owner]

Fixed with the backout of my patch on bug 1529516.

Assignee: nobody → hskupin
Status: NEW → RESOLVED
Closed: 5 years ago
status-firefox67: affected → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla67
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.