Closed
Bug 1836733
Opened 1 year ago
Closed 1 year ago
Intermittent [tier 2] arsenic.errors.SessionStartError: timeout: Socket timeout reading Marionette handshake data: A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed be
Categories
(Testing :: Condprofile, defect, P5)
Testing
Condprofile
Tracking
(Not tracked)
RESOLVED
INCOMPLETE
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=418087702&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/cCfXQiFOQzKNQh5gj9Hi3Q/runs/0/artifacts/public/logs/live_backing.log
[task 2023-06-05T10:08:57.413Z] 10:08:57 INFO - condprof INFO | Starting the Gecko app...
[task 2023-06-05T10:08:57.414Z] 10:08:57 INFO - condprof INFO | Writing geckodriver logs in C:\Users\task_1685806004\AppData\Local\Temp\tmplshcdaof\geckodriver-settled-default.log
[task 2023-06-05T10:08:57.424Z] 10:08:57 INFO - condprof INFO | Running Webdriver on port 49820
[task 2023-06-05T10:08:57.424Z] 10:08:57 INFO - condprof INFO | Running Marionette on port 2828
[task 2023-06-05T10:08:57.933Z] 10:08:57 INFO - condprof INFO | url='http://localhost:49820/session' method='POST' body='{"desiredCapabilities": {"browserName": "firefox", "marionette": true, "acceptInsecureCerts": true, "moz:firefoxOptions": {"args": ["--allow-downgrade", "-profile", "C:\\\\Users\\\\task_1685806004\\\\AppData\\\\Local\\\\Temp\\\\tmprkr604xz\\\\profile"], "binary": "C:\\\\Users\\\\task_1685806004\\\\build\\\\application\\\\firefox\\\\firefox.exe", "prefs": {"focusmanager.testmode": true, "marionette.defaultPrefs.port": 2828, "marionette.port": 2828, "remote.log.level": "Trace", "marionette.log.truncate": false, "extensions.autoDisableScopes": 10, "devtools.debugger.remote-enabled": true, "devtools.console.stdout.content": true, "devtools.console.stdout.chrome": true}, "log": {"level": "trace"}}}}' headers={'Content-Type': 'application/json'} event='request'
[task 2023-06-05T10:11:08.320Z] 10:11:08 INFO - condprof INFO | url='http://localhost:49820/session' method='POST' body='{"desiredCapabilities": {"browserName": "firefox", "marionette": true, "acceptInsecureCerts": true, "moz:firefoxOptions": {"args": ["--allow-downgrade", "-profile", "C:\\\\Users\\\\task_1685806004\\\\AppData\\\\Local\\\\Temp\\\\tmprkr604xz\\\\profile"], "binary": "C:\\\\Users\\\\task_1685806004\\\\build\\\\application\\\\firefox\\\\firefox.exe", "prefs": {"focusmanager.testmode": true, "marionette.defaultPrefs.port": 2828, "marionette.port": 2828, "remote.log.level": "Trace", "marionette.log.truncate": false, "extensions.autoDisableScopes": 10, "devtools.debugger.remote-enabled": true, "devtools.console.stdout.content": true, "devtools.console.stdout.chrome": true}, "log": {"level": "trace"}}}}' response=<ClientResponse(http://localhost:49820/session) [500 Internal Server Error]>
[task 2023-06-05T10:11:08.321Z] 10:11:08 INFO - <CIMultiDictProxy('Content-Type': 'application/json; charset=utf-8', 'Cache-Control': 'no-cache', 'Content-Length': '308', 'Date': 'Mon, 05 Jun 2023 10:08:57 GMT')>
[task 2023-06-05T10:11:08.322Z] 10:11:08 INFO - data={'value': {'error': 'timeout', 'message': 'Socket timeout reading Marionette handshake data: A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond. (os error 10060)', 'stacktrace': ''}} event='response'
[task 2023-06-05T10:11:08.322Z] 10:11:08 INFO - condprof ERROR | settled scenario broke!
[task 2023-06-05T10:11:08.322Z] 10:11:08 INFO - condprof INFO | Could not start the session, check C:\Users\task_1685806004\AppData\Local\Temp\tmplshcdaof\geckodriver-settled-default.log first
[task 2023-06-05T10:11:08.323Z] 10:11:08 ERROR - Traceback (most recent call last):
[task 2023-06-05T10:11:08.323Z] 10:11:08 INFO - File "C:\Users\task_1685806004\build\tests\raptor\raptor\raptor.py", line 103, in main
[task 2023-06-05T10:11:08.323Z] 10:11:08 INFO - raptor = raptor_class(
[task 2023-06-05T10:11:08.324Z] 10:11:08 INFO - File "C:\Users\task_1685806004\build\tests\raptor\raptor\raptor.py", line 100, in raptor_class
[task 2023-06-05T10:11:08.324Z] 10:11:08 INFO - return klass(*inner_args, **inner_kwargs)
[task 2023-06-05T10:11:08.325Z] 10:11:08 INFO - File "C:\Users\task_1685806004\build\tests\raptor\raptor\browsertime\desktop.py", line 17, in __init__
[task 2023-06-05T10:11:08.325Z] 10:11:08 INFO - super(BrowsertimeDesktop, self).__init__(*args, **kwargs)
[task 2023-06-05T10:11:08.325Z] 10:11:08 INFO - File "C:\Users\task_1685806004\build\tests\raptor\raptor\perftest.py", line 767, in __init__
[task 2023-06-05T10:11:08.325Z] 10:11:08 INFO - super(PerftestDesktop, self).__init__(*args, **kwargs)
[task 2023-06-05T10:11:08.326Z] 10:11:08 INFO - File "C:\Users\task_1685806004\build\tests\raptor\raptor\browsertime\base.py", line 57, in __init__
[task 2023-06-05T10:11:08.326Z] 10:11:08 INFO - super(Browsertime, self).__init__(
[task 2023-06-05T10:11:08.326Z] 10:11:08 INFO - File "C:\Users\task_1685806004\build\tests\raptor\raptor\perftest.py", line 226, in __init__
[task 2023-06-05T10:11:08.327Z] 10:11:08 INFO - self.build_browser_profile()
[task 2023-06-05T10:11:08.327Z] 10:11:08 INFO - File "C:\Users\task_1685806004\build\tests\raptor\raptor\browsertime\base.py", line 84, in build_browser_profile
[task 2023-06-05T10:11:08.327Z] 10:11:08 INFO - super(Browsertime, self).build_browser_profile()
[task 2023-06-05T10:11:08.328Z] 10:11:08 INFO - File "C:\Users\task_1685806004\build\tests\raptor\raptor\perftest.py", line 405, in build_browser_profile
[task 2023-06-05T10:11:08.328Z] 10:11:08 INFO - self.profile_class, profile=self.get_conditioned_profile()
[task 2023-06-05T10:11:08.329Z] 10:11:08 INFO - File "C:\Users\task_1685806004\build\tests\raptor\raptor\perftest.py", line 322, in get_conditioned_profile
[task 2023-06-05T10:11:08.329Z] 10:11:08 INFO - return self.build_conditioned_profile()
[task 2023-06-05T10:11:08.329Z] 10:11:08 INFO - File "C:\Users\task_1685806004\build\tests\raptor\raptor\perftest.py", line 304, in build_conditioned_profile
[task 2023-06-05T10:11:08.329Z] 10:11:08 INFO - loop.run_until_complete(runner.one_run(scenario, "default"))
[task 2023-06-05T10:11:08.330Z] 10:11:08 INFO - File "c:\mozilla-build\python3\lib\asyncio\base_events.py", line 642, in run_until_complete
[task 2023-06-05T10:11:08.330Z] 10:11:08 INFO - return future.result()
[task 2023-06-05T10:11:08.330Z] 10:11:08 INFO - File "C:\Users\task_1685806004\build\venv\lib\site-packages\condprof\runner.py", line 139, in one_run
[task 2023-06-05T10:11:08.331Z] 10:11:08 INFO - return await ProfileCreator(
[task 2023-06-05T10:11:08.331Z] 10:11:08 INFO - File "C:\Users\task_1685806004\build\venv\lib\site-packages\condprof\creator.py", line 100, in run
[task 2023-06-05T10:11:08.331Z] 10:11:08 INFO - metadata = await self.build_profile(device, headless)
[task 2023-06-05T10:11:08.332Z] 10:11:08 INFO - File "C:\Users\task_1685806004\build\venv\lib\site-packages\condprof\creator.py", line 190, in build_profile
[task 2023-06-05T10:11:08.332Z] 10:11:08 INFO - async with get_session(geckodriver, firefox_instance) as session:
[task 2023-06-05T10:11:08.332Z] 10:11:08 INFO - File "C:\Users\task_1685806004\build\venv\lib\site-packages\arsenic\__init__.py", line 16, in __aenter__
[task 2023-06-05T10:11:08.333Z] 10:11:08 INFO - self.session = await start_session(self.service, self.browser, self.bind)
[task 2023-06-05T10:11:08.333Z] 10:11:08 INFO - File "C:\Users\task_1685806004\build\venv\lib\site-packages\arsenic\__init__.py", line 29, in start_session
[task 2023-06-05T10:11:08.333Z] 10:11:08 INFO - return await driver.new_session(browser, bind=bind)
[task 2023-06-05T10:11:08.334Z] 10:11:08 INFO - File "C:\Users\task_1685806004\build\venv\lib\site-packages\arsenic\webdriver.py", line 55, in new_session
[task 2023-06-05T10:11:08.334Z] 10:11:08 INFO - raise SessionStartError(
[task 2023-06-05T10:11:08.335Z] 10:11:08 INFO - arsenic.errors.SessionStartError: timeout: Socket timeout reading Marionette handshake data: A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond. (os error 10060)
[task 2023-06-05T10:11:08.335Z] 10:11:08 ERROR - raptor-main Critical: TEST-UNEXPECTED-FAIL: could not initialize the raptor test runner
[task 2023-06-05T10:11:08.338Z] 10:11:08 INFO - Unclosed client session
[task 2023-06-05T10:11:08.338Z] 10:11:08 INFO - client_session: <aiohttp.client.ClientSession object at 0x0000026BD23697C0>
[task 2023-06-05T10:11:08.339Z] 10:11:08 INFO - Unclosed connector
[task 2023-06-05T10:11:08.339Z] 10:11:08 INFO - connections: ['[(<aiohttp.client_proto.ResponseHandler object at 0x0000026BD236B520>, 85268.406)]']
[task 2023-06-05T10:11:08.339Z] 10:11:08 INFO - connector: <aiohttp.connector.TCPConnector object at 0x0000026BD2369CD0>
[task 2023-06-05T10:14:13.381Z] WARNING | IO Completion Port failed to signal process shutdown
[task 2023-06-05T10:14:13.381Z] Parent process 3156 exited with children alive:
[task 2023-06-05T10:14:13.381Z] PIDS: 824, 2352, 5868, 352, 5844
[task 2023-06-05T10:14:13.381Z] Attempting to kill them, but no guarantee of success
[task 2023-06-05T10:14:13.381Z] 10:14:13 INFO - Return code: 1
[task 2023-06-05T10:14:13.381Z] 10:14:13 WARNING - setting return code to 1
| Comment hidden (Intermittent Failures Robot) |
|
||
Comment 2•1 year ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.
Status: NEW → RESOLVED
Closed: 1 year ago
Resolution: --- → INCOMPLETE
You need to log in
before you can comment on or make changes to this bug.
Description
•