Closed
Bug 1904167
Opened 4 months ago
Closed 4 months ago
Intermittent mozilla/tests/webdriver/classic/protocol/marionette_port.py | test_marionette_port[system allocated] - webdriver.error.UnknownErrorException: unknown error (500): Failed to decode response from marionette
Categories
(Remote Protocol :: Marionette, defect, P5)
Remote Protocol
Marionette
Tracking
(Not tracked)
RESOLVED
DUPLICATE
of bug 1894213
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: intermittent-failure)
Filed by: imoraru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=463585845&repo=mozilla-beta
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/fWj18GarQO26qUIIIHbbQg/runs/0/artifacts/public/logs/live_backing.log
[task 2024-06-21T23:14:32.136Z] 23:14:32 INFO - [Child 19733, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040111 (NS_ERROR_NOT_AVAILABLE): file /builds/worker/checkouts/gecko/js/loader/ModuleLoaderBase.cpp:475
[task 2024-06-21T23:14:32.178Z] 23:14:32 INFO - ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpl3lzw6dd.mozrunner/runtests_leaks_903_utility_pid19768.log
[task 2024-06-21T23:14:32.221Z] 23:14:32 INFO - [WARN glean_core::error_recording] fog.initialization: Timespan value already recorded. New value discarded.
[task 2024-06-21T23:14:32.289Z] 23:14:32 INFO - ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpl3lzw6dd.mozrunner/runtests_leaks_903_tab_pid19777.log
[task 2024-06-21T23:14:32.300Z] 23:14:32 INFO - ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpl3lzw6dd.mozrunner/runtests_leaks_903_tab_pid19779.log
[task 2024-06-21T23:14:32.326Z] 23:14:32 INFO - [Child 19779, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:757
[task 2024-06-21T23:14:32.326Z] 23:14:32 INFO - [Child 19777, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:757
[task 2024-06-21T23:14:32.346Z] 23:14:32 INFO - [ERROR error_support::handling] suggest-unexpected: Error from Remote Settings: Error parsing URL: relative URL with a cannot-be-a-base base
[task 2024-06-21T23:14:32.361Z] 23:14:32 INFO - ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpl3lzw6dd.mozrunner/runtests_leaks_903_tab_pid19790.log
[task 2024-06-21T23:14:32.398Z] 23:14:32 INFO - [Child 19790, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:757
[task 2024-06-21T23:14:32.775Z] 23:14:32 INFO - [Parent 19575, Compositor] WARNING: Possibly dropping task posted to updater thread: file /builds/worker/checkouts/gecko/gfx/layers/apz/src/APZUpdater.cpp:395
[task 2024-06-21T23:14:33.130Z] 23:14:33 INFO - [Parent 19575, Main Thread] WARNING: BlockShutdown: Init failed: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/toolkit/components/antitracking/bouncetrackingprotection/BounceTrackingProtectionStorage.cpp:304
[task 2024-06-21T23:14:33.183Z] 23:14:33 INFO - [Parent 19575, IPDL Background] WARNING: quota manager shutdown step: '0.000000s: startCrashBrowserTimer', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2231
[task 2024-06-21T23:14:33.183Z] 23:14:33 INFO - [Parent 19575, IPDL Background] WARNING: quota manager shutdown step: '0.000000s: initiateShutdownWorkThreads', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2231
[task 2024-06-21T23:14:33.183Z] 23:14:33 INFO - [Parent 19575, IPDL Background] WARNING: idb: '0.000000s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2231
[task 2024-06-21T23:14:33.183Z] 23:14:33 INFO - [Parent 19575, IPDL Background] WARNING: cache: '0.000000s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2231
[task 2024-06-21T23:14:33.184Z] 23:14:33 INFO - [Parent 19575, IPDL Background] WARNING: sdb: '0.000000s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2231
[task 2024-06-21T23:14:33.185Z] 23:14:33 INFO - [Parent 19575, IPDL Background] WARNING: fs: '0.000000s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2231
[task 2024-06-21T23:14:33.186Z] 23:14:33 INFO - [Parent 19575, IPDL Background] WARNING: ls: '0.000000s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2231
[task 2024-06-21T23:14:33.186Z] 23:14:33 INFO - [Parent 19575, IPDL Background] WARNING: quota manager shutdown step: '0.000000s: startKillActorsTimer', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2231
[task 2024-06-21T23:14:33.187Z] 23:14:33 INFO - [Parent 19575, IPDL Background] WARNING: idb: '0.000000s: Live database entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2231
[task 2024-06-21T23:14:33.188Z] 23:14:33 INFO - [Parent 19575, IPDL Background] WARNING: idb: '0.000000s: gLiveDatabaseHashtable entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2231
[task 2024-06-21T23:14:33.188Z] 23:14:33 INFO - [Parent 19575, IPDL Background] WARNING: idb: '0.000000s: Live database entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2231
[task 2024-06-21T23:14:33.188Z] 23:14:33 INFO - [Parent 19575, IPDL Background] WARNING: idb: '0.000000s: gLiveDatabaseHashtable entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2231
[task 2024-06-21T23:14:33.188Z] 23:14:33 INFO - [Parent 19575, IPDL Background] WARNING: idb: '0.000000s: Live database entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2231
[task 2024-06-21T23:14:33.188Z] 23:14:33 INFO - [Parent 19575, IPDL Background] WARNING: idb: '0.000000s: gLiveDatabaseHashtable entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2231
[task 2024-06-21T23:14:33.229Z] 23:14:33 INFO - [Parent 19575, IPDL Background] WARNING: idb: '0.048000s: Live database entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2231
[task 2024-06-21T23:14:33.230Z] 23:14:33 INFO - [Parent 19575, IPDL Background] WARNING: idb: '0.048000s: Live database entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2231
[task 2024-06-21T23:14:33.230Z] 23:14:33 INFO - [Parent 19575, IPDL Background] WARNING: idb: '0.048000s: gLiveDatabaseHashtable entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2231
[task 2024-06-21T23:14:33.231Z] 23:14:33 INFO - [Parent 19575, QuotaManager IO] WARNING: quota manager shutdown step: '0.048000s: ShutdownStorageOp::DoDirectoryWork -> ShutdownStorageInternal.', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2231
[task 2024-06-21T23:14:33.231Z] 23:14:33 INFO - [Parent 19575, IPDL Background] WARNING: quota manager shutdown step: '0.048000s: stopKillActorsTimer', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2231
[task 2024-06-21T23:14:33.231Z] 23:14:33 INFO - [Parent 19575, IPDL Background] WARNING: quota manager shutdown step: '0.048000s: shutdownAndJoinWorkThreads', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2231
[task 2024-06-21T23:14:33.232Z] 23:14:33 INFO - [Parent 19575, IPDL Background] WARNING: idb: '0.048000s: completed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2231
[task 2024-06-21T23:14:33.233Z] 23:14:33 INFO - [Parent 19575, IPDL Background] WARNING: cache: '0.048000s: completed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2231
[task 2024-06-21T23:14:33.233Z] 23:14:33 INFO - [Parent 19575, IPDL Background] WARNING: sdb: '0.048000s: completed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2231
[task 2024-06-21T23:14:33.233Z] 23:14:33 INFO - [Parent 19575, IPDL Background] WARNING: fs: '0.048000s: completed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2231
[task 2024-06-21T23:14:33.233Z] 23:14:33 INFO - [Parent 19575, IPDL Background] WARNING: ls: '0.048000s: completed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2231
[task 2024-06-21T23:14:33.233Z] 23:14:33 INFO - [Parent 19575, IPDL Background] WARNING: quota manager shutdown step: '0.048000s: shutdownAndJoinIOThread', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2231
[task 2024-06-21T23:14:33.233Z] 23:14:33 INFO - [Parent 19575, IPDL Background] WARNING: quota manager shutdown step: '0.048000s: invalidatePendingDirectoryLocks', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2231
[task 2024-06-21T23:14:33.233Z] 23:14:33 INFO - [Parent 19575, IPDL Background] WARNING: quota manager shutdown step: '0.052000s: stopCrashBrowserTimer', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2231
[task 2024-06-21T23:14:33.390Z] 23:14:33 INFO - [Utility 19768, Main Thread] WARNING: IPC message 'PUtilityProcess::Msg_FOGData' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:551
[task 2024-06-21T23:14:33.425Z] 23:14:33 INFO - Destroying context 7fa10f8183c0 surface 0 on display 7fa10f861200
[task 2024-06-21T23:14:33.980Z] 23:14:33 INFO - [Parent 19575, Main Thread] WARNING: '!top', file /builds/worker/checkouts/gecko/dom/xul/MenuBarListener.cpp:99
[task 2024-06-21T23:14:34.414Z] 23:14:34 INFO - STDOUT: PASSED
[task 2024-06-21T23:14:34.418Z] 23:14:34 INFO - STDOUT: =================================== FAILURES ===================================
[task 2024-06-21T23:14:34.420Z] 23:14:34 INFO - STDOUT: ____________________ test_marionette_port[system allocated] ____________________
[task 2024-06-21T23:14:34.422Z] 23:14:34 INFO - STDOUT: geckodriver = <function geckodriver.<locals>._geckodriver at 0x7fa562628af0>
[task 2024-06-21T23:14:34.423Z] 23:14:34 INFO - STDOUT: port = '0'
[task 2024-06-21T23:14:34.428Z] 23:14:34 INFO -
[task 2024-06-21T23:14:34.428Z] 23:14:34 INFO - TEST-UNEXPECTED-FAIL | /_mozilla/webdriver/classic/protocol/marionette_port.py | test_marionette_port[system allocated] - webdriver.error.UnknownErrorException: unknown error (500): Failed to decode response from marionette
[task 2024-06-21T23:14:34.428Z] 23:14:34 INFO - geckodriver = <function geckodriver.<locals>._geckodriver at 0x7fa562628af0>
[task 2024-06-21T23:14:34.428Z] 23:14:34 INFO - port = '0'
[task 2024-06-21T23:14:34.428Z] 23:14:34 INFO -
[task 2024-06-21T23:14:34.428Z] 23:14:34 INFO - @pytest.mark.parametrize("port", ["0", "2828"], ids=["system allocated", "fixed"])
[task 2024-06-21T23:14:34.428Z] 23:14:34 INFO - async def test_marionette_port(geckodriver, port):
[task 2024-06-21T23:14:34.428Z] 23:14:34 INFO - extra_args = ["--marionette-port", port]
[task 2024-06-21T23:14:34.428Z] 23:14:34 INFO -
[task 2024-06-21T23:14:34.428Z] 23:14:34 INFO - driver = geckodriver(extra_args=extra_args)
[task 2024-06-21T23:14:34.428Z] 23:14:34 INFO - driver.new_session()
[task 2024-06-21T23:14:34.428Z] 23:14:34 INFO - > await driver.delete_session()
[task 2024-06-21T23:14:34.428Z] 23:14:34 INFO -
[task 2024-06-21T23:14:34.428Z] 23:14:34 INFO - driver = <support.helpers.Geckodriver object at 0x7fa5625eac10>
[task 2024-06-21T23:14:34.428Z] 23:14:34 INFO - extra_args = ['--marionette-port', '0']
[task 2024-06-21T23:14:34.428Z] 23:14:34 INFO - geckodriver = <function geckodriver.<locals>._geckodriver at 0x7fa562628af0>
[task 2024-06-21T23:14:34.428Z] 23:14:34 INFO - port = '0'
[task 2024-06-21T23:14:34.428Z] 23:14:34 INFO -
[task 2024-06-21T23:14:34.428Z] 23:14:34 INFO - tests/web-platform/mozilla/tests/webdriver/classic/protocol/marionette_port.py:15:
[task 2024-06-21T23:14:34.428Z] 23:14:34 INFO - _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
[task 2024-06-21T23:14:34.429Z] 23:14:34 INFO - tests/web-platform/mozilla/tests/webdriver/support/helpers.py:206: in delete_session
[task 2024-06-21T23:14:34.429Z] 23:14:34 INFO - self.session.end()
[task 2024-06-21T23:14:34.429Z] 23:14:34 INFO - self = <support.helpers.Geckodriver object at 0x7fa5625eac10>
[task 2024-06-21T23:14:34.429Z] 23:14:34 INFO - tests/web-platform/tests/tools/webdriver/webdriver/client.py:529: in end
[task 2024-06-21T23:14:34.429Z] 23:14:34 INFO - self.send_command("DELETE", "session/%s" % self.session_id)
[task 2024-06-21T23:14:34.429Z] 23:14:34 INFO - self = <Session (disconnected)>
[task 2024-06-21T23:14:34.429Z] 23:14:34 INFO - _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
[task 2024-06-21T23:14:34.429Z] 23:14:34 INFO -
[task 2024-06-21T23:14:34.429Z] 23:14:34 INFO - self = <Session (disconnected)>, method = 'DELETE'
[task 2024-06-21T23:14:34.429Z] 23:14:34 INFO - url = 'session/90ecc609-6320-47e2-b2d0-494f06e4a403', body = None
[task 2024-06-21T23:14:34.429Z] 23:14:34 INFO - timeout = None
[task 2024-06-21T23:14:34.429Z] 23:14:34 INFO -
[task 2024-06-21T23:14:34.429Z] 23:14:34 INFO - def send_command(self, method, url, body=None, timeout=None):
[task 2024-06-21T23:14:34.429Z] 23:14:34 INFO - """
[task 2024-06-21T23:14:34.429Z] 23:14:34 INFO - Send a command to the remote end and validate its success.
[task 2024-06-21T23:14:34.429Z] 23:14:34 INFO -
[task 2024-06-21T23:14:34.429Z] 23:14:34 INFO - :param method: HTTP method to use in request.
[task 2024-06-21T23:14:34.429Z] 23:14:34 INFO - :param uri: "Command part" of the HTTP request URL,
[task 2024-06-21T23:14:34.429Z] 23:14:34 INFO - e.g. `window/rect`.
[task 2024-06-21T23:14:34.430Z] 23:14:34 INFO - :param body: Optional body of the HTTP request.
[task 2024-06-21T23:14:34.430Z] 23:14:34 INFO -
[task 2024-06-21T23:14:34.430Z] 23:14:34 INFO - :return: `None` if the HTTP response body was empty, otherwise
[task 2024-06-21T23:14:34.430Z] 23:14:34 INFO - the `value` field returned after parsing the response
[task 2024-06-21T23:14:34.430Z] 23:14:34 INFO - body as JSON.
[task 2024-06-21T23:14:34.430Z] 23:14:34 INFO -
[task 2024-06-21T23:14:34.430Z] 23:14:34 INFO - :raises error.WebDriverException: If the remote end returns
[task 2024-06-21T23:14:34.430Z] 23:14:34 INFO - an error.
[task 2024-06-21T23:14:34.430Z] 23:14:34 INFO - :raises ValueError: If the response body does not contain a
[task 2024-06-21T23:14:34.430Z] 23:14:34 INFO - `value` key.
[task 2024-06-21T23:14:34.430Z] 23:14:34 INFO - """
[task 2024-06-21T23:14:34.430Z] 23:14:34 INFO -
[task 2024-06-21T23:14:34.431Z] 23:14:34 INFO - response = self.transport.send(
[task 2024-06-21T23:14:34.431Z] 23:14:34 INFO - method, url, body,
[task 2024-06-21T23:14:34.431Z] 23:14:34 INFO - encoder=protocol.Encoder, decoder=protocol.Decoder,
[task 2024-06-21T23:14:34.431Z] 23:14:34 INFO - session=self, timeout=timeout)
[task 2024-06-21T23:14:34.431Z] 23:14:34 INFO -
[task 2024-06-21T23:14:34.431Z] 23:14:34 INFO - if response.status != 200:
[task 2024-06-21T23:14:34.431Z] 23:14:34 INFO - err = error.from_response(response)
[task 2024-06-21T23:14:34.431Z] 23:14:34 INFO -
[task 2024-06-21T23:14:34.431Z] 23:14:34 INFO - if isinstance(err, error.InvalidSessionIdException):
[task 2024-06-21T23:14:34.431Z] 23:14:34 INFO - # The driver could have already been deleted the session.
[task 2024-06-21T23:14:34.431Z] 23:14:34 INFO - self.session_id = None
[task 2024-06-21T23:14:34.431Z] 23:14:34 INFO -
[task 2024-06-21T23:14:34.431Z] 23:14:34 INFO - > raise err
[task 2024-06-21T23:14:34.431Z] 23:14:34 INFO - E webdriver.error.UnknownErrorException: unknown error (500): Failed to decode response from marionette
[task 2024-06-21T23:14:34.431Z] 23:14:34 INFO -
[task 2024-06-21T23:14:34.431Z] 23:14:34 INFO - body = None
[task 2024-06-21T23:14:34.431Z] 23:14:34 INFO - err = <UnknownErrorException http_status=500>
[task 2024-06-21T23:14:34.431Z] 23:14:34 INFO - method = 'DELETE'
[task 2024-06-21T23:14:34.431Z] 23:14:34 INFO - response = <Response status=500 error=<UnknownErrorException http_status=500>>
[task 2024-06-21T23:14:34.431Z] 23:14:34 INFO - self = <Session (disconnected)>
[task 2024-06-21T23:14:34.431Z] 23:14:34 INFO - timeout = None
[task 2024-06-21T23:14:34.431Z] 23:14:34 INFO - url = 'session/90ecc609-6320-47e2-b2d0-494f06e4a403'
[task 2024-06-21T23:14:34.431Z] 23:14:34 INFO -
[task 2024-06-21T23:14:34.431Z] 23:14:34 INFO - tests/web-platform/tests/tools/webdriver/webdriver/client.py:567: UnknownErrorException
[task 2024-06-21T23:14:34.431Z] 23:14:34 INFO - ..
[task 2024-06-21T23:14:34.431Z] 23:14:34 INFO - TEST-OK | /_mozilla/webdriver/classic/protocol/marionette_port.py | took 25539ms
| Comment hidden (Intermittent Failures Robot) |
|
||
Updated•4 months ago
|
|
|
||
Updated•4 months ago
|
You need to log in
before you can comment on or make changes to this bug.
Description
•