Open
Bug 1837900
Opened 1 year ago
Updated 1 year ago
Intermittent mozilla/tests/webdriver/bidi/session/<random> | <random> - setup error: json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0)
Categories
(Remote Protocol :: WebDriver BiDi, defect, P5)
Remote Protocol
WebDriver BiDi
Tracking
(Not tracked)
NEW
People
(Reporter: intermittent-bug-filer, Unassigned)
References
Details
(Keywords: intermittent-failure)
Filed by: nfay [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=418921100&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/Wu0_L1RBQeO6op4X7tTF1A/runs/0/artifacts/public/logs/live_backing.log
[task 2023-06-12T01:25:22.465Z] 01:25:22 INFO - TEST-START | /_mozilla/webdriver/bidi/session/new/first_match.py
[task 2023-06-12T01:25:22.511Z] 01:25:22 INFO - STDOUT: ============================= test session starts ==============================
[task 2023-06-12T01:25:22.511Z] 01:25:22 INFO - STDOUT: platform linux -- Python 3.7.5, pytest-7.0.1, pluggy-unknown -- /builds/worker/workspace/build/venv/bin/python
[task 2023-06-12T01:25:22.512Z] 01:25:22 INFO - STDOUT: rootdir: /builds/worker/workspace/build
[task 2023-06-12T01:25:22.513Z] 01:25:22 INFO - STDOUT: plugins: asyncio-0.19.0
[task 2023-06-12T01:25:22.513Z] 01:25:22 INFO - STDOUT: asyncio: mode=strict
[task 2023-06-12T01:25:22.514Z] 01:25:22 INFO - STDOUT: collecting ...
[task 2023-06-12T01:25:22.519Z] 01:25:22 INFO - STDOUT: collected 12 items
[task 2023-06-12T01:25:22.520Z] 01:25:22 INFO - STDOUT: tests/web-platform/mozilla/tests/webdriver/bidi/session/new/first_match.py::test_valid[acceptInsecureCerts-False]
[task 2023-06-12T01:25:22.869Z] 01:25:22 INFO - STDOUT: ATTENTION: default value of option mesa_glthread overridden by environment.
[task 2023-06-12T01:25:22.880Z] 01:25:22 INFO - STDOUT: ATTENTION: default value of option mesa_glthread overridden by environment.
[task 2023-06-12T01:25:24.198Z] 01:25:24 INFO - STDOUT: 1686533124196 RemoteAgent DEBUG WebDriver BiDi enabled
[task 2023-06-12T01:25:24.199Z] 01:25:24 INFO - STDOUT: 1686533124197 RemoteAgent DEBUG CDP enabled
[task 2023-06-12T01:25:24.199Z] 01:25:24 INFO - STDOUT: 1686533124197 RemoteAgent TRACE Received observer notification final-ui-startup
[task 2023-06-12T01:25:24.311Z] 01:25:24 INFO - STDOUT: 1686533124309 RemoteAgent TRACE Available local IP addresses: 127.0.0.1, [::1]
[task 2023-06-12T01:25:24.315Z] 01:25:24 INFO - STDOUT: WebDriver BiDi listening on ws://127.0.0.1:35643
[task 2023-06-12T01:25:24.316Z] 01:25:24 INFO - STDOUT: 1686533124315 CDP DEBUG Waiting for initial application window
[task 2023-06-12T01:25:24.340Z] 01:25:24 INFO - STDOUT: console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-06-12T01:25:24.340Z] 01:25:24 INFO - STDOUT: console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-06-12T01:25:24.460Z] 01:25:24 INFO - STDOUT: 1686533124458 RemoteAgent INFO Perform WebSocket upgrade for incoming connection from 127.0.0.1:53744
[task 2023-06-12T01:25:24.555Z] 01:25:24 INFO - STDOUT: 1686533124553 RemoteAgent DEBUG WebDriverBiDiConnection fbac2f30-41df-4822-b01f-9b58de4162e7 accepted
[task 2023-06-12T01:25:24.556Z] 01:25:24 INFO - STDOUT: 1686533124554 RemoteAgent DEBUG WebDriverBiDiConnection fbac2f30-41df-4822-b01f-9b58de4162e7 -> {"id":1,"method":"session.new","params":{"capabilities":{"firstMatch":[{"moz:firefoxOptions":{"args":["--profile","/tmp/tmpet91rx8j.mozrunner"]},"acceptInsecureCerts":false}]}}}
[task 2023-06-12T01:25:24.561Z] 01:25:24 INFO - STDOUT: 1686533124560 WebDriver BiDi DEBUG Connection fbac2f30-41df-4822-b01f-9b58de4162e7 attached to session 4a1db6f7-da46-4f01-ac5c-f8897a438713
[task 2023-06-12T01:25:24.561Z] 01:25:24 INFO - STDOUT: 1686533124560 WebDriver BiDi DEBUG Waiting for initial application window
[task 2023-06-12T01:25:24.888Z] 01:25:24 INFO - STDOUT: console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-06-12T01:25:26.604Z] 01:25:26 INFO - STDOUT: console.error: ({})
[task 2023-06-12T01:25:26.729Z] 01:25:26 INFO - STDOUT: console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-06-12T01:25:26.762Z] 01:25:26 INFO - STDOUT: console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-06-12T01:25:26.764Z] 01:25:26 INFO - STDOUT: console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-06-12T01:25:26.806Z] 01:25:26 INFO - STDOUT: console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-06-12T01:25:26.864Z] 01:25:26 INFO - STDOUT: console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-06-12T01:25:26.979Z] 01:25:26 INFO - STDOUT: console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-06-12T01:25:27.163Z] 01:25:27 INFO - STDOUT: console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-06-12T01:25:27.411Z] 01:25:27 INFO - STDOUT: console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-06-12T01:25:27.413Z] 01:25:27 INFO - STDOUT: console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-06-12T01:25:27.415Z] 01:25:27 INFO - STDOUT: console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-06-12T01:25:27.593Z] 01:25:27 INFO - STDOUT: 1686533127592 RemoteAgent TRACE Received observer notification browser-idle-startup-tasks-finished
[task 2023-06-12T01:25:27.608Z] 01:25:27 INFO - STDOUT: 1686533127607 WebDriver BiDi DEBUG Registered session handler: /session/4a1db6f7-da46-4f01-ac5c-f8897a438713
[task 2023-06-12T01:25:27.612Z] 01:25:27 INFO - STDOUT: PASSED
<...>
[task 2023-06-12T01:26:16.594Z] 01:26:16 INFO - STDOUT: keep_browser = False
[task 2023-06-12T01:26:16.595Z] 01:26:16 INFO - STDOUT: keep_browser_open = False
[task 2023-06-12T01:26:16.595Z] 01:26:16 INFO - STDOUT: server_host = None
[task 2023-06-12T01:26:16.596Z] 01:26:16 INFO - STDOUT: server_port = None
[task 2023-06-12T01:26:16.596Z] 01:26:16 INFO - STDOUT: tests/web-platform/tests/tools/webdriver/webdriver/bidi/client.py
[task 2023-06-12T01:26:16.597Z] 01:26:16 INFO - STDOUT: :145: in start
[task 2023-06-12T01:26:16.597Z] 01:26:16 INFO - STDOUT: await self.transport.start()
[task 2023-06-12T01:26:16.598Z] 01:26:16 INFO - STDOUT: loop = <_UnixSelectorEventLoop running=False closed=False debug=False>
[task 2023-06-12T01:26:16.598Z] 01:26:16 INFO - STDOUT: self = <webdriver.bidi.client.BidiSession object at 0x7f7148421f10>
[task 2023-06-12T01:26:16.599Z] 01:26:16 INFO - STDOUT: tests/web-platform/tests/tools/webdriver/webdriver/bidi/transport.py
[task 2023-06-12T01:26:16.599Z] 01:26:16 INFO - STDOUT: :40: in start
[task 2023-06-12T01:26:16.600Z] 01:26:16 INFO - STDOUT: self.connection = await websockets.connect(self.url) # type: ignore
[task 2023-06-12T01:26:16.600Z] 01:26:16 INFO - STDOUT: self = <webdriver.bidi.transport.Transport object at 0x7f7148421310>
[task 2023-06-12T01:26:16.601Z] 01:26:16 INFO - STDOUT: tests/web-platform/tests/tools/third_party/websockets/src/websockets/client.py
[task 2023-06-12T01:26:16.602Z] 01:26:16 INFO - STDOUT: :415: in __init__
[task 2023-06-12T01:26:16.602Z] 01:26:16 INFO - STDOUT: wsuri = parse_uri(uri)
[task 2023-06-12T01:26:16.602Z] 01:26:16 INFO - STDOUT: close_timeout = 10
[task 2023-06-12T01:26:16.603Z] 01:26:16 INFO - STDOUT: compression = 'deflate'
[task 2023-06-12T01:26:16.603Z] 01:26:16 INFO - STDOUT: create_protocol = <class 'websockets.client.WebSocketClientProtocol'>
[task 2023-06-12T01:26:16.604Z] 01:26:16 INFO - STDOUT: extensions = None
[task 2023-06-12T01:26:16.605Z] 01:26:16 INFO - STDOUT: extra_headers = None
[task 2023-06-12T01:26:16.606Z] 01:26:16 INFO - STDOUT: klass = <class 'websockets.client.WebSocketClientProtocol'>
[task 2023-06-12T01:26:16.606Z] 01:26:16 INFO - STDOUT: kwargs = {}
[task 2023-06-12T01:26:16.606Z] 01:26:16 INFO - STDOUT: legacy_recv = False
[task 2023-06-12T01:26:16.607Z] 01:26:16 INFO - STDOUT: loop = <_UnixSelectorEventLoop running=False closed=False debug=False>
[task 2023-06-12T01:26:16.607Z] 01:26:16 INFO - STDOUT: max_queue = 32
[task 2023-06-12T01:26:16.608Z] 01:26:16 INFO - STDOUT: max_size = 1048576
[task 2023-06-12T01:26:16.608Z] 01:26:16 INFO - STDOUT: origin = None
[task 2023-06-12T01:26:16.609Z] 01:26:16 INFO - STDOUT: path = None
[task 2023-06-12T01:26:16.610Z] 01:26:16 INFO - STDOUT: ping_interval = 20
[task 2023-06-12T01:26:16.610Z] 01:26:16 INFO - STDOUT: ping_timeout = 20
[task 2023-06-12T01:26:16.611Z] 01:26:16 INFO - STDOUT: read_limit = 65536
[task 2023-06-12T01:26:16.611Z] 01:26:16 INFO - STDOUT: self = <websockets.client.Connect object at 0x7f7148421390>
[task 2023-06-12T01:26:16.612Z] 01:26:16 INFO - STDOUT: subprotocols = None
[task 2023-06-12T01:26:16.613Z] 01:26:16 INFO - STDOUT: timeout = 10
[task 2023-06-12T01:26:16.613Z] 01:26:16 INFO - STDOUT: uri = 'ws://None:None/session'
[task 2023-06-12T01:26:16.614Z] 01:26:16 INFO - STDOUT: write_limit = 65536
[task 2023-06-12T01:26:16.614Z] 01:26:16 INFO - STDOUT: tests/web-platform/tests/tools/third_party/websockets/src/websockets/uri.py
[task 2023-06-12T01:26:16.615Z] 01:26:16 INFO - STDOUT: :70: in parse_uri
[task 2023-06-12T01:26:16.615Z] 01:26:16 INFO - STDOUT: port = parsed.port or (443 if secure else 80)
[task 2023-06-12T01:26:16.616Z] 01:26:16 INFO - STDOUT: host = 'none'
[task 2023-06-12T01:26:16.617Z] 01:26:16 INFO - STDOUT: parsed = ParseResult(scheme='ws', netloc='None:None', path='/session', params='', query='', fragment='')
[task 2023-06-12T01:26:16.617Z] 01:26:16 INFO - STDOUT: secure = False
[task 2023-06-12T01:26:16.618Z] 01:26:16 INFO - STDOUT: uri = 'ws://None:None/session'
[task 2023-06-12T01:26:16.618Z] 01:26:16 INFO - STDOUT: _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
[task 2023-06-12T01:26:16.619Z] 01:26:16 INFO - STDOUT: self = ParseResult(scheme='ws', netloc='None:None', path='/session', params='', query='', fragment='')
[task 2023-06-12T01:26:16.620Z] 01:26:16 INFO - STDOUT: @property
[task 2023-06-12T01:26:16.620Z] 01:26:16 INFO - STDOUT: def port(self):
[task 2023-06-12T01:26:16.621Z] 01:26:16 INFO - STDOUT: port = self._hostinfo[1]
[task 2023-06-12T01:26:16.621Z] 01:26:16 INFO - STDOUT: if port is not None:
[task 2023-06-12T01:26:16.622Z] 01:26:16 INFO - STDOUT: > port = int(port, 10)
[task 2023-06-12T01:26:16.622Z] 01:26:16 INFO - STDOUT: E ValueError: invalid literal for int() with base 10: 'None'
[task 2023-06-12T01:26:16.623Z] 01:26:16 INFO - STDOUT: port = 'None'
[task 2023-06-12T01:26:16.624Z] 01:26:16 INFO - STDOUT: self = ParseResult(scheme='ws', netloc='None:None', path='/session', params='', query='', fragment='')
[task 2023-06-12T01:26:16.624Z] 01:26:16 INFO - STDOUT: /usr/lib/python3.7/urllib/parse.py
[task 2023-06-12T01:26:16.625Z] 01:26:16 INFO - STDOUT: :169: ValueError
[task 2023-06-12T01:26:16.625Z] 01:26:16 INFO - STDOUT: =========================== short test summary info ============================
[task 2023-06-12T01:26:16.626Z] 01:26:16 INFO - STDOUT: FAILED tests/web-platform/mozilla/tests/webdriver/bidi/session/new/first_match.py::test_valid[test:extension-None]
[task 2023-06-12T01:26:16.627Z] 01:26:16 INFO - STDOUT: ERROR tests/web-platform/mozilla/tests/webdriver/bidi/session/new/first_match.py::test_valid[proxy-None]
[task 2023-06-12T01:26:16.627Z] 01:26:16 INFO - STDOUT: ==================== 1 failed, 10 passed, 1 error in 53.99s ====================
[task 2023-06-12T01:26:16.648Z] 01:26:16 INFO -
[task 2023-06-12T01:26:16.648Z] 01:26:16 INFO - TEST-PASS | /_mozilla/webdriver/bidi/session/new/first_match.py | test_valid[acceptInsecureCerts-False]
[task 2023-06-12T01:26:16.648Z] 01:26:16 INFO - TEST-PASS | /_mozilla/webdriver/bidi/session/new/first_match.py | test_valid[acceptInsecureCerts-None]
[task 2023-06-12T01:26:16.648Z] 01:26:16 INFO - TEST-PASS | /_mozilla/webdriver/bidi/session/new/first_match.py | test_valid[browserName-None]
[task 2023-06-12T01:26:16.648Z] 01:26:16 INFO - TEST-PASS | /_mozilla/webdriver/bidi/session/new/first_match.py | test_valid[browserVersion-None]
[task 2023-06-12T01:26:16.649Z] 01:26:16 INFO - TEST-PASS | /_mozilla/webdriver/bidi/session/new/first_match.py | test_valid[platformName-None]
[task 2023-06-12T01:26:16.649Z] 01:26:16 INFO - TEST-UNEXPECTED-ERROR | /_mozilla/webdriver/bidi/session/new/first_match.py | test_valid[proxy-None] - setup error: json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0)
[task 2023-06-12T01:26:16.649Z] 01:26:16 INFO - event_loop = <_UnixSelectorEventLoop running=False closed=False debug=False>
[task 2023-06-12T01:26:16.649Z] 01:26:16 INFO - request = <SubRequest 'new_session' for <Function test_valid[proxy-None]>>
[task 2023-06-12T01:26:16.649Z] 01:26:16 INFO - kwargs = {'browser': <function browser.<locals>._browser at 0x7f71487b6dd0>}
[task 2023-06-12T01:26:16.649Z] 01:26:16 INFO - setup = <function _wrap_asyncgen.<locals>._asyncgen_fixture_wrapper.<locals>.setup at 0x7f714852bdd0>
[task 2023-06-12T01:26:16.649Z] 01:26:16 INFO - finalizer = <function _wrap_asyncgen.<locals>._asyncgen_fixture_wrapper.<locals>.finalizer at 0x7f714852b440>
[task 2023-06-12T01:26:16.649Z] 01:26:16 INFO -
[task 2023-06-12T01:26:16.649Z] 01:26:16 INFO - @functools.wraps(func)
[task 2023-06-12T01:26:16.649Z] 01:26:16 INFO - def _asyncgen_fixture_wrapper(
[task 2023-06-12T01:26:16.649Z] 01:26:16 INFO - event_loop: asyncio.AbstractEventLoop, request: SubRequest, **kwargs: Any
[task 2023-06-12T01:26:16.650Z] 01:26:16 INFO - ) -> _R:
[task 2023-06-12T01:26:16.650Z] 01:26:16 INFO - gen_obj = func(**_add_kwargs(func, kwargs, event_loop, request))
[task 2023-06-12T01:26:16.650Z] 01:26:16 INFO -
[task 2023-06-12T01:26:16.650Z] 01:26:16 INFO - async def setup() -> _R:
[task 2023-06-12T01:26:16.650Z] 01:26:16 INFO - res = await gen_obj.__anext__()
[task 2023-06-12T01:26:16.650Z] 01:26:16 INFO - return res
[task 2023-06-12T01:26:16.650Z] 01:26:16 INFO -
[task 2023-06-12T01:26:16.650Z] 01:26:16 INFO - def finalizer() -> None:
[task 2023-06-12T01:26:16.650Z] 01:26:16 INFO - """Yield again, to finalize."""
[task 2023-06-12T01:26:16.650Z] 01:26:16 INFO -
[task 2023-06-12T01:26:16.650Z] 01:26:16 INFO - async def async_finalizer() -> None:
[task 2023-06-12T01:26:16.651Z] 01:26:16 INFO - try:
[task 2023-06-12T01:26:16.651Z] 01:26:16 INFO - await gen_obj.__anext__()
[task 2023-06-12T01:26:16.651Z] 01:26:16 INFO - except StopAsyncIteration:
[task 2023-06-12T01:26:16.651Z] 01:26:16 INFO - pass
[task 2023-06-12T01:26:16.651Z] 01:26:16 INFO - else:
[task 2023-06-12T01:26:16.651Z] 01:26:16 INFO - msg = "Async generator fixture didn't stop."
[task 2023-06-12T01:26:16.651Z] 01:26:16 INFO - msg += "Yield only once."
[task 2023-06-12T01:26:16.651Z] 01:26:16 INFO - raise ValueError(msg)
[task 2023-06-12T01:26:16.652Z] 01:26:16 INFO -
[task 2023-06-12T01:26:16.652Z] 01:26:16 INFO - event_loop.run_until_complete(async_finalizer())
[task 2023-06-12T01:26:16.652Z] 01:26:16 INFO -
[task 2023-06-12T01:26:16.652Z] 01:26:16 INFO - > result = event_loop.run_until_complete(setup())
[task 2023-06-12T01:26:16.652Z] 01:26:16 INFO -
[task 2023-06-12T01:26:16.652Z] 01:26:16 INFO - event_loop = <_UnixSelectorEventLoop running=False closed=False debug=False>
[task 2023-06-12T01:26:16.652Z] 01:26:16 INFO - finalizer = <function _wrap_asyncgen.<locals>._asyncgen_fixture_wrapper.<locals>.finalizer at 0x7f714852b440>
[task 2023-06-12T01:26:16.652Z] 01:26:16 INFO - func = <function new_session at 0x7f714a073290>
[task 2023-06-12T01:26:16.652Z] 01:26:16 INFO - gen_obj = <async_generator object new_session at 0x7f714852b680>
[task 2023-06-12T01:26:16.652Z] 01:26:16 INFO - kwargs = {'browser': <function browser.<locals>._browser at 0x7f71487b6dd0>}
[task 2023-06-12T01:26:16.653Z] 01:26:16 INFO - request = <SubRequest 'new_session' for <Function test_valid[proxy-None]>>
[task 2023-06-12T01:26:16.653Z] 01:26:16 INFO - setup = <function _wrap_asyncgen.<locals>._asyncgen_fixture_wrapper.<locals>.setup at 0x7f714852bdd0>
[task 2023-06-12T01:26:16.653Z] 01:26:16 INFO -
[task 2023-06-12T01:26:16.653Z] 01:26:16 INFO - tests/web-platform/tests/tools/third_party/pytest-asyncio/pytest_asyncio/plugin.py:293:
Comment 1•1 year ago
|
||
Sadly it's not clear what's happening here. This is not much detail in the log to see what actually was failing or has been returned:
https://treeherder.mozilla.org/logviewer?job_id=418921100&repo=autoland&lineNumber=165459-165468
Note that this is a new test as introduced by the landing of the patches on bug 1731730.
Depends on: 1731730
Updated•1 year ago
|
Summary: Intermittent mozilla/tests/webdriver/bidi/session/new/first_match.py | test_valid[proxy-None] - setup error: json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0) → Intermittent mozilla/tests/webdriver/bidi/session/new/<random> | <random> - setup error: json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0)
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Updated•1 year ago
|
Summary: Intermittent mozilla/tests/webdriver/bidi/session/new/<random> | <random> - setup error: json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0) → Intermittent mozilla/tests/webdriver/bidi/session/<random> | <random> - setup error: json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0)
You need to log in
before you can comment on or make changes to this bug.
Description
•