1574967 - Intermittent Wd | <random> - setup error [Killing process]

Status: RESOLVED FIXED

(Remote Protocol :: Marionette, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: aciure [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=262268709&repo=autoland
Full log: https://queue.taskcluster.net/v1/task/Nm24orzAS_e6ahY8r_IcqQ/runs/0/artifacts/public/logs/live_backing.log

---

[task 2019-08-19T14:44:28.717Z] 14:44:28 INFO - TEST-PASS | /webdriver/tests/get_element_text/user_prompts.py | test_ignore[capabilities0-prompt]
[task 2019-08-19T14:44:28.717Z] 14:44:28 INFO - TEST-UNEXPECTED-ERROR | /webdriver/tests/get_element_text/user_prompts.py | test_default[alert-None] - setup error
[task 2019-08-19T14:44:28.717Z] 14:44:28 INFO - capabilities = {}
[task 2019-08-19T14:44:28.717Z] 14:44:28 INFO - configuration = {'capabilities': {'moz:firefoxOptions': {'binary': 'Z:\task_1566220377\build\application\firefox\firefox.exe', 'prefs'...platform.test,www2.www.not-web-platform.test', 'network.process.enabled': False}}}, 'host': '127.0.0.1', 'port': 51818}
[task 2019-08-19T14:44:28.717Z] 14:44:28 INFO - request = <SubRequest 'session' for <Function 'test_default[alert-None]'>>
[task 2019-08-19T14:44:28.717Z] 14:44:28 INFO -
[task 2019-08-19T14:44:28.717Z] 14:44:28 INFO - @pytest.fixture(scope="function")
[task 2019-08-19T14:44:28.718Z] 14:44:28 INFO - def session(capabilities, configuration, request):
[task 2019-08-19T14:44:28.718Z] 14:44:28 INFO - """Create and start a session for a test that does not itself test session creation.
[task 2019-08-19T14:44:28.718Z] 14:44:28 INFO -
[task 2019-08-19T14:44:28.718Z] 14:44:28 INFO - By default the session will stay open after each test, but we always try to start a
[task 2019-08-19T14:44:28.718Z] 14:44:28 INFO - new one and assume that if that fails there is already a valid session. This makes it
[task 2019-08-19T14:44:28.718Z] 14:44:28 INFO - possible to recover from some errors that might leave the session in a bad state, but
[task 2019-08-19T14:44:28.718Z] 14:44:28 INFO - does not demand that we start a new session per test."""
[task 2019-08-19T14:44:28.718Z] 14:44:28 INFO - global _current_session
[task 2019-08-19T14:44:28.718Z] 14:44:28 INFO -
[task 2019-08-19T14:44:28.718Z] 14:44:28 INFO - # Update configuration capabilities with custom ones from the
[task 2019-08-19T14:44:28.719Z] 14:44:28 INFO - # capabilities fixture, which can be set by tests
[task 2019-08-19T14:44:28.719Z] 14:44:28 INFO - caps = copy.deepcopy(configuration["capabilities"])
[task 2019-08-19T14:44:28.719Z] 14:44:28 INFO - caps.update(capabilities)
[task 2019-08-19T14:44:28.719Z] 14:44:28 INFO - caps = {"alwaysMatch": caps}
[task 2019-08-19T14:44:28.720Z] 14:44:28 INFO -
[task 2019-08-19T14:44:28.720Z] 14:44:28 INFO - # If there is a session with different capabilities active, end it now
[task 2019-08-19T14:44:28.721Z] 14:44:28 INFO - if _current_session is not None and (
[task 2019-08-19T14:44:28.721Z] 14:44:28 INFO - caps != _current_session.requested_capabilities):
[task 2019-08-19T14:44:28.722Z] 14:44:28 INFO - _current_session.end()
[task 2019-08-19T14:44:28.722Z] 14:44:28 INFO - _current_session = None
[task 2019-08-19T14:44:28.723Z] 14:44:28 INFO -
[task 2019-08-19T14:44:28.723Z] 14:44:28 INFO - if _current_session is None:
[task 2019-08-19T14:44:28.723Z] 14:44:28 INFO - _current_session = webdriver.Session(
[task 2019-08-19T14:44:28.723Z] 14:44:28 INFO - configuration["host"],
[task 2019-08-19T14:44:28.723Z] 14:44:28 INFO - configuration["port"],
[task 2019-08-19T14:44:28.723Z] 14:44:28 INFO - capabilities=caps)
[task 2019-08-19T14:44:28.723Z] 14:44:28 INFO - try:
[task 2019-08-19T14:44:28.723Z] 14:44:28 INFO - > _current_session.start()
[task 2019-08-19T14:44:28.723Z] 14:44:28 INFO -
[task 2019-08-19T14:44:28.723Z] 14:44:28 INFO - capabilities = {}
[task 2019-08-19T14:44:28.723Z] 14:44:28 INFO - caps = {'alwaysMatch': {'moz:firefoxOptions': {'binary': 'Z:\task_1566220377\build\application\firefox\firefox.exe', 'prefs':...form.test,xn--lve-6lad.www2.not-web-platform.test,www2.www.not-web-platform.test', 'network.process.enabled': False}}}}
[task 2019-08-19T14:44:28.724Z] 14:44:28 INFO - configuration = {'capabilities': {'moz:firefoxOptions': {'binary': 'Z:\task_1566220377\build\application\firefox\firefox.exe', 'prefs'...platform.test,www2.www.not-web-platform.test', 'network.process.enabled': False}}}, 'host': '127.0.0.1', 'port': 51818}
[task 2019-08-19T14:44:28.724Z] 14:44:28 INFO - request = <SubRequest 'session' for <Function 'test_default[alert-None]'>>

Comment 1

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

Firefox failed to start. There is a warning in the log:

[task 2019-08-19T14:44:19.406Z] 14:44:19     INFO - PID 5036 | 1566225859390	geckodriver::marionette	DEBUG	Waiting 60s to connect to browser on 127.0.0.1:2828
[task 2019-08-19T14:44:19.821Z] 14:44:19     INFO - PID 5036 | [3516, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012: file z:/build/build/src/extensions/permissions/nsPermissionManager.cpp, line 2901
[task 2019-08-19T14:44:20.504Z] 14:44:20     INFO - PID 5036 | 1566225860490	mozrunner::runner	DEBUG	Killing process 5528

What I don't understand is why geckodriver kills Firefox after just 1 second. I think that I will finally file a new bug, which can be used to collect all those failing jobs.

Comment 3

[Intermittent Failures Robot]

4 failures in 5073 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 3
• mozilla-inbound: 1

Platform breakdown:

• windows7-32: 3
• macosx1014-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1574967&startday=2019-08-19&endday=2019-08-25&tree=all

Comment 4

[Intermittent Failures Robot]

5 failures in 5047 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-inbound: 1
• mozilla-central: 4

Platform breakdown:

• windows7-32: 1
• linux64-ccov: 4

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1574967&startday=2019-08-26&endday=2019-09-01&tree=all

Comment 5

[Intermittent Failures Robot]

3 failures in 4408 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 3

Platform breakdown:

• windows7-32: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1574967&startday=2019-09-02&endday=2019-09-08&tree=all

Comment 6

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform breakdown:

• windows7-32: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1574967&startday=2019-09-09&endday=2019-09-15&tree=all

Comment 7

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-beta: 1

Platform breakdown:

• windows7-32: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1574967&startday=2019-09-23&endday=2019-09-29&tree=all

Comment 8

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

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

Comment 9

[Daniel Varga [:dvarga]]

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=295458213&repo=autoland&lineNumber=40596

Comment 10

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform breakdown:

• macosx1014-64-shippable: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1574967&startday=2020-03-30&endday=2020-04-05&tree=all

Comment 11

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

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

Comment 12

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

Recently no failures have been tagged for this bug. As such it was closed as incomplete. But with bug 1575021 fixed it should be gone now.

Comment 14

[BMO Automation]

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