Closed Bug 1825986 Opened 2 years ago Closed 2 years ago

Intermittent /webdriver/tests/execute_script/arguments.py | test_null - setup error: webdriver.error.UnknownErrorException: unknown error (500): Failed to decode response from marionette

Categories

(Remote Protocol :: Marionette, defect, P5)

defect

Tracking

(Not tracked)

RESOLVED DUPLICATE of bug 1770595

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

Filed by: nbeleuzu [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=411120881&repo=try
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/c7uE9P0lQjORsI7mMR4BEA/runs/0/artifacts/public/logs/live_backing.log


[task 2023-04-02T12:01:14.716Z] 12:01:14     INFO - STDOUT: response = <Response status=500 error=<JavascriptErrorException http_status=500>>
[task 2023-04-02T12:01:14.717Z] 12:01:14     INFO - STDOUT: value = None
[task 2023-04-02T12:01:14.718Z] 12:01:14     INFO - STDOUT:     def assert_success(response, value=None):
[task 2023-04-02T12:01:14.718Z] 12:01:14     INFO - STDOUT:         """
[task 2023-04-02T12:01:14.719Z] 12:01:14     INFO - STDOUT:         Verify that the provided webdriver.Response instance described
[task 2023-04-02T12:01:14.719Z] 12:01:14     INFO - STDOUT:         a valid success response as defined by `dfn-send-a-response` and
[task 2023-04-02T12:01:14.720Z] 12:01:14     INFO - STDOUT:         the provided response value.
[task 2023-04-02T12:01:14.720Z] 12:01:14     INFO - STDOUT:     
[task 2023-04-02T12:01:14.721Z] 12:01:14     INFO - STDOUT:         :param response: ``webdriver.Response`` instance.
[task 2023-04-02T12:01:14.722Z] 12:01:14     INFO - STDOUT:         :param value: Expected value of the response body, if any.
[task 2023-04-02T12:01:14.722Z] 12:01:14     INFO - STDOUT:         """
[task 2023-04-02T12:01:14.723Z] 12:01:14     INFO - STDOUT: >       assert response.status == 200, str(response.error)
[task 2023-04-02T12:01:14.723Z] 12:01:14     INFO - STDOUT: E       AssertionError: javascript error (500): Cyclic object value
[task 2023-04-02T12:01:14.724Z] 12:01:14     INFO - STDOUT: E         
[task 2023-04-02T12:01:14.724Z] 12:01:14     INFO - STDOUT: E         Remote-end stacktrace:
[task 2023-04-02T12:01:14.725Z] 12:01:14     INFO - STDOUT: E         
[task 2023-04-02T12:01:14.725Z] 12:01:14     INFO - STDOUT: E         RemoteError@chrome://remote/content/shared/RemoteError.sys.mjs:8:8
[task 2023-04-02T12:01:14.726Z] 12:01:14     INFO - STDOUT: E         WebDriverError@chrome://remote/content/shared/webdriver/Errors.sys.mjs:182:5
[task 2023-04-02T12:01:14.727Z] 12:01:14     INFO - STDOUT: E         JavaScriptError@chrome://remote/content/shared/webdriver/Errors.sys.mjs:361:5
[task 2023-04-02T12:01:14.727Z] 12:01:14     INFO - STDOUT: E         cloneObject@chrome://remote/content/marionette/json.sys.mjs:43:11
[task 2023-04-02T12:01:14.728Z] 12:01:14     INFO - STDOUT: E         cloneJSON@chrome://remote/content/marionette/json.sys.mjs:177:12
[task 2023-04-02T12:01:14.729Z] 12:01:14     INFO - STDOUT: E         cloneObject@chrome://remote/content/marionette/json.sys.mjs:56:24
[task 2023-04-02T12:01:14.729Z] 12:01:14     INFO - STDOUT: E         cloneJSON@chrome://remote/content/marionette/json.sys.mjs:177:12
[task 2023-04-02T12:01:14.730Z] 12:01:14     INFO - STDOUT: E         cloneObject@chrome://remote/content/marionette/json.sys.mjs:56:24
[task 2023-04-02T12:01:14.731Z] 12:01:14     INFO - STDOUT: E         cloneJSON@chrome://remote/content/marionette/json.sys.mjs:177:12
[task 2023-04-02T12:01:14.731Z] 12:01:14     INFO - STDOUT: E         json.clone@chrome://remote/content/marionette/json.sys.mjs:180:10
[task 2023-04-02T12:01:14.732Z] 12:01:14     INFO - STDOUT: E         receiveMessage@chrome://remote/content/marionette/actors/MarionetteCommandsChild.sys.mjs:188:25
[task 2023-04-02T12:01:14.732Z] 12:01:14     INFO - STDOUT: E         
[task 2023-04-02T12:01:14.733Z] 12:01:14     INFO - STDOUT: E       assert 500 == 200
[task 2023-04-02T12:01:14.733Z] 12:01:14     INFO - STDOUT: E         +500
[task 2023-04-02T12:01:14.734Z] 12:01:14     INFO - STDOUT: E         -200
[task 2023-04-02T12:01:14.735Z] 12:01:14     INFO - STDOUT: response   = <Response status=500 error=<JavascriptErrorException http_status=500>>
[task 2023-04-02T12:01:14.735Z] 12:01:14     INFO - STDOUT: value      = None
[task 2023-04-02T12:01:14.736Z] 12:01:14     INFO - STDOUT: tests/web-platform/tests/webdriver/tests/support/asserts.py
[task 2023-04-02T12:01:14.736Z] 12:01:14     INFO - STDOUT: :67: AssertionError
[task 2023-04-02T12:01:14.737Z] 12:01:14     INFO - STDOUT: =========================== short test summary info ============================
[task 2023-04-02T12:01:14.738Z] 12:01:14     INFO - STDOUT: FAILED tests/web-platform/tests/webdriver/tests/execute_script/arguments.py::test_element_reference[frame]
[task 2023-04-02T12:01:14.738Z] 12:01:14     INFO - STDOUT: FAILED tests/web-platform/tests/webdriver/tests/execute_script/arguments.py::test_element_reference[window]
[task 2023-04-02T12:01:14.739Z] 12:01:14     INFO - STDOUT: ERROR tests/web-platform/tests/webdriver/tests/execute_script/arguments.py::test_null
[task 2023-04-02T12:01:14.740Z] 12:01:14     INFO - STDOUT: ==================== 2 failed, 21 passed, 1 error in 41.14s ====================
[task 2023-04-02T12:01:14.747Z] 12:01:14     INFO - 
[task 2023-04-02T12:01:14.747Z] 12:01:14     INFO - TEST-UNEXPECTED-ERROR | /webdriver/tests/execute_script/arguments.py | test_null - setup error: webdriver.error.UnknownErrorException: unknown error (500): Failed to decode response from marionette
[task 2023-04-02T12:01:14.747Z] 12:01:14     INFO - event_loop = <_UnixSelectorEventLoop running=False closed=False debug=False>
[task 2023-04-02T12:01:14.747Z] 12:01:14     INFO - request = <SubRequest 'session' for <Function test_null>>
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO - kwargs = {'capabilities': {}, 'configuration': {'capabilities': {'moz:firefoxOptions': {'args': ['--profile', '/tmp/tmpn8p3crgq...rker/workspace/build/application/firefox/firefox'}}, 'host': '127.0.0.1', 'port': 37144, 'timeout_multiplier': 3, ...}}
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO - setup = <function _wrap_asyncgen.<locals>._asyncgen_fixture_wrapper.<locals>.setup at 0x7f96e9b66560>
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO - finalizer = <function _wrap_asyncgen.<locals>._asyncgen_fixture_wrapper.<locals>.finalizer at 0x7f96e9b665f0>
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO - 
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO -     @functools.wraps(func)
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO -     def _asyncgen_fixture_wrapper(
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO -         event_loop: asyncio.AbstractEventLoop, request: SubRequest, **kwargs: Any
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO -     ) -> _R:
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO -         gen_obj = func(**_add_kwargs(func, kwargs, event_loop, request))
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO -     
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO -         async def setup() -> _R:
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO -             res = await gen_obj.__anext__()
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO -             return res
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO -     
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO -         def finalizer() -> None:
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO -             """Yield again, to finalize."""
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO -     
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO -             async def async_finalizer() -> None:
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO -                 try:
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO -                     await gen_obj.__anext__()
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO -                 except StopAsyncIteration:
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO -                     pass
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO -                 else:
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO -                     msg = "Async generator fixture didn't stop."
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO -                     msg += "Yield only once."
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO -                     raise ValueError(msg)
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO -     
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO -             event_loop.run_until_complete(async_finalizer())
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO -     
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO - >       result = event_loop.run_until_complete(setup())
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO - 
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO - event_loop = <_UnixSelectorEventLoop running=False closed=False debug=False>
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO - finalizer  = <function _wrap_asyncgen.<locals>._asyncgen_fixture_wrapper.<locals>.finalizer at 0x7f96e9b665f0>
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO - func       = <function session at 0x7f96ea46d7a0>
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO - gen_obj    = <async_generator object session at 0x7f96e9b664d0>
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO - kwargs     = {'capabilities': {},
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO -  'configuration': {'capabilities': {'moz:firefoxOptions': {'args': ['--profile',
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO -                                                                     '/tmp/tmpn8p3crgq.mozrunner'],
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO -                                                            'binary': '/builds/worker/workspace/build/application/firefox/firefox'}},
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO -                    'host': '127.0.0.1',
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO -                    'port': 37144,
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO -                    'timeout_multiplier': 3,
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO -                    'webdriver': {'args': ['-vv'],
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO -                                  'binary': '/builds/worker/fetches/geckodriver'}}}
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO - request    = <SubRequest 'session' for <Function test_null>>
[task 2023-04-02T12:01:14.748Z] 12:01:14     INFO - setup      = <function _wrap_asyncgen.<locals>._asyncgen_fixture_wrapper.<locals>.setup at 0x7f96e9b66560>
[task 2023-04-02T12:01:14.749Z] 12:01:14     INFO - 
[task 2023-04-02T12:01:14.749Z] 12:01:14     INFO - tests/web-platform/tests/tools/third_party/pytest-asyncio/pytest_asyncio/plugin.py:293: 

Here the exact failure from the log:
https://treeherder.mozilla.org/logviewer?job_id=411120881&repo=try&lineNumber=5601-5605

[task 2023-04-02T12:00:35.555Z] 12:00:35     INFO - PID 3171 | 1680436835554	Marionette	DEBUG	Waiting for initial application window
[task 2023-04-02T12:00:37.902Z] 12:00:37     INFO - PID 3171 | ==3185==ERROR: ThreadSanitizer failed to allocate 0xff1ea5fc9000 (280507098894336) bytes at address 800006a1000 (errno: 12)
Status: NEW → RESOLVED
Closed: 2 years ago
Duplicate of bug: 1770595
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.