Closed
Bug 1838331
Opened 1 year ago
Closed 1 year ago
Intermittent Mn, Wd | "unknown error" (500): Failed to decode response from marionette or "no such window" (404): Browsing context has been discarded [ConnectNamedPipe timed out]
Categories
(Remote Protocol :: Marionette, defect, P5)
Remote Protocol
Marionette
Tracking
(Not tracked)
RESOLVED
WORKSFORME
People
(Reporter: intermittent-bug-filer, Unassigned)
References
Details
(Keywords: intermittent-failure)
Filed by: sstanca [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=419180702&repo=mozilla-beta
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/BoL-ot2oQEWQXm_gXgwu-A/runs/0/artifacts/public/logs/live_backing.log
[task 2023-06-13T21:02:55.189Z] 21:02:55 INFO - TEST-PASS | /webdriver/tests/classic/refresh/user_prompts.py | test_accept[capabilities0-prompt]
[task 2023-06-13T21:02:55.189Z] 21:02:55 INFO - TEST-UNEXPECTED-ERROR | /webdriver/tests/classic/refresh/user_prompts.py | test_accept_and_notify[capabilities0-alert-None] - setup error: webdriver.error.UnknownErrorException: unknown error (500): Failed to decode response from marionette
[task 2023-06-13T21:02:55.189Z] 21:02:55 INFO - event_loop = <ProactorEventLoop running=False closed=False debug=False>
[task 2023-06-13T21:02:55.189Z] 21:02:55 INFO - request = <SubRequest 'session' for <Function test_accept_and_notify[capabilities0-alert-None]>>
[task 2023-06-13T21:02:55.189Z] 21:02:55 INFO - kwargs = {'capabilities': {'unhandledPromptBehavior': 'accept and notify'}, 'configuration': {'browser': {'args': ['--profile',...Users\\task_168668678821791\\AppData\\Local\\Temp\\tmpe38tkygi.mozrunner']}}, 'host': '127.0.0.1', 'port': 59874, ...}}
[task 2023-06-13T21:02:55.189Z] 21:02:55 INFO - setup = <function _wrap_asyncgen.<locals>._asyncgen_fixture_wrapper.<locals>.setup at 0x0000020CDBC76AF0>
[task 2023-06-13T21:02:55.189Z] 21:02:55 INFO - finalizer = <function _wrap_asyncgen.<locals>._asyncgen_fixture_wrapper.<locals>.finalizer at 0x0000020CDBC76040>
[task 2023-06-13T21:02:55.189Z] 21:02:55 INFO -
[task 2023-06-13T21:02:55.189Z] 21:02:55 INFO - @functools.wraps(func)
[task 2023-06-13T21:02:55.189Z] 21:02:55 INFO - def _asyncgen_fixture_wrapper(
[task 2023-06-13T21:02:55.189Z] 21:02:55 INFO - event_loop: asyncio.AbstractEventLoop, request: SubRequest, **kwargs: Any
[task 2023-06-13T21:02:55.189Z] 21:02:55 INFO - ) -> _R:
[task 2023-06-13T21:02:55.189Z] 21:02:55 INFO - gen_obj = func(**_add_kwargs(func, kwargs, event_loop, request))
[task 2023-06-13T21:02:55.189Z] 21:02:55 INFO -
[task 2023-06-13T21:02:55.189Z] 21:02:55 INFO - async def setup() -> _R:
[task 2023-06-13T21:02:55.189Z] 21:02:55 INFO - res = await gen_obj.__anext__()
[task 2023-06-13T21:02:55.189Z] 21:02:55 INFO - return res
[task 2023-06-13T21:02:55.189Z] 21:02:55 INFO -
[task 2023-06-13T21:02:55.189Z] 21:02:55 INFO - def finalizer() -> None:
[task 2023-06-13T21:02:55.189Z] 21:02:55 INFO - """Yield again, to finalize."""
[task 2023-06-13T21:02:55.189Z] 21:02:55 INFO -
[task 2023-06-13T21:02:55.189Z] 21:02:55 INFO - async def async_finalizer() -> None:
[task 2023-06-13T21:02:55.189Z] 21:02:55 INFO - try:
[task 2023-06-13T21:02:55.189Z] 21:02:55 INFO - await gen_obj.__anext__()
[task 2023-06-13T21:02:55.189Z] 21:02:55 INFO - except StopAsyncIteration:
[task 2023-06-13T21:02:55.189Z] 21:02:55 INFO - pass
[task 2023-06-13T21:02:55.189Z] 21:02:55 INFO - else:
[task 2023-06-13T21:02:55.190Z] 21:02:55 INFO - msg = "Async generator fixture didn't stop."
[task 2023-06-13T21:02:55.190Z] 21:02:55 INFO - msg += "Yield only once."
[task 2023-06-13T21:02:55.190Z] 21:02:55 INFO - raise ValueError(msg)
[task 2023-06-13T21:02:55.190Z] 21:02:55 INFO -
[task 2023-06-13T21:02:55.190Z] 21:02:55 INFO - event_loop.run_until_complete(async_finalizer())
[task 2023-06-13T21:02:55.190Z] 21:02:55 INFO -
[task 2023-06-13T21:02:55.190Z] 21:02:55 INFO - > result = event_loop.run_until_complete(setup())
[task 2023-06-13T21:02:55.190Z] 21:02:55 INFO -
[task 2023-06-13T21:02:55.190Z] 21:02:55 INFO - event_loop = <ProactorEventLoop running=False closed=False debug=False>
[task 2023-06-13T21:02:55.190Z] 21:02:55 INFO - finalizer = <function _wrap_asyncgen.<locals>._asyncgen_fixture_wrapper.<locals>.finalizer at 0x0000020CDBC76040>
[task 2023-06-13T21:02:55.190Z] 21:02:55 INFO - func = <function session at 0x0000020CDBB0E550>
[task 2023-06-13T21:02:55.190Z] 21:02:55 INFO - gen_obj = <async_generator object session at 0x0000020CDBC768B0>
[task 2023-06-13T21:02:55.190Z] 21:02:55 INFO - kwargs = {'capabilities': {'unhandledPromptBehavior': 'accept and notify'},
[task 2023-06-13T21:02:55.190Z] 21:02:55 INFO - 'configuration': {'browser': {'args': ['--profile',
[task 2023-06-13T21:02:55.190Z] 21:02:55 INFO - 'C:\\Users\\task_168668678821791\\AppData\\Local\\Temp\\tmpe38tkygi.mozrunner'],
[task 2023-06-13T21:02:55.190Z] 21:02:55 INFO - 'binary': 'Z:\\task_168668678821791\\build\\application\\firefox\\firefox.exe'},
[task 2023-06-13T21:02:55.190Z] 21:02:55 INFO - 'capabilities': {'moz:firefoxOptions': {'args': ['--profile',
[task 2023-06-13T21:02:55.190Z] 21:02:55 INFO - 'C:\\Users\\task_168668678821791\\AppData\\Local\\Temp\\tmpe38tkygi.mozrunner']}},
[task 2023-06-13T21:02:55.190Z] 21:02:55 INFO - 'host': '127.0.0.1',
[task 2023-06-13T21:02:55.190Z] 21:02:55 INFO - 'port': 59874,
[task 2023-06-13T21:02:55.190Z] 21:02:55 INFO - 'timeout_multiplier': 3,
[task 2023-06-13T21:02:55.191Z] 21:02:55 INFO - 'webdriver': {'args': ['-vv',
[task 2023-06-13T21:02:55.191Z] 21:02:55 INFO - '--binary',
[task 2023-06-13T21:02:55.191Z] 21:02:55 INFO - 'Z:\\task_168668678821791\\build\\application\\firefox\\firefox.exe'],
[task 2023-06-13T21:02:55.191Z] 21:02:55 INFO - 'binary': 'Z:\\task_168668678821791\\fetches\\geckodriver.exe'}}}
[task 2023-06-13T21:02:55.191Z] 21:02:55 INFO - request = <SubRequest 'session' for <Function test_accept_and_notify[capabilities0-alert-None]>>
[task 2023-06-13T21:02:55.191Z] 21:02:55 INFO - setup = <function _wrap_asyncgen.<locals>._asyncgen_fixture_wrapper.<locals>.setup at 0x0000020CDBC76AF0>
[task 2023-06-13T21:02:55.192Z] 21:02:55 INFO -
[task 2023-06-13T21:02:55.192Z] 21:02:55 INFO - tests\web-platform\tests\tools\third_party\pytest-asyncio\pytest_asyncio\plugin.py:293:
[task 2023-06-13T21:02:55.192Z] 21:02:55 INFO - _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
[task 2023-06-13T21:02:55.192Z] 21:02:55 INFO - c:\mozilla-build\python3\lib\asyncio\base_events.py:642: in run_until_complete
[task 2023-06-13T21:02:55.192Z] 21:02:55 INFO - return future.result()
[task 2023-06-13T21:02:55.192Z] 21:02:55 INFO - future = <Task finished name='Task-21' coro=<_wrap_asyncgen.<locals>._asyncgen_fixture_wrapper.<locals>.setup() done, defined at Z:\task_168668678821791\build\tests\web-platform\tests\tools\third_party\pytest-asyncio\pytest_asyncio\plugin.py:274> exception=<UnknownErrorException http_status=500>>
[task 2023-06-13T21:02:55.192Z] 21:02:55 INFO - new_task = True
[task 2023-06-13T21:02:55.192Z] 21:02:55 INFO - self = <ProactorEventLoop running=False closed=False debug=False>
[task 2023-06-13T21:02:55.192Z] 21:02:55 INFO - tests\web-platform\tests\tools\third_party\pytest-asyncio\pytest_asyncio\plugin.py:275: in setup
[task 2023-06-13T21:02:55.192Z] 21:02:55 INFO - res = await gen_obj.__anext__()
[task 2023-06-13T21:02:55.192Z] 21:02:55 INFO - gen_obj = <async_generator object session at 0x0000020CDBC768B0>
[task 2023-06-13T21:02:55.192Z] 21:02:55 INFO - tests\web-platform\tests\webdriver\tests\support\fixtures.py:136: in session
[task 2023-06-13T21:02:55.192Z] 21:02:55 INFO - _current_session.start()
[task 2023-06-13T21:02:55.192Z] 21:02:55 INFO - capabilities = {'unhandledPromptBehavior': 'accept and notify'}
[task 2023-06-13T21:02:55.192Z] 21:02:55 INFO - caps = {'alwaysMatch': {'moz:firefoxOptions': {'args': ['--profile',
[task 2023-06-13T21:02:55.192Z] 21:02:55 INFO - 'C:\\Users\\task_168668678821791\\AppData\\Local\\Temp\\tmpe38tkygi.mozrunner']},
[task 2023-06-13T21:02:55.192Z] 21:02:55 INFO - 'unhandledPromptBehavior': 'accept and notify'}}
[task 2023-06-13T21:02:55.192Z] 21:02:55 INFO - configuration = {'browser': {'args': ['--profile',
[task 2023-06-13T21:02:55.193Z] 21:02:55 INFO - 'C:\\Users\\task_168668678821791\\AppData\\Local\\Temp\\tmpe38tkygi.mozrunner'],
[task 2023-06-13T21:02:55.193Z] 21:02:55 INFO - 'binary': 'Z:\\task_168668678821791\\build\\application\\firefox\\firefox.exe'},
[task 2023-06-13T21:02:55.193Z] 21:02:55 INFO - 'capabilities': {'moz:firefoxOptions': {'args': ['--profile',
[task 2023-06-13T21:02:55.193Z] 21:02:55 INFO - 'C:\\Users\\task_168668678821791\\AppData\\Local\\Temp\\tmpe38tkygi.mozrunner']}},
[task 2023-06-13T21:02:55.193Z] 21:02:55 INFO - 'host': '127.0.0.1',
[task 2023-06-13T21:02:55.193Z] 21:02:55 INFO - 'port': 59874,
[task 2023-06-13T21:02:55.193Z] 21:02:55 INFO - 'timeout_multiplier': 3,
[task 2023-06-13T21:02:55.193Z] 21:02:55 INFO - 'webdriver': {'args': ['-vv',
[task 2023-06-13T21:02:55.193Z] 21:02:55 INFO - '--binary',
[task 2023-06-13T21:02:55.193Z] 21:02:55 INFO - 'Z:\\task_168668678821791\\build\\application\\firefox\\firefox.exe'],
[task 2023-06-13T21:02:55.193Z] 21:02:55 INFO - 'binary': 'Z:\\task_168668678821791\\fetches\\geckodriver.exe'}}
[task 2023-06-13T21:02:55.193Z] 21:02:55 INFO - tests\web-platform\tests\tools\webdriver\webdriver\client.py:558: in start
[task 2023-06-13T21:02:55.193Z] 21:02:55 INFO - value = self.send_command("POST", "session", body=body)
[task 2023-06-13T21:02:55.193Z] 21:02:55 INFO - body = {'capabilities': {'alwaysMatch': {'moz:firefoxOptions': {'args': ['--profile',
[task 2023-06-13T21:02:55.193Z] 21:02:55 INFO - 'C:\\Users\\task_168668678821791\\AppData\\Local\\Temp\\tmpe38tkygi.mozrunner']},
[task 2023-06-13T21:02:55.193Z] 21:02:55 INFO - 'unhandledPromptBehavior': 'accept and '
[task 2023-06-13T21:02:55.193Z] 21:02:55 INFO - 'notify'}}}
[task 2023-06-13T21:02:55.194Z] 21:02:55 INFO - self = <Session (disconnected)>
[task 2023-06-13T21:02:55.194Z] 21:02:55 INFO - _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
[task 2023-06-13T21:02:55.194Z] 21:02:55 INFO -
[task 2023-06-13T21:02:55.194Z] 21:02:55 INFO - self = <Session (disconnected)>, method = 'POST', url = 'session'
[task 2023-06-13T21:02:55.194Z] 21:02:55 INFO - body = {'capabilities': {'alwaysMatch': {'moz:firefoxOptions': {'args': ['--profile', 'C:\\Users\\task_168668678821791\\AppData\\Local\\Temp\\tmpe38tkygi.mozrunner']}, 'unhandledPromptBehavior': 'accept and notify'}}}
[task 2023-06-13T21:02:55.194Z] 21:02:55 INFO - timeout = None
[task 2023-06-13T21:02:55.194Z] 21:02:55 INFO -
[task 2023-06-13T21:02:55.194Z] 21:02:55 INFO - def send_command(self, method, url, body=None, timeout=None):
[task 2023-06-13T21:02:55.194Z] 21:02:55 INFO - """
[task 2023-06-13T21:02:55.194Z] 21:02:55 INFO - Send a command to the remote end and validate its success.
[task 2023-06-13T21:02:55.194Z] 21:02:55 INFO -
[task 2023-06-13T21:02:55.194Z] 21:02:55 INFO - :param method: HTTP method to use in request.
[task 2023-06-13T21:02:55.194Z] 21:02:55 INFO - :param uri: "Command part" of the HTTP request URL,
[task 2023-06-13T21:02:55.194Z] 21:02:55 INFO - e.g. `window/rect`.
[task 2023-06-13T21:02:55.194Z] 21:02:55 INFO - :param body: Optional body of the HTTP request.
[task 2023-06-13T21:02:55.194Z] 21:02:55 INFO -
[task 2023-06-13T21:02:55.194Z] 21:02:55 INFO - :return: `None` if the HTTP response body was empty, otherwise
[task 2023-06-13T21:02:55.195Z] 21:02:55 INFO - the `value` field returned after parsing the response
[task 2023-06-13T21:02:55.195Z] 21:02:55 INFO - body as JSON.
[task 2023-06-13T21:02:55.195Z] 21:02:55 INFO -
[task 2023-06-13T21:02:55.195Z] 21:02:55 INFO - :raises error.WebDriverException: If the remote end returns
[task 2023-06-13T21:02:55.195Z] 21:02:55 INFO - an error.
[task 2023-06-13T21:02:55.195Z] 21:02:55 INFO - :raises ValueError: If the response body does not contain a
[task 2023-06-13T21:02:55.195Z] 21:02:55 INFO - `value` key.
[task 2023-06-13T21:02:55.195Z] 21:02:55 INFO - """
[task 2023-06-13T21:02:55.195Z] 21:02:55 INFO -
[task 2023-06-13T21:02:55.195Z] 21:02:55 INFO - response = self.transport.send(
[task 2023-06-13T21:02:55.195Z] 21:02:55 INFO - method, url, body,
[task 2023-06-13T21:02:55.195Z] 21:02:55 INFO - encoder=protocol.Encoder, decoder=protocol.Decoder,
[task 2023-06-13T21:02:55.195Z] 21:02:55 INFO - session=self, timeout=timeout)
[task 2023-06-13T21:02:55.195Z] 21:02:55 INFO -
[task 2023-06-13T21:02:55.195Z] 21:02:55 INFO - if response.status != 200:
[task 2023-06-13T21:02:55.195Z] 21:02:55 INFO - err = error.from_response(response)
[task 2023-06-13T21:02:55.196Z] 21:02:55 INFO -
[task 2023-06-13T21:02:55.196Z] 21:02:55 INFO - if isinstance(err, error.InvalidSessionIdException):
[task 2023-06-13T21:02:55.196Z] 21:02:55 INFO - # The driver could have already been deleted the session.
[task 2023-06-13T21:02:55.196Z] 21:02:55 INFO - self.session_id = None
[task 2023-06-13T21:02:55.196Z] 21:02:55 INFO -
[task 2023-06-13T21:02:55.196Z] 21:02:55 INFO - > raise err
[task 2023-06-13T21:02:55.196Z] 21:02:55 INFO - E webdriver.error.UnknownErrorException: unknown error (500): Failed to decode response from marionette
[task 2023-06-13T21:02:55.196Z] 21:02:55 INFO -
[task 2023-06-13T21:02:55.196Z] 21:02:55 INFO - body = {'capabilities': {'alwaysMatch': {'moz:firefoxOptions': {'args': ['--profile',
[task 2023-06-13T21:02:55.196Z] 21:02:55 INFO - 'C:\\Users\\task_168668678821791\\AppData\\Local\\Temp\\tmpe38tkygi.mozrunner']},
[task 2023-06-13T21:02:55.196Z] 21:02:55 INFO - 'unhandledPromptBehavior': 'accept and '
[task 2023-06-13T21:02:55.196Z] 21:02:55 INFO - 'notify'}}}
[task 2023-06-13T21:02:55.196Z] 21:02:55 INFO - err = <UnknownErrorException http_status=500>
[task 2023-06-13T21:02:55.196Z] 21:02:55 INFO - method = 'POST'
[task 2023-06-13T21:02:55.196Z] 21:02:55 INFO - response = <Response status=500 error=<UnknownErrorException http_status=500>>
[task 2023-06-13T21:02:55.196Z] 21:02:55 INFO - self = <Session (disconnected)>
[task 2023-06-13T21:02:55.196Z] 21:02:55 INFO - timeout = None
[task 2023-06-13T21:02:55.197Z] 21:02:55 INFO - url = 'session'
[task 2023-06-13T21:02:55.197Z] 21:02:55 INFO -
[task 2023-06-13T21:02:55.197Z] 21:02:55 INFO - tests\web-platform\tests\tools\webdriver\webdriver\client.py:622: UnknownErrorException
[task 2023-06-13T21:02:55.203Z] 21:02:55 INFO - ..............
[task 2023-06-13T21:02:55.203Z] 21:02:55 INFO - TEST-OK | /webdriver/tests/classic/refresh/user_prompts.py | took 58498ms
|
||
Comment 1•1 year ago
|
||
For the above failure Marionette is waiting for the initial browser window to appear but that is never happening. Instead a lot of IPC errors can be seen in the log file which finally lead the browser to quit itself 13 seconds later:
https://treeherder.mozilla.org/logviewer?job_id=419180702&repo=mozilla-beta&lineNumber=178951
Nika, do you have an idea what might have caused the self-triggered quit?
Flags: needinfo?(nika)
|
||
Comment 2•1 year ago
|
||
(In reply to Henrik Skupin [:whimboo][⌚️UTC+2] from comment #1)
For the above failure Marionette is waiting for the initial browser window to appear but that is never happening. Instead a lot of IPC errors can be seen in the log file which finally lead the browser to quit itself 13 seconds later:
https://treeherder.mozilla.org/logviewer?job_id=419180702&repo=mozilla-beta&lineNumber=178951
Nika, do you have an idea what might have caused the self-triggered quit?
The first error in the sequence is
[Parent 1712, IPC I/O Parent] WARNING: ConnectNamedPipe timed out!: file /builds/worker/checkouts/gecko/ipc/chromium/src/chrome/common/ipc_channel_win.cc:327
Which is what is fired if the content process takes too long to start up, and we end out timing out when waiting for it to connect to us. Once the content process fails to start up like that, we'll end up treating it as crashed. It appears in this case that the attempt to connect from the content process was only just barely too slow (it tried to connect at 10 seconds, which is also the timeout)
Because the browser was configured with MOZ_CRASHREPORTER_SHUTDOWN set, we'll then end up shutting down the parent process because a content process crashed:
[task 2023-06-13T21:02:17.891Z] 21:02:17 INFO - PID 9404 | A content process crashed and MOZ_CRASHREPORTER_SHUTDOWN is set, shutting down
Which explains why it quit immediately after starting up.
Flags: needinfo?(nika)
|
|
||
Comment 3•1 year ago
|
||
Ah that is a good explanation. Would it maybe make sense to have a special log entry when we explicitly kill such a content process? If MOZ_CRASHREPORTER_SHUTDOWN isn't set it would really not be observable and it's not clear that ConnectNamedPipe timed out means we trigger a crash.
Also the above triggered crash didn't produce any minidump file given that we would have detected that. Is that expected because the content process really didn't startup or is it something that needs to be fixed?
Flags: needinfo?(nika)
|
|
||
Comment 4•1 year ago
|
||
As it looks like there are also other instances of this problem resulting in a different test failure "no such window" (404): Browsing context has been discarded:
https://treeherder.mozilla.org/logviewer?job_id=419282550&repo=mozilla-beta&lineNumber=172040-172058
[task 2023-06-14T14:35:18.022Z] 14:35:18 INFO - PID 9908 | 1686753318021 Marionette DEBUG Waiting for initial application window
[task 2023-06-14T14:35:28.073Z] 14:35:28 INFO - PID 9908 | [Parent 10180, IPC I/O Parent] WARNING: ConnectNamedPipe timed out!: file /builds/worker/checkouts/gecko/ipc/chromium/src/chrome/common/ipc_channel_win.cc:327
[task 2023-06-14T14:35:31.074Z] 14:35:31 INFO - PID 9908 | [8392, IPC I/O Child] WARNING: failed to create pipe: 2: file /builds/worker/checkouts/gecko/ipc/chromium/src/chrome/common/ipc_channel_win.cc:237
[task 2023-06-14T14:35:31.075Z] 14:35:31 INFO - PID 9908 | [8392, IPC I/O Child] WARNING: Unable to create pipe named "10180.0.258293749\1038124257" in client mode.: file /builds/worker/checkouts/gecko/ipc/chromium/src/chrome/common/ipc_channel_win.cc:55
[task 2023-06-14T14:35:31.081Z] 14:35:31 INFO - PID 9908 | Exiting due to channel error.
[task 2023-06-14T14:35:31.121Z] 14:35:31 INFO - PID 9908 | [GFX1-]: RenderCompositorSWGL failed mapping default framebuffer, no dt
[task 2023-06-14T14:35:31.857Z] 14:35:31 INFO - PID 9908 | console.error: ({})
[task 2023-06-14T14:35:31.888Z] 14:35:31 INFO - PID 9908 | 1686753331888 Marionette TRACE Received observer notification browser-idle-startup-tasks-finished
[task 2023-06-14T14:35:31.892Z] 14:35:31 INFO - PID 9908 | 1686753331890 RemoteAgent TRACE [3] ProgressListener Start: expectNavigation=false resolveWhenStarted=false unloadTimeout=200 waitForExplicitStart=false
[task 2023-06-14T14:35:31.893Z] 14:35:31 INFO - PID 9908 | 1686753331891 RemoteAgent TRACE [3] ProgressListener Setting unload timer (200ms)
[task 2023-06-14T14:35:32.092Z] 14:35:32 INFO - PID 9908 | 1686753332092 RemoteAgent TRACE [3] ProgressListener No navigation detected: about:blank
[task 2023-06-14T14:35:32.095Z] 14:35:32 INFO - PID 9908 | 1686753332093 RemoteAgent TRACE [3] ProgressListener Stop: has error=false
[task 2023-06-14T14:35:32.103Z] 14:35:32 INFO - PID 9908 | 1686753332100 Marionette DEBUG 0 <- [1,1,null,{"sessionId":"5de7fb45-5c18-46d8-9b1a-51a5214a0604","capabilities":{"browserName":"firefox","browserVersion":"115.0","platformName":"windows","acceptInsecureCerts":false,"pageLoadStrategy":"normal","setWindowRect":true,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"strictFileInteractability":false,"unhandledPromptBehavior":"dismiss and notify","moz:accessibilityChecks":false,"moz:buildID":"20230614123000","moz:headless":true,"moz:platformVersion":"10.0","moz:processID":10180,"moz:profile":"C:\\Users\\task_168675076585106\\AppData\\Local\\Temp\\tmpx5lgtl9a.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true,"moz:windowless":false,"proxy":{}}}]
[task 2023-06-14T14:35:32.104Z] 14:35:32 INFO - PID 9908 | 1686753332102 webdriver::server DEBUG <- 200 OK {"value":{"sessionId":"5de7fb45-5c18-46d8-9b1a-51a5214a0604","capabilities":{"acceptInsecureCerts":false,"browserNa ... ctability":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"unhandledPromptBehavior":"dismiss and notify"}}}
[task 2023-06-14T14:35:32.106Z] 14:35:32 INFO - PID 9908 | 1686753332104 webdriver::server DEBUG -> POST /session/5de7fb45-5c18-46d8-9b1a-51a5214a0604/window/maximize {}
[task 2023-06-14T14:35:32.108Z] 14:35:32 INFO - PID 9908 | 1686753332107 Marionette DEBUG 0 -> [0,2,"WebDriver:MaximizeWindow",{}]
[task 2023-06-14T14:35:32.109Z] 14:35:32 INFO - PID 9908 | 1686753332108 Marionette DEBUG 0 <- [1,2,{"error":"no such window","message":"Browsing context has been discarded","stacktrace":"RemoteError@chrome://remote/content/shared/RemoteError.sys.mjs:8:8\nWebDriverError@chrome://remote/content/shared/webdriver/Er ... ote/content/marionette/server.sys.mjs:265:9\n_onJSONObjectReady/<@chrome://remote/content/marionette/transport.sys.mjs:496:20\n"},null]
[task 2023-06-14T14:35:32.111Z] 14:35:32 INFO - PID 9908 | 1686753332108 webdriver::server DEBUG <- 404 Not Found {"value":{"error":"no such window","message":"Browsing context has been discarded","stacktrace":"RemoteError ... ontent/marionette/server.sys.mjs:265:9\n_onJSONObjectReady/<@chrome://remote/content/marionette/transport.sys.mjs:496:20\n"}}
[task 2023-06-14T14:35:32.312Z] 14:35:32 INFO - STDOUT: FAILED
Not sure why WARNING: ConnectNamedPipe timed out didn't trigger a crash given that we have always have MOZ_CRASHREPORTER_SHUTDOWN set.
Summary: Intermittent /webdriver/tests/classic/refresh/user_prompts.py | test_accept_and_notify[capabilities0-alert-None] - setup error: webdriver.error.UnknownErrorException: unknown error (500): Failed to decode response from marionette → Intermittent Wd | "unknown error" (500): Failed to decode response from marionette or "no such window" (404): Browsing context has been discarded [ConnectNamedPipe timed out]
|
|
||
Updated•1 year ago
|
Summary: Intermittent Wd | "unknown error" (500): Failed to decode response from marionette or "no such window" (404): Browsing context has been discarded [ConnectNamedPipe timed out] → Intermittent Mn, Wd | "unknown error" (500): Failed to decode response from marionette or "no such window" (404): Browsing context has been discarded [ConnectNamedPipe timed out]
| Comment hidden (Intermittent Failures Robot) |
|
|
||
Comment 8•1 year ago
|
||
We're making the timeout a bit longer in bug 1832020, and I'm hoping to remove the need to call ConnectNamedPipe at all in bug 1838906, so hopefully this issue will stop being a problem soon.
|
|
||
Comment 9•1 year ago
|
||
That sounds great. Thanks!
|
|
||
Comment 10•1 year ago
|
||
This should be fixed by the dependent bugs being landed. I'll mark as WFM given that it is hard to verify.
Status: NEW → RESOLVED
Closed: 1 year ago
Resolution: --- → WORKSFORME
You need to log in
before you can comment on or make changes to this bug.
Description
•