Intermittent WD | <random> - setup error: webdriver.error.UnknownErrorException: unknown error (500): Process unexpectedly closed with status 1
Categories
(Remote Protocol :: Marionette, defect, P5)
Tracking
(Not tracked)
People
(Reporter: intermittent-bug-filer, Unassigned)
References
Details
(Keywords: intermittent-failure)
Filed by: ccozmuta [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=349920872&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/ShSccnBZSQOH1MVi198zww/runs/0/artifacts/public/logs/live_backing.log
[task 2021-08-30T07:43:43.007Z] 07:43:43 INFO - TEST-START | /webdriver/tests/element_click/bubbling.py
[task 2021-08-30T07:43:43.229Z] 07:43:43 INFO - STDOUT: ============================= test session starts ==============================
[task 2021-08-30T07:43:43.230Z] 07:43:43 INFO - STDOUT: platform darwin -- Python 3.7.9, pytest-6.1.1, py-1.5.2, pluggy-unknown -- /opt/worker/tasks/task_163030089473356/build/venv/bin/python
[task 2021-08-30T07:43:43.231Z] 07:43:43 INFO - STDOUT: rootdir: /opt/worker/tasks/task_163030089473356/build
[task 2021-08-30T07:43:43.232Z] 07:43:43 INFO - STDOUT: plugins: asyncio-0.14.0
[task 2021-08-30T07:43:43.232Z] 07:43:43 INFO - STDOUT: collecting ...
[task 2021-08-30T07:43:43.244Z] 07:43:43 INFO - STDOUT: collected 3 items
[task 2021-08-30T07:43:43.245Z] 07:43:43 INFO - STDOUT: tests/web-platform/tests/webdriver/tests/element_click/bubbling.py::test_click_event_bubbles_to_parents
[task 2021-08-30T07:43:43.247Z] 07:43:43 INFO - PID 5893 | 1630309423246 webdriver::server DEBUG -> POST /session {"capabilities": {"alwaysMatch": {"moz:firefoxOptions": {"args": ["--profile", "/var/folders/tf/93bb5jv56vb7tmkplpdbr3_0000014/T/tmpea_nf7rr.mozrunner"], "binary": "/opt/worker/tasks/task_163030089473356/build/application/Firefox Nightly.app/Contents/MacOS/firefox"}}}}
[task 2021-08-30T07:43:43.248Z] 07:43:43 INFO - PID 5893 | 1630309423246 geckodriver::capabilities DEBUG Trying to read firefox version from ini files
[task 2021-08-30T07:43:43.249Z] 07:43:43 INFO - PID 5893 | 1630309423246 geckodriver::capabilities DEBUG Found version 93.0a1
[task 2021-08-30T07:43:43.250Z] 07:43:43 INFO - PID 5893 | 1630309423247 geckodriver::browser DEBUG Backing up prefs to "/var/folders/tf/93bb5jv56vb7tmkplpdbr3_0000014/T/tmpea_nf7rr.mozrunner/user.geckodriver_backup_5"
[task 2021-08-30T07:43:43.259Z] 07:43:43 INFO - PID 5893 | 1630309423258 mozrunner::runner INFO Running command: "/opt/worker/tasks/task_163030089473356/build/application/Firefox Nightly.app/Contents/MacOS/firefox" "--marionette" "--profile" "/var/folders/tf/93bb5jv56vb7tmkplpdbr3_0000014/T/tmpea_nf7rr.mozrunner" "-foreground" "-no-remote"
[task 2021-08-30T07:43:43.260Z] 07:43:43 INFO - PID 5893 | 1630309423259 geckodriver::marionette DEBUG Waiting 60s to connect to browser on 127.0.0.1:2828
[task 2021-08-30T07:43:43.261Z] 07:43:43 INFO - PID 5893 | 1630309423259 geckodriver::marionette TRACE Connection refused (os error 61). Retrying in 100ms
[task 2021-08-30T07:43:43.314Z] 07:43:43 INFO - PID 5893 | *** You are running in headless mode.
<...>
[task 2021-08-30T07:43:47.491Z] 07:43:47 INFO - STDOUT: err = <UnknownErrorException http_status=500>
[task 2021-08-30T07:43:47.491Z] 07:43:47 INFO - STDOUT: method = 'POST'
[task 2021-08-30T07:43:47.492Z] 07:43:47 INFO - STDOUT: response = <Response status=500 error=<UnknownErrorException http_status=500>>
[task 2021-08-30T07:43:47.492Z] 07:43:47 INFO - STDOUT: self = <Session (disconnected)>
[task 2021-08-30T07:43:47.493Z] 07:43:47 INFO - STDOUT: timeout = None
[task 2021-08-30T07:43:47.493Z] 07:43:47 INFO - STDOUT: url = 'session'
[task 2021-08-30T07:43:47.494Z] 07:43:47 INFO - STDOUT: tests/web-platform/tests/tools/webdriver/webdriver/client.py
[task 2021-08-30T07:43:47.494Z] 07:43:47 INFO - STDOUT: :604: UnknownErrorException
[task 2021-08-30T07:43:47.495Z] 07:43:47 INFO - STDOUT: =========================== short test summary info ============================
[task 2021-08-30T07:43:47.495Z] 07:43:47 INFO - STDOUT: ERROR tests/web-platform/tests/webdriver/tests/element_click/bubbling.py::test_click_event_bubbles_to_parents
[task 2021-08-30T07:43:47.496Z] 07:43:47 INFO - STDOUT: ========================== 2 passed, 1 error in 4.18s ==========================
[task 2021-08-30T07:43:47.503Z] 07:43:47 INFO - TEST-UNEXPECTED-ERROR | /webdriver/tests/element_click/bubbling.py | test_click_event_bubbles_to_parents - setup error: webdriver.error.UnknownErrorException: unknown error (500): Process unexpectedly closed with status 1
[task 2021-08-30T07:43:47.503Z] 07:43:47 INFO - args = ()
[task 2021-08-30T07:43:47.503Z] 07:43:47 INFO - kwargs = {'capabilities': {}, 'configuration': {'capabilities': {'moz:firefoxOptions': {'args': ['--profile', '/var/folders/tf/...st': '127.0.0.1', 'port': 52114}, 'request': <SubRequest 'session' for <Function test_click_event_bubbles_to_parents>>}
[task 2021-08-30T07:43:47.503Z] 07:43:47 INFO - request = <SubRequest 'session' for <Function test_click_event_bubbles_to_parents>>
[task 2021-08-30T07:43:47.503Z] 07:43:47 INFO - setup = <function pytest_fixture_setup.<locals>.wrapper.<locals>.setup at 0x7fe912776d40>
[task 2021-08-30T07:43:47.503Z] 07:43:47 INFO - finalizer = <function pytest_fixture_setup.<locals>.wrapper.<locals>.finalizer at 0x7fe912776dd0>
[task 2021-08-30T07:43:47.503Z] 07:43:47 INFO -
[task 2021-08-30T07:43:47.503Z] 07:43:47 INFO - def wrapper(*args, **kwargs):
[task 2021-08-30T07:43:47.504Z] 07:43:47 INFO - loop = fixture_stripper.get_and_strip_from(FixtureStripper.EVENT_LOOP, kwargs)
[task 2021-08-30T07:43:47.504Z] 07:43:47 INFO - request = fixture_stripper.get_and_strip_from(FixtureStripper.REQUEST, kwargs)
[task 2021-08-30T07:43:47.504Z] 07:43:47 INFO -
[task 2021-08-30T07:43:47.504Z] 07:43:47 INFO - gen_obj = generator(*args, **kwargs)
[task 2021-08-30T07:43:47.504Z] 07:43:47 INFO -
[task 2021-08-30T07:43:47.504Z] 07:43:47 INFO - async def setup():
[task 2021-08-30T07:43:47.504Z] 07:43:47 INFO - res = await gen_obj.__anext__()
[task 2021-08-30T07:43:47.504Z] 07:43:47 INFO - return res
[task 2021-08-30T07:43:47.504Z] 07:43:47 INFO -
[task 2021-08-30T07:43:47.504Z] 07:43:47 INFO - def finalizer():
[task 2021-08-30T07:43:47.504Z] 07:43:47 INFO - """Yield again, to finalize."""
[task 2021-08-30T07:43:47.504Z] 07:43:47 INFO - async def async_finalizer():
[task 2021-08-30T07:43:47.504Z] 07:43:47 INFO - try:
[task 2021-08-30T07:43:47.504Z] 07:43:47 INFO - await gen_obj.__anext__()
[task 2021-08-30T07:43:47.504Z] 07:43:47 INFO - except StopAsyncIteration:
[task 2021-08-30T07:43:47.504Z] 07:43:47 INFO - pass
[task 2021-08-30T07:43:47.504Z] 07:43:47 INFO - else:
[task 2021-08-30T07:43:47.504Z] 07:43:47 INFO - msg = "Async generator fixture didn't stop."
[task 2021-08-30T07:43:47.504Z] 07:43:47 INFO - msg += "Yield only once."
[task 2021-08-30T07:43:47.504Z] 07:43:47 INFO - raise ValueError(msg)
[task 2021-08-30T07:43:47.504Z] 07:43:47 INFO - loop.run_until_complete(async_finalizer())
[task 2021-08-30T07:43:47.504Z] 07:43:47 INFO -
[task 2021-08-30T07:43:47.504Z] 07:43:47 INFO - request.addfinalizer(finalizer)
[task 2021-08-30T07:43:47.505Z] 07:43:47 INFO - > return loop.run_until_complete(setup())
[task 2021-08-30T07:43:47.505Z] 07:43:47 INFO -
[task 2021-08-30T07:43:47.505Z] 07:43:47 INFO - args = ()
[task 2021-08-30T07:43:47.505Z] 07:43:47 INFO - finalizer = <function pytest_fixture_setup.<locals>.wrapper.<locals>.finalizer at 0x7fe912776dd0>
[task 2021-08-30T07:43:47.505Z] 07:43:47 INFO - fixture_stripper = <pytest_asyncio.plugin.FixtureStripper object at 0x7fe91274c350>
[task 2021-08-30T07:43:47.505Z] 07:43:47 INFO - gen_obj = <async_generator object session at 0x7fe912776cb0>
[task 2021-08-30T07:43:47.505Z] 07:43:47 INFO - generator = <function session at 0x7fe9126f94d0>
[task 2021-08-30T07:43:47.505Z] 07:43:47 INFO - kwargs = {'capabilities': {},
[task 2021-08-30T07:43:47.505Z] 07:43:47 INFO - 'configuration': {'capabilities': {'moz:firefoxOptions': {'args': ['--profile',
[task 2021-08-30T07:43:47.505Z] 07:43:47 INFO - '/var/folders/tf/93bb5jv56vb7tmkplpdbr3_0000014/T/tmpea_nf7rr.mozrunner'],
[task 2021-08-30T07:43:47.505Z] 07:43:47 INFO - 'binary': '/opt/worker/tasks/task_163030089473356/build/application/Firefox '
[task 2021-08-30T07:43:47.505Z] 07:43:47 INFO - 'Nightly.app/Contents/MacOS/firefox'}},
[task 2021-08-30T07:43:47.505Z] 07:43:47 INFO - 'host': '127.0.0.1',
[task 2021-08-30T07:43:47.505Z] 07:43:47 INFO - 'port': 52114},
[task 2021-08-30T07:43:47.505Z] 07:43:47 INFO - 'request': <SubRequest 'session' for <Function test_click_event_bubbles_to_parents>>}
[task 2021-08-30T07:43:47.505Z] 07:43:47 INFO - loop = <_UnixSelectorEventLoop running=False closed=False debug=False>
[task 2021-08-30T07:43:47.505Z] 07:43:47 INFO - request = <SubRequest 'session' for <Function test_click_event_bubbles_to_parents>>
[task 2021-08-30T07:43:47.505Z] 07:43:47 INFO - setup = <function pytest_fixture_setup.<locals>.wrapper.<locals>.setup at 0x7fe912776d40>
[task 2021-08-30T07:43:47.505Z] 07:43:47 INFO -
[task 2021-08-30T07:43:47.505Z] 07:43:47 INFO - tests/web-platform/tests/tools/third_party/pytest-asyncio/pytest_asyncio/plugin.py:127:
[task 2021-08-30T07:43:47.505Z] 07:43:47 INFO - _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
[task 2021-08-30T07:43:47.505Z] 07:43:47 INFO - /Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/asyncio/base_events.py:587: in run_until_complete
[task 2021-08-30T07:43:47.505Z] 07:43:47 INFO - return future.result()
[task 2021-08-30T07:43:47.505Z] 07:43:47 INFO - future = <Task finished coro=<pytest_fixture_setup.<locals>.wrapper.<locals>.setup() done, defined at /opt/worker/tasks/task_163030089473356/build/tests/web-platform/tests/tools/third_party/pytest-asyncio/pytest_asyncio/plugin.py:109> exception=<UnknownErrorException http_status=500>>
[task 2021-08-30T07:43:47.505Z] 07:43:47 INFO - new_task = True
[task 2021-08-30T07:43:47.505Z] 07:43:47 INFO - self = <_UnixSelectorEventLoop running=False closed=False debug=False>
[task 2021-08-30T07:43:47.505Z] 07:43:47 INFO - tests/web-platform/tests/tools/third_party/pytest-asyncio/pytest_asyncio/plugin.py:110: in setup
[task 2021-08-30T07:43:47.505Z] 07:43:47 INFO - res = await gen_obj.__anext__()
[task 2021-08-30T07:43:47.505Z] 07:43:47 INFO - gen_obj = <async_generator object session at 0x7fe912776cb0>
[task 2021-08-30T07:43:47.505Z] 07:43:47 INFO - tests/web-platform/tests/webdriver/tests/support/fixtures.py:117: in session
[task 2021-08-30T07:43:47.506Z] 07:43:47 INFO - _current_session.start()
[task 2021-08-30T07:43:47.506Z] 07:43:47 INFO - capabilities = {}
[task 2021-08-30T07:43:47.506Z] 07:43:47 INFO - caps = {'alwaysMatch': {'moz:firefoxOptions': {'args': ['--profile',
[task 2021-08-30T07:43:47.506Z] 07:43:47 INFO - '/var/folders/tf/93bb5jv56vb7tmkplpdbr3_0000014/T/tmpea_nf7rr.mozrunner'],
[task 2021-08-30T07:43:47.506Z] 07:43:47 INFO - 'binary': '/opt/worker/tasks/task_163030089473356/build/application/Firefox '
[task 2021-08-30T07:43:47.506Z] 07:43:47 INFO - 'Nightly.app/Contents/MacOS/firefox'}}}
[task 2021-08-30T07:43:47.506Z] 07:43:47 INFO - configuration = {'capabilities': {'moz:firefoxOptions': {'args': ['--profile',
[task 2021-08-30T07:43:47.506Z] 07:43:47 INFO - '/var/folders/tf/93bb5jv56vb7tmkplpdbr3_0000014/T/tmpea_nf7rr.mozrunner'],
[task 2021-08-30T07:43:47.506Z] 07:43:47 INFO - 'binary': '/opt/worker/tasks/task_163030089473356/build/application/Firefox '
[task 2021-08-30T07:43:47.506Z] 07:43:47 INFO - 'Nightly.app/Contents/MacOS/firefox'}},
[task 2021-08-30T07:43:47.506Z] 07:43:47 INFO - 'host': '127.0.0.1',
<...>
[task 2021-08-30T07:43:47.508Z] 07:43:47 INFO - tests/web-platform/tests/tools/webdriver/webdriver/client.py:604: UnknownErrorException
[task 2021-08-30T07:43:47.509Z] 07:43:47 INFO - ..
[task 2021-08-30T07:43:47.509Z] 07:43:47 INFO - TEST-OK | /webdriver/tests/element_click/bubbling.py | took 4433ms
[task 2021-08-30T07:43:47.599Z] 07:43:47 INFO - Closing logging queue
[task 2021-08-30T07:43:47.600Z] 07:43:47 INFO - queue closed
[task 2021-08-30T07:43:47.601Z] 07:43:47 INFO - Starting runner
[task 2021-08-30T07:43:48.716Z] 07:43:48 INFO - PID 5905 | 1630309428102 geckodriver INFO Listening on 127.0.0.1:52179
[task 2021-08-30T07:43:48.716Z] 07:43:48 INFO - WebDriver HTTP server listening at http://127.0.0.1:52179/
[task 2021-08-30T07:43:48.718Z] 07:43:48 INFO - TEST-START | /webdriver/tests/element_click/center_point.py
Updated•4 years ago
|
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 4•4 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.
Reporter | ||
Comment 5•3 years ago
|
||
treeherder |
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=392495068&repo=mozilla-beta
Comment 6•3 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.
Comment 7•2 years ago
|
||
Reporter | ||
Comment 8•2 years ago
|
||
treeherder |
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=430564985&repo=mozilla-esr115
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 24•1 years ago
|
||
All the recent intermittent failures were wrongly classified. I've fixed that for bug 1819763.
As such there we no failures with a status 1
exit code within the last month.
Reporter | ||
Comment 25•1 years ago
|
||
treeherder |
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=444260258&repo=mozilla-central
Comment 26•1 years ago
|
||
(In reply to Treeherder Bug Filer from comment #25)
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=444260258&repo=mozilla-central
This is a wrong classification again. Also the exit code with 127 doesn't match 1. It's as well bug 1819763.
Christian, as best is when you are using the search field of the log viewer and check for that failure message where exactly it is returned. Then observe the lines right before if some assertion is raised. That way you can find the real underlying issue.
Reporter | ||
Comment 28•1 year ago
|
||
treeherder |
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=463004227&repo=mozilla-beta
Comment 29•1 year ago
|
||
(In reply to Treeherder Bug Filer from comment #28)
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=463004227&repo=mozilla-beta
This is just bug 1819763.
Reporter | ||
Comment 30•1 year ago
|
||
treeherder |
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=467701262&repo=mozilla-central
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 43•9 months ago
|
||
We need trace logs (bug 1906355) to find out why the Mozilla specific tests causing Firefox to terminate abnormally.
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 56•4 months ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Reporter | ||
Comment 59•3 months ago
|
||
treeherder |
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=504448677&repo=mozilla-beta
Comment 60•3 months ago
|
||
(In reply to Treeherder Bug Filer from comment #59)
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=504448677&repo=mozilla-beta
This is bug 1819763.
Reporter | ||
Comment 61•6 days ago
|
||
treeherder |
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=515677880&repo=mozilla-esr115
Description
•