1597532 - Intermittent TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/is_element_selected/selected.py | expected OK [missing marionette-startup-requested]

Status: RESOLVED INCOMPLETE

(Remote Protocol :: Marionette, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: rgurzau [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=276798078&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/REFD2LvSQwiwqkbzMdgAnA/runs/0/artifacts/public/logs/live_backing.log

---

[task 2019-11-18T18:00:53.493Z] 18:00:53 INFO - TEST-START | /webdriver/tests/is_element_selected/selected.py
[task 2019-11-18T18:00:53.802Z] 18:00:53 INFO - STDOUT: ============================= test session starts =============================
[task 2019-11-18T18:00:53.802Z] 18:00:53 INFO - STDOUT: platform win32 -- Python 2.7.15, pytest-unknown, py-1.5.2, pluggy-0.5.3.dev -- Z:\task_1574099255\build\venv\Scripts\python.exe
[task 2019-11-18T18:00:53.802Z] 18:00:53 INFO - STDOUT: rootdir: Z:\task_1574099255\build, inifile:
[task 2019-11-18T18:00:53.802Z] 18:00:53 INFO - STDOUT: collecting ...
[task 2019-11-18T18:00:53.827Z] 18:00:53 INFO - STDOUT: collected 6 items
[task 2019-11-18T18:00:53.827Z] 18:00:53 INFO - STDOUT: tests/web-platform/tests/webdriver/tests/is_element_selected/selected.py::test_no_browsing_context
[task 2019-11-18T18:00:53.833Z] 18:00:53 INFO - PID 7972 | 1574100053823 webdriver::server DEBUG -> POST /session {"capabilities": {"alwaysMatch": {"moz:firefoxOptions": {"binary": "Z:\task_1574099255\build\application\firefox\firefox.exe", "prefs": {"media.peerconnection.mtransport_process": false, "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", "network.process.enabled": false}}}}}
[task 2019-11-18T18:00:53.833Z] 18:00:53 INFO - PID 7972 | 1574100053827 mozrunner::runner INFO Running command: "Z:\task_1574099255\build\application\firefox\firefox.exe" "-marionette" "-foreground" "-no-remote" "-profile" "C:\Users\task_1574099255\AppData\Local\Temp\rust_mozprofilesyeKk9"
[task 2019-11-18T18:00:53.833Z] 18:00:53 INFO - PID 7972 | 1574100053827 geckodriver::marionette DEBUG Waiting 60s to connect to browser on 127.0.0.1:2828
[task 2019-11-18T18:00:54.304Z] 18:00:54 INFO - PID 7972 | 1574100054291 [e-mail] WARN Loading extension '[e-mail]': Reading manifest: Invalid extension permission: mozillaAddons
[task 2019-11-18T18:00:54.304Z] 18:00:54 INFO - PID 7972 | 1574100054291 [e-mail] WARN Loading extension '[e-mail]': Reading manifest: Invalid extension permission: telemetry
[task 2019-11-18T18:00:54.304Z] 18:00:54 INFO - PID 7972 | 1574100054292 [e-mail] WARN Loading extension '[e-mail]': Reading manifest: Invalid extension permission: resource://pdf.js/
[task 2019-11-18T18:00:54.305Z] 18:00:54 INFO - PID 7972 | 1574100054292 [e-mail] WARN Loading extension '[e-mail]': Reading manifest: Invalid extension permission: about:reader*
[task 2019-11-18T18:00:54.424Z] 18:00:54 INFO - PID 7972 | 1574100054402 Marionette TRACE Received observer notification profile-after-change
[task 2019-11-18T18:00:54.475Z] 18:00:54 INFO - PID 7972 | 1574100054468 Marionette TRACE Received observer notification toplevel-window-ready
[task 2019-11-18T18:00:54.517Z] 18:00:54 INFO - PID 7972 | 1574100054510 Marionette TRACE Received observer notification command-line-startup
[task 2019-11-18T18:00:54.517Z] 18:00:54 INFO - PID 7972 | 1574100054510 Marionette DEBUG Init aborted (running=false, enabled=true, finalUIStartup=false)
[task 2019-11-18T18:00:54.582Z] 18:00:54 INFO - PID 7972 | 1574100054564 Marionette TRACE Received observer notification toplevel-window-ready
[task 2019-11-18T18:01:23.521Z] 18:01:23 INFO - TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/is_element_selected/selected.py | expected OK
[task 2019-11-18T18:01:23.521Z] 18:01:23 INFO - TEST-INFO took 30021ms
[task 2019-11-18T18:01:23.561Z] 18:01:23 INFO - Closing logging queue
[task 2019-11-18T18:01:23.561Z] 18:01:23 INFO - queue closed
[task 2019-11-18T18:01:23.562Z] 18:01:23 INFO - Starting runner
[task 2019-11-18T18:01:24.061Z] 18:01:24 INFO - PID 10204 | 1574100084051 geckodriver DEBUG Listening on 127.0.0.1:53534
[task 2019-11-18T18:01:24.552Z] 18:01:24 INFO - WebDriver HTTP server listening at http://127.0.0.1:53534/

Comment 1

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

Another case of a missing marionette-startup-requested notification.

Comment 2

[Intermittent Failures Robot]

1 failures in 5444 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform breakdown:

• windows10-64-shippable: 1

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

Comment 3

[BugBot [:suhaib / :marco/ :calixte]]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Comment 4

[BMO Automation]

Moving bug to Remote Protocol::Marionette component per bug 1815831.