Closed Bug 1542250 Opened 6 years ago Closed 5 years ago

Intermittent TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/maximize_window/maximize.py | expected OK

Categories

(Remote Protocol :: Marionette, defect, P5)

Version 3
defect

Tracking

(Not tracked)

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure, regression)

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

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

https://queue.taskcluster.net/v1/task/UFcmPK-8R9G7VgO9rufqmA/runs/0/artifacts/public/logs/live_backing.log

[task 2019-04-05T12:42:53.441Z] 12:42:53 INFO - TEST-START | /webdriver/tests/maximize_window/maximize.py
[task 2019-04-05T12:42:53.679Z] 12:42:53 INFO - STDOUT: ============================= test session starts ==============================
[task 2019-04-05T12:42:53.680Z] 12:42:53 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-04-05T12:42:53.681Z] 12:42:53 INFO - STDOUT: rootdir: /builds/worker/workspace/build, inifile:
[task 2019-04-05T12:42:53.681Z] 12:42:53 INFO - STDOUT: collecting ...
[task 2019-04-05T12:42:53.758Z] 12:42:53 INFO - STDOUT: collected 7 items
[task 2019-04-05T12:42:53.760Z] 12:42:53 INFO - STDOUT: tests/web-platform/tests/webdriver/tests/maximize_window/maximize.py::test_no_browsing_context
[task 2019-04-05T12:42:53.763Z] 12:42:53 INFO - PID 23150 | 1554468173755 webdriver::server DEBUG -> POST /session {"capabilities": {"alwaysMatch": {"moz:firefoxOptions": {"binary": "/builds/worker/workspace/build/application/firefox/firefox", "prefs": {"network.dns.localDomains": "www1.xn--n8j6ds53lwwkrqhv28a.web-platform.test,xn--lve-6lad.www1.web-platform.test,www.www2.not-web-platform.test,www2.www2.not-web-platform.test,xn--lve-6lad.www.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,www.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.www.not-web-platform.test,not-web-platform.test,www1.www.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.www1.web-platform.test,www2.not-web-platform.test,www1.not-web-platform.test,www1.www1.web-platform.test,www2.xn--lve-6lad.web-platform.test,www1.xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.xn--n8j6ds53lwwkrqhv28a.web-platform.test,www1.www2.web-platform.test,xn--lve-6lad.xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,xn--lve-6lad.xn--lve-6lad.not-web-platform.test,www2.www1.not-web-platform.test,www2.xn--n8j6ds53lwwkrqhv28a.web-platform.test,www.xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,web-platform.test,xn--n8j6ds53lwwkrqhv28a.xn--lve-6lad.not-web-platform.test,xn--lve-6lad.www.web-platform.test,www.www.web-platform.test,www1.xn--lve-6lad.web-platform.test,xn--lve-6lad.www2.web-platform.test,www.www2.web-platform.test,www2.www.web-platform.test,xn--n8j6ds53lwwkrqhv28a.www2.not-web-platform.test,www1.www.web-platform.test,www.xn--lve-6lad.web-platform.test,www.www.not-web-platform.test,xn--lve-6lad.xn--lve-6lad.web-platform.test,xn--lve-6lad.www1.not-web-platform.test,www1.www1.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.www2.web-platform.test,xn--n8j6ds53lwwkrqhv28a.www1.not-web-platform.test,www2.www2.web-platform.test,xn--lve-6lad.web-platform.test,xn--n8j6ds53lwwkrqhv28a.web-platform.test,xn--n8j6ds53lwwkrqhv28a.www.web-platform.test,xn--lve-6lad.not-web-platform.test,www2.xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,www2.xn--lve-6lad.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.xn--lve-6lad.web-platform.test,www1.xn--lve-6lad.not-web-platform.test,www1.web-platform.test,www.www1.web-platform.test,www2.web-platform.test,www.xn--lve-6lad.not-web-platform.test,www.web-platform.test,xn--lve-6lad.xn--n8j6ds53lwwkrqhv28a.web-platform.test,www1.www2.not-web-platform.test,www2.www1.web-platform.test,www.www1.not-web-platform.test,www.xn--n8j6ds53lwwkrqhv28a.web-platform.test,xn--lve-6lad.www2.not-web-platform.test,www2.www.not-web-platform.test"}}}}}
[task 2019-04-05T12:42:53.764Z] 12:42:53 INFO - PID 23150 | 1554468173757 mozrunner::runner INFO Running command: "/builds/worker/workspace/build/application/firefox/firefox" "-marionette" "-foreground" "-no-remote" "-profile" "/tmp/rust_mozprofile.jMvtYuryje17"
[task 2019-04-05T12:42:53.765Z] 12:42:53 INFO - PID 23150 | 1554468173757 geckodriver::marionette DEBUG Waiting 60s to connect to browser on 127.0.0.1:2828
[task 2019-04-05T12:42:54.347Z] 12:42:54 INFO - PID 23150 | 1554468174344 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: mozillaAddons
[task 2019-04-05T12:42:54.349Z] 12:42:54 INFO - PID 23150 | 1554468174345 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: resource://pdf.js/
[task 2019-04-05T12:42:54.349Z] 12:42:54 INFO - PID 23150 | 1554468174345 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: about:reader*
[task 2019-04-05T12:42:54.532Z] 12:42:54 INFO - PID 23150 | 1554468174524 Marionette TRACE Received observer notification profile-after-change
[task 2019-04-05T12:42:54.594Z] 12:42:54 INFO - PID 23150 | 1554468174591 Marionette TRACE Received observer notification command-line-startup
[task 2019-04-05T12:42:54.595Z] 12:42:54 INFO - PID 23150 | 1554468174591 Marionette TRACE Received observer notification nsPref:changed
[task 2019-04-05T12:42:54.596Z] 12:42:54 INFO - PID 23150 | 1554468174592 Marionette DEBUG Init aborted (running=false, enabled=true, finalUIStartup=false)
[task 2019-04-05T12:42:55.008Z] 12:42:55 INFO - PID 23150 | 1554468175003 Marionette TRACE Received observer notification toplevel-window-ready
[task 2019-04-05T12:42:55.643Z] 12:42:55 INFO - PID 23150 | JavaScript warning: chrome://global/content/bindings/tabbox.xml, line 162: Array.forEach is deprecated; use Array.prototype.forEach instead
[task 2019-04-05T12:42:56.964Z] 12:42:56 INFO - PID 23150 | JavaScript warning: chrome://browser/content/tabbrowser.js, line 4834: Array.unshift is deprecated; use Array.prototype.unshift instead
[task 2019-04-05T12:42:57.183Z] 12:42:57 INFO - PID 23150 | JavaScript warning: chrome://browser/content/tabbrowser.js, line 239: Array.filter is deprecated; use Array.prototype.filter instead
...
[task 2019-04-05T12:43:23.385Z] 12:43:23 INFO - PID 23150 | 1554468203378 webdriver::server DEBUG <- 200 OK {"value":{"x":0,"y":0,"width":1600,"height":1200}}
[task 2019-04-05T12:43:23.386Z] 12:43:23 INFO - PID 23150 | 1554468203379 webdriver::server DEBUG -> GET /session/bebf61d0-7179-4f2d-a0da-6866cadef420/window/rect
[task 2019-04-05T12:43:23.387Z] 12:43:23 INFO - PID 23150 | 1554468203380 Marionette DEBUG 0 -> [0,5,"WebDriver:GetWindowRect",{}]
[task 2019-04-05T12:43:23.388Z] 12:43:23 INFO - PID 23150 | 1554468203383 Marionette DEBUG 0 <- [1,5,null,{"x":0,"y":0,"width":1600,"height":1200}]
[task 2019-04-05T12:43:23.389Z] 12:43:23 INFO - STDOUT: PASSED
[task 2019-04-05T12:43:23.389Z] 12:43:23 INFO - PID 23150 | 1554468203384 webdriver::server DEBUG <- 200 OK {"value":{"x":0,"y":0,"width":1600,"height":1200}}
[task 2019-04-05T12:43:23.391Z] 12:43:23 INFO - PID 23150 | 1554468203388 webdriver::server DEBUG -> POST /session/bebf61d0-7179-4f2d-a0da-6866cadef420/timeouts {"implicit": 0}
[task 2019-04-05T12:43:23.439Z] 12:43:23 INFO - PID 23150 | 1554468203391 Marionette DEBUG 0 -> [0,6,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2019-04-05T12:43:23.440Z] 12:43:23 INFO - PID 23150 | 1554468203392 Marionette DEBUG 0 <- [1,6,null,{"value":null}]
[task 2019-04-05T12:43:23.440Z] 12:43:23 INFO - PID 23150 | 1554468203392 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2019-04-05T12:43:23.440Z] 12:43:23 INFO - PID 23150 | 1554468203393 webdriver::server DEBUG -> POST /session/bebf61d0-7179-4f2d-a0da-6866cadef420/timeouts {"pageLoad": 300000}
[task 2019-04-05T12:43:23.441Z] 12:43:23 INFO - PID 23150 | 1554468203394 Marionette DEBUG 0 -> [0,7,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2019-04-05T12:43:23.447Z] 12:43:23 INFO - PID 23150 | 1554468203394 Marionette DEBUG 0 <- [1,7,null,{"value":null}]
[task 2019-04-05T12:43:23.447Z] 12:43:23 INFO - PID 23150 | 1554468203395 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2019-04-05T12:43:23.448Z] 12:43:23 INFO - PID 23150 | 1554468203396 webdriver::server DEBUG -> POST /session/bebf61d0-7179-4f2d-a0da-6866cadef420/timeouts {"script": 30000}
[task 2019-04-05T12:43:23.448Z] 12:43:23 INFO - PID 23150 | 1554468203396 Marionette DEBUG 0 -> [0,8,"WebDriver:SetTimeouts",{"script":30000}]
[task 2019-04-05T12:43:23.449Z] 12:43:23 INFO - PID 23150 | 1554468203397 Marionette DEBUG 0 <- [1,8,null,{"value":null}]
[task 2019-04-05T12:43:23.450Z] 12:43:23 INFO - PID 23150 | 1554468203398 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2019-04-05T12:43:23.451Z] 12:43:23 INFO - PID 23150 | 1554468203399 webdriver::server DEBUG -> GET /session/bebf61d0-7179-4f2d-a0da-6866cadef420/window
[task 2019-04-05T12:43:23.451Z] 12:43:23 INFO - PID 23150 | 1554468203399 Marionette DEBUG 0 -> [0,9,"WebDriver:GetWindowHandle",{}]
[task 2019-04-05T12:43:23.451Z] 12:43:23 INFO - PID 23150 | 1554468203400 Marionette DEBUG 0 <- [1,9,null,{"value":"4294967297"}]
[task 2019-04-05T12:43:23.451Z] 12:43:23 INFO - PID 23150 | 1554468203400 webdriver::server DEBUG <- 200 OK {"value":"4294967297"}
[task 2019-04-05T12:43:23.452Z] 12:43:23 INFO - PID 23150 | 1554468203401 webdriver::server DEBUG -> GET /session/bebf61d0-7179-4f2d-a0da-6866cadef420/window
[task 2019-04-05T12:43:23.452Z] 12:43:23 INFO - PID 23150 | 1554468203401 Marionette DEBUG 0 -> [0,10,"WebDriver:GetWindowHandle",{}]
[task 2019-04-05T12:43:23.458Z] 12:43:23 INFO - PID 23150 | 1554468203402 Marionette DEBUG 0 <- [1,10,null,{"value":"4294967297"}]
[task 2019-04-05T12:43:23.458Z] 12:43:23 INFO - PID 23150 | 1554468203402 webdriver::server DEBUG <- 200 OK {"value":"4294967297"}
[task 2019-04-05T12:43:23.458Z] 12:43:23 INFO - PID 23150 | 1554468203403 webdriver::server DEBUG -> GET /session/bebf61d0-7179-4f2d-a0da-6866cadef420/window/handles
[task 2019-04-05T12:43:23.458Z] 12:43:23 INFO - PID 23150 | 1554468203405 Marionette DEBUG 0 -> [0,11,"WebDriver:GetWindowHandles",{}]
[task 2019-04-05T12:43:23.458Z] 12:43:23 INFO - PID 23150 | 1554468203407 Marionette DEBUG 0 <- [1,11,null,["4294967297"]]
[task 2019-04-05T12:43:23.459Z] 12:43:23 INFO - PID 23150 | 1554468203407 webdriver::server DEBUG <- 200 OK {"value":["4294967297"]}
[task 2019-04-05T12:43:23.459Z] 12:43:23 INFO - PID 23150 | 1554468203408 webdriver::server DEBUG -> POST /session/bebf61d0-7179-4f2d-a0da-6866cadef420/window {"handle": "4294967297"}
[task 2019-04-05T12:43:23.460Z] 12:43:23 INFO - PID 23150 | 1554468203409 Marionette DEBUG 0 -> [0,12,"WebDriver:SwitchToWindow",{"handle":"4294967297","name":"4294967297"}]
[task 2019-04-05T12:43:23.460Z] 12:43:23 INFO - PID 23150 | 1554468203410 Marionette DEBUG 0 <- [1,12,null,{"value":null}]
[task 2019-04-05T12:43:23.461Z] 12:43:23 INFO - PID 23150 | 1554468203410 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2019-04-05T12:43:23.461Z] 12:43:23 INFO - PID 23150 | 1554468203411 webdriver::server DEBUG -> POST /session/bebf61d0-7179-4f2d-a0da-6866cadef420/alert/dismiss {}
[task 2019-04-05T12:43:23.462Z] 12:43:23 INFO - PID 23150 | 1554468203411 Marionette DEBUG 0 -> [0,13,"WebDriver:DismissAlert",{}]
[task 2019-04-05T12:43:23.463Z] 12:43:23 INFO - PID 23150 | 1554468203412 Marionette DEBUG 0 <- [1,13,{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://marionette/content/error.js:179:5\nNoSuchAl ... t@chrome://marionette/content/server.js:236:9\n_onJSONObjectReady/<@chrome://marionette/content/transport.js:492:20\n"},null]
[task 2019-04-05T12:43:23.463Z] 12:43:23 INFO - PID 23150 | 1554468203412 webdriver::server DEBUG <- 404 Not Found {"value":{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://marionette/content/error.js:179:5\nNoSuchAlertError@chrome://marionette/content/error.js:378:5\nGeckoDriver.prototype._checkIfAlertIsPresent@chrome://marionette/content/driver.js:3251:11\nGeckoDriver.prototype.dismissDialog@chrome://marionette/content/driver.js:3165:8\ndespatch@chrome://marionette/content/server.js:289:40\nexecute@chrome://marionette/content/server.js:262:16\nonPacket/<@chrome://marionette/content/server.js:235:20\nonPacket@chrome://marionette/content/server.js:236:9\n_onJSONObjectReady/<@chrome://marionette/content/transport.js:492:20\n"}}
[task 2019-04-05T12:43:23.465Z] 12:43:23 INFO - PID 23150 | 1554468203413 webdriver::server DEBUG -> POST /session/bebf61d0-7179-4f2d-a0da-6866cadef420/window {"handle": "4294967297"}
[task 2019-04-05T12:43:23.465Z] 12:43:23 INFO - PID 23150 | 1554468203414 Marionette DEBUG 0 -> [0,14,"WebDriver:SwitchToWindow",{"handle":"4294967297","name":"4294967297"}]
[task 2019-04-05T12:43:23.466Z] 12:43:23 INFO - PID 23150 | 1554468203415 Marionette DEBUG 0 <- [1,14,null,{"value":null}]
[task 2019-04-05T12:43:23.468Z] 12:43:23 INFO - PID 23150 | 1554468203415 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2019-04-05T12:43:23.469Z] 12:43:23 INFO - PID 23150 | 1554468203416 webdriver::server DEBUG -> GET /session/bebf61d0-7179-4f2d-a0da-6866cadef420/window
[task 2019-04-05T12:43:23.469Z] 12:43:23 INFO - PID 23150 | 1554468203417 Marionette DEBUG 0 -> [0,15,"WebDriver:GetWindowHandle",{}]
[task 2019-04-05T12:43:23.470Z] 12:43:23 INFO - PID 23150 | 1554468203417 Marionette DEBUG 0 <- [1,15,null,{"value":"4294967297"}]
[task 2019-04-05T12:43:23.471Z] 12:43:23 INFO - PID 23150 | 1554468203418 webdriver::server DEBUG <- 200 OK {"value":"4294967297"}
[task 2019-04-05T12:43:23.474Z] 12:43:23 INFO - PID 23150 | 1554468203419 webdriver::server DEBUG -> GET /session/bebf61d0-7179-4f2d-a0da-6866cadef420/window/handles
[task 2019-04-05T12:43:23.475Z] 12:43:23 INFO - PID 23150 | 1554468203420 Marionette DEBUG 0 -> [0,16,"WebDriver:GetWindowHandles",{}]
[task 2019-04-05T12:43:23.475Z] 12:43:23 INFO - PID 23150 | 1554468203420 Marionette DEBUG 0 <- [1,16,null,["4294967297"]]
[task 2019-04-05T12:43:23.476Z] 12:43:23 INFO - PID 23150 | 1554468203420 webdriver::server DEBUG <- 200 OK {"value":["4294967297"]}
[task 2019-04-05T12:43:23.476Z] 12:43:23 INFO - PID 23150 | 1554468203421 webdriver::server DEBUG -> POST /session/bebf61d0-7179-4f2d-a0da-6866cadef420/window {"handle": "4294967297"}
[task 2019-04-05T12:43:23.477Z] 12:43:23 INFO - PID 23150 | 1554468203422 Marionette DEBUG 0 -> [0,17,"WebDriver:SwitchToWindow",{"handle":"4294967297","name":"4294967297"}]
[task 2019-04-05T12:43:23.477Z] 12:43:23 INFO - PID 23150 | 1554468203422 Marionette DEBUG 0 <- [1,17,null,{"value":null}]
[task 2019-04-05T12:43:23.480Z] 12:43:23 INFO - PID 23150 | 1554468203423 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2019-04-05T12:43:23.480Z] 12:43:23 INFO - PID 23150 | 1554468203423 webdriver::server DEBUG -> POST /session/bebf61d0-7179-4f2d-a0da-6866cadef420/window/rect {"width": 800, "height": 600}
[task 2019-04-05T12:43:23.480Z] 12:43:23 INFO - PID 23150 | 1554468203424 Marionette DEBUG 0 -> [0,18,"WebDriver:SetWindowRect",{"height":600,"width":800}]
[task 2019-04-05T12:43:23.481Z] 12:43:23 INFO - TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/maximize_window/maximize.py | expected OK
[task 2019-04-05T12:43:23.481Z] 12:43:23 INFO - TEST-INFO took 30020ms
[task 2019-04-05T12:43:23.670Z] 12:43:23 INFO - STDOUT: tests/web-platform/tests/webdriver/tests/maximize_window/maximize.py::test_maximize_when_resized_to_max_size
[task 2019-04-05T12:43:23.671Z] 12:43:23 INFO - STDOUT: ERROR
[task 2019-04-05T12:43:23.671Z] 12:43:23 INFO - STDOUT: ==================================== ERRORS ====================================
[task 2019-04-05T12:43:23.672Z] 12:43:23 INFO - STDOUT: _________ ERROR at teardown of test_maximize_when_resized_to_max_size __________
[task 2019-04-05T12:43:23.672Z] 12:43:23 INFO - STDOUT: capabilities = {}
[task 2019-04-05T12:43:23.672Z] 12:43:23 INFO - STDOUT: configuration = {'capabilities': {'moz:firefoxOptions': {'binary': '/builds/worker/workspace/build/application/firefox/firefox', 'pref...orm.test,xn--lve-6lad.www2.not-web-platform.test,www2.www.not-web-platform.test'}}}, 'host': '127.0.0.1', 'port': 4445}
[task 2019-04-05T12:43:23.672Z] 12:43:23 INFO - Closing logging queue
[task 2019-04-05T12:43:23.673Z] 12:43:23 INFO - STDOUT: request = <SubRequest 'session' for <Function 'test_maximize_when_resized_to_max_size'>>
[task 2019-04-05T12:43:23.673Z] 12:43:23 INFO - STDOUT: @pytest.fixture(scope="function")
[task 2019-04-05T12:43:23.673Z] 12:43:23 INFO - STDOUT: def session(capabilities, configuration, request):
[task 2019-04-05T12:43:23.674Z] 12:43:23 INFO - STDOUT: """Create and start a session for a test that does not itself test session creation.
[task 2019-04-05T12:43:23.675Z] 12:43:23 INFO - STDOUT:
[task 2019-04-05T12:43:23.675Z] 12:43:23 INFO - STDOUT: By default the session will stay open after each test, but we always try to start a
[task 2019-04-05T12:43:23.675Z] 12:43:23 INFO - STDOUT: new one and assume that if that fails there is already a valid session. This makes it
[task 2019-04-05T12:43:23.676Z] 12:43:23 INFO - STDOUT: possible to recover from some errors that might leave the session in a bad state, but
[task 2019-04-05T12:43:23.677Z] 12:43:23 INFO - queue closed

Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 6 years ago5 years ago
Resolution: --- → INCOMPLETE
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.