Closed Bug 1733286 Opened 3 years ago Closed 3 years ago

Intermittent [tier 2] browser/components/migration/tests/marionette/test_refresh_firefox.py TestFirefoxRefresh.testResetEverything | OSError: Process has been unexpectedly closed (Exit code: 0) (Reason: No data received over socket)

Tracking

()

Status:

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

Treeherder Bug Filer

Reporter

Description

•

3 years ago

treeherder

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

[task 2021-09-30T00:59:10.172Z] 00:59:10     INFO - TEST-START | browser/components/migration/tests/marionette/test_refresh_firefox.py TestFirefoxRefresh.testResetEverything
[task 2021-09-30T00:59:10.174Z] 00:59:10     INFO -  1632963550174	Marionette	DEBUG	Accepted connection 2 from 127.0.0.1:35856
[task 2021-09-30T00:59:10.177Z] 00:59:10     INFO -  1632963550177	Marionette	DEBUG	2 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2021-09-30T00:59:10.179Z] 00:59:10     INFO -  1632963550179	Marionette	DEBUG	2 <- [1,1,null,{"sessionId":"f8e26c30-bd75-4ec7-b2bf-ddf0bac481de","capabilities":{"browserName":"firefox","browserVersion":"94.0a ... m.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true,"proxy":{}}}]
[task 2021-09-30T00:59:10.182Z] 00:59:10     INFO -  1632963550181	Marionette	DEBUG	2 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}]
[task 2021-09-30T00:59:10.184Z] 00:59:10     INFO -  1632963550184	Marionette	DEBUG	2 <- [1,2,null,{"value":null}]
[task 2021-09-30T00:59:10.185Z] 00:59:10     INFO -  1632963550185	Marionette	DEBUG	2 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2021-09-30T00:59:10.188Z] 00:59:10     INFO -  1632963550185	Marionette	DEBUG	2 <- [1,3,null,{"value":null}]
[task 2021-09-30T00:59:10.189Z] 00:59:10     INFO -  1632963550189	Marionette	DEBUG	2 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2021-09-30T00:59:10.190Z] 00:59:10     INFO -  1632963550190	Marionette	DEBUG	2 <- [1,4,null,{"value":null}]
[task 2021-09-30T00:59:10.192Z] 00:59:10     INFO -  1632963550192	Marionette	DEBUG	2 -> [0,5,"Marionette:SetContext",{"value":"chrome"}]
[task 2021-09-30T00:59:10.193Z] 00:59:10     INFO -  1632963550192	Marionette	DEBUG	2 <- [1,5,null,{"value":null}]
[task 2021-09-30T00:59:10.196Z] 00:59:10     INFO -  1632963550195	Marionette	DEBUG	2 -> [0,6,"WebDriver:ExecuteScript",{"script":"window.global = {};\n          global.LoginInfo = Components.Constructor(\"@mozilla ... dbox":"firefox-refresh","line":550,"filename":"tests/browser/components/migration/tests/marionette/test_refresh_firefox.py"}]
[task 2021-09-30T00:59:10.197Z] 00:59:10     INFO -  1632963550196	Marionette	TRACE	[7] MarionetteCommands actor created for window id 2
[task 2021-09-30T00:59:10.199Z] 00:59:10     INFO -  1632963550198	Marionette	DEBUG	2 <- [1,6,null,{"value":null}]
[task 2021-09-30T00:59:10.201Z] 00:59:10     INFO -  1632963550200	Marionette	DEBUG	2 -> [0,7,"WebDriver:ExecuteScript",{"script":"try {\n            global.formAutofillStorage = Cu.import(\"resource://formautofill ... dbox":"firefox-refresh","line":550,"filename":"tests/browser/components/migration/tests/marionette/test_refresh_firefox.py"}]
[task 2021-09-30T00:59:10.203Z] 00:59:10     INFO -  Missing chrome or resource URL: resource://formautofill/FormAutofillStorage.jsm
[task 2021-09-30T00:59:10.204Z] 00:59:10     INFO -  1632963550204	Marionette	DEBUG	2 <- [1,7,null,{"value":false}]
[task 2021-09-30T00:59:10.205Z] 00:59:10     INFO -  DEBUG: Adding blocker ScriptPreloader: Saving bytecode cache for phase xpcom-will-shutdown
[task 2021-09-30T00:59:10.207Z] 00:59:10     INFO -  1632963550206	Marionette	DEBUG	2 -> [0,8,"WebDriver:ExecuteScript",{"script":"let myLogin = new global.LoginInfo(\n            \"test.marionette.mozilla.com\",\n ... dbox":"firefox-refresh","line":550,"filename":"tests/browser/components/migration/tests/marionette/test_refresh_firefox.py"}]
[task 2021-09-30T00:59:10.239Z] 00:59:10     INFO -  1632963550238	Marionette	DEBUG	2 <- [1,8,null,{"value":null}]
[task 2021-09-30T00:59:10.242Z] 00:59:10     INFO -  1632963550241	Marionette	DEBUG	2 -> [0,9,"WebDriver:ExecuteAsyncScript",{"script":"// let url = arguments[0];\n          // let title = arguments[1];\n           ... h","scriptTimeout":null,"line":555,"filename":"tests/browser/components/migration/tests/marionette/test_refresh_firefox.py"}]
[task 2021-09-30T00:59:10.247Z] 00:59:10     INFO -  DEBUG: Adding blocker places.sqlite#1: Bookmarks.jsm: fetchBookmark (19) for phase places.sqlite#1: waiting for clients
[task 2021-09-30T00:59:10.248Z] 00:59:10     INFO -  DEBUG: Completed blocker places.sqlite#1: Bookmarks.jsm: fetchBookmark (19) for phase places.sqlite#1: waiting for clients
[task 2021-09-30T00:59:10.248Z] 00:59:10     INFO -  DEBUG: Adding blocker Transaction (20) for phase places.sqlite#1: waiting for clients
[task 2021-09-30T00:59:10.249Z] 00:59:10     INFO -  DEBUG: Adding blocker places.sqlite#1: Bookmarks.jsm: insertBookmark (21) for phase places.sqlite#1: waiting for clients
[task 2021-09-30T00:59:10.257Z] 00:59:10     INFO -  DEBUG: Completed blocker Transaction (20) for phase places.sqlite#1: waiting for clients
[task 2021-09-30T00:59:10.258Z] 00:59:10     INFO -  DEBUG: Completed blocker places.sqlite#1: Bookmarks.jsm: insertBookmark (21) for phase places.sqlite#1: waiting for clients
[task 2021-09-30T00:59:10.259Z] 00:59:10     INFO -  DEBUG: Adding blocker places.sqlite#1: GuidHelper.getItemId (22) for phase places.sqlite#1: waiting for clients
[task 2021-09-30T00:59:10.260Z] 00:59:10     INFO -  DEBUG: Completed blocker places.sqlite#1: GuidHelper.getItemId (22) for phase places.sqlite#1: waiting for clients
[task 2021-09-30T00:59:10.263Z] 00:59:10     INFO -  1632963550262	Marionette	DEBUG	2 <- [1,9,null,{"value":false}]
[task 2021-09-30T00:59:10.267Z] 00:59:10     INFO -  1632963550266	Marionette	DEBUG	2 -> [0,10,"WebDriver:ExecuteAsyncScript",{"script":"let resolve = arguments[arguments.length - 1];\n          let children = [];\ ... h","scriptTimeout":null,"line":555,"filename":"tests/browser/components/migration/tests/marionette/test_refresh_firefox.py"}]
[task 2021-09-30T00:59:10.270Z] 00:59:10     INFO -  DEBUG: Adding blocker places.sqlite#1: Bookmarks.jsm: fetchBookmark (23) for phase places.sqlite#1: waiting for clients
[task 2021-09-30T00:59:10.272Z] 00:59:10     INFO -  DEBUG: Completed blocker places.sqlite#1: Bookmarks.jsm: fetchBookmark (23) for phase places.sqlite#1: waiting for clients
[task 2021-09-30T00:59:10.273Z] 00:59:10     INFO -  DEBUG: Adding blocker Transaction (24) for phase places.sqlite#1: waiting for clients
[task 2021-09-30T00:59:10.273Z] 00:59:10     INFO -  DEBUG: Adding blocker places.sqlite#1: Bookmarks.jsm: insertBookmarkTree (25) for phase places.sqlite#1: waiting for clients
...
[task 2021-09-30T00:59:10.951Z] 00:59:10     INFO -  DEBUG: Finished phase xpcom-will-shutdown
[task 2021-09-30T00:59:11.129Z] 00:59:11     INFO -  DEBUG: Starting phase web-workers-shutdown
[task 2021-09-30T00:59:11.131Z] 00:59:11     INFO -  DEBUG: Spinning the event loop
[task 2021-09-30T00:59:11.132Z] 00:59:11     INFO -  DEBUG: Finished phase web-workers-shutdown
[task 2021-09-30T00:59:11.201Z] 00:59:11     INFO -  *** You are running in headless mode.
[task 2021-09-30T00:59:11.247Z] 00:59:11     INFO -  [GFX1-]: glxtest: Unable to open a connection to the X server
[task 2021-09-30T00:59:11.247Z] 00:59:11     INFO -  [GFX1-]: glxtest: libEGL initialize failed
[task 2021-09-30T00:59:11.439Z] 00:59:11     INFO -  [GFX1-]: RenderCompositorSWGL failed mapping default framebuffer, no dt
[task 2021-09-30T00:59:18.849Z] 00:59:18     INFO -  Missing chrome or resource URL: resource://formautofill/FormAutofillStorage.jsm
[task 2021-09-30T00:59:18.952Z] 00:59:18     INFO -  ExceptionHandler::GenerateDump cloned child 24220
[task 2021-09-30T00:59:18.952Z] 00:59:18     INFO -  ExceptionHandler::SendContinueSignalToChild sent continue signal to child
[task 2021-09-30T00:59:18.953Z] 00:59:18     INFO -  ExceptionHandler::WaitForContinueSignal waiting for continue signal...
[task 2021-09-30T00:59:19.096Z] 00:59:19     INFO -  Exiting due to channel error.
[task 2021-09-30T00:59:19.096Z] 00:59:19     INFO -  Exiting due to channel error.
[task 2021-09-30T00:59:19.097Z] 00:59:19     INFO -  Exiting due to channel error.
[task 2021-09-30T00:59:19.097Z] 00:59:19     INFO -  Exiting due to channel error.
[task 2021-09-30T00:59:19.119Z] 00:59:19     INFO - TEST-UNEXPECTED-ERROR | browser/components/migration/tests/marionette/test_refresh_firefox.py TestFirefoxRefresh.testResetEverything | OSError: Process has been unexpectedly closed (Exit code: 0) (Reason: No data received over socket)
[task 2021-09-30T00:59:19.119Z] 00:59:19     INFO - Traceback (most recent call last):
[task 2021-09-30T00:59:19.120Z] 00:59:19     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_harness/marionette_test/testcases.py", line 202, in run
[task 2021-09-30T00:59:19.120Z] 00:59:19     INFO -     testMethod()
[task 2021-09-30T00:59:19.121Z] 00:59:19     INFO -   File "/builds/worker/workspace/build/tests/marionette/tests/browser/components/migration/tests/marionette/test_refresh_firefox.py", line 686, in testResetEverything
[task 2021-09-30T00:59:19.121Z] 00:59:19     INFO -     self.checkProfile(has_migrated=True, expect_sync_user=True)
[task 2021-09-30T00:59:19.121Z] 00:59:19     INFO -   File "/builds/worker/workspace/build/tests/marionette/tests/browser/components/migration/tests/marionette/test_refresh_firefox.py", line 512, in checkProfile
[task 2021-09-30T00:59:19.121Z] 00:59:19     INFO -     self.checkSession()
[task 2021-09-30T00:59:19.121Z] 00:59:19     INFO -   File "/builds/worker/workspace/build/tests/marionette/tests/browser/components/migration/tests/marionette/test_refresh_firefox.py", line 463, in checkSession
[task 2021-09-30T00:59:19.122Z] 00:59:19     INFO -     """  # NOQA: E501
[task 2021-09-30T00:59:19.122Z] 00:59:19     INFO -   File "/builds/worker/workspace/build/tests/marionette/tests/browser/components/migration/tests/marionette/test_refresh_firefox.py", line 555, in runAsyncCode
[task 2021-09-30T00:59:19.123Z] 00:59:19     INFO -     script, new_sandbox=False, sandbox=self._sandbox, *args, **kwargs
[task 2021-09-30T00:59:19.123Z] 00:59:19     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/marionette.py", line 1734, in execute_async_script
[task 2021-09-30T00:59:19.123Z] 00:59:19     INFO -     rv = self._send_message("WebDriver:ExecuteAsyncScript", body, key="value")
[task 2021-09-30T00:59:19.124Z] 00:59:19     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/decorators.py", line 37, in _
[task 2021-09-30T00:59:19.124Z] 00:59:19     INFO -     m._handle_socket_failure()
[task 2021-09-30T00:59:19.125Z] 00:59:19     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/marionette.py", line 717, in _handle_socket_failure
[task 2021-09-30T00:59:19.126Z] 00:59:19     INFO -     IOError, IOError(message.format(returncode=returncode, reason=exc)), tb
[task 2021-09-30T00:59:19.126Z] 00:59:19     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/six.py", line 702, in reraise
[task 2021-09-30T00:59:19.126Z] 00:59:19     INFO -     raise value.with_traceback(tb)
[task 2021-09-30T00:59:19.126Z] 00:59:19     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/decorators.py", line 27, in _
[task 2021-09-30T00:59:19.126Z] 00:59:19     INFO -     return func(*args, **kwargs)
[task 2021-09-30T00:59:19.126Z] 00:59:19     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/marionette.py", line 623, in _send_message
[task 2021-09-30T00:59:19.126Z] 00:59:19     INFO -     msg = self.client.request(name, params)
[task 2021-09-30T00:59:19.127Z] 00:59:19     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/transport.py", line 383, in request
[task 2021-09-30T00:59:19.127Z] 00:59:19     INFO -     return self.receive()
[task 2021-09-30T00:59:19.128Z] 00:59:19     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/transport.py", line 230, in receive
[task 2021-09-30T00:59:19.128Z] 00:59:19     INFO -     raise socket.error("No data received over socket")
[task 2021-09-30T00:59:19.128Z] 00:59:19     INFO - TEST-INFO took 8944ms
[task 2021-09-30T00:59:19.130Z] 00:59:19    ERROR - test_end for browser/components/migration/tests/marionette/test_refresh_firefox.py TestFirefoxRefresh.testResetEverything logged while not in progress. Logged with data: {"message": "marionette_driver.errors.InvalidSessionIdException: Please start a session", "expected": "PASS", "stack": "Traceback (most recent call last):\n  File \"/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_harness/marionette_test/testcases.py\", line 235, in run\n    self.tearDown()\n  File \"/builds/worker/workspace/build/tests/marionette/tests/browser/components/migration/tests/marionette/test_refresh_firefox.py\", line 568, in tearDown\n    self.marionette.restart(clean=True, in_app=False)\n  File \"/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/decorators.py\", line 27, in _\n    return func(*args, **kwargs)\n  File \"/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/marionette.py\", line 1054, in restart\n    context = self._send_message(\"Marionette:GetContext\", key=\"value\")\n  File \"/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/decorators.py\", line 27, in _\n    return func(*args, **kwargs)\n  File \"/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/marionette.py\", line 620, in _send_message\n    raise errors.InvalidSessionIdException(\"Please start a session\")\n", "extra": {"class_name": "test_refresh_firefox.TestFirefoxRefresh", "method_name": "testResetEverything"}, "test": "browser/components/migration/tests/marionette/test_refresh_firefox.py TestFirefoxRefresh.testResetEverything", "status": "ERROR"}
[task 2021-09-30T00:59:19.130Z] 00:59:19     INFO - TEST-START | js/xpconnect/tests/marionette/test_preloader_telemetry.py TestScriptPreloader.test_preloader_requests_histogram

Comment hidden (Intermittent Failures Robot)

BugBot [:suhaib / :marco/ :calixte]

Comment 2

•

3 years ago

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Status: NEW → RESOLVED

Closed: 3 years ago

Resolution: --- → INCOMPLETE

You need to log in before you can comment on or make changes to this bug.

Bugzilla

Quick Search

Intermittent [tier 2] browser/components/migration/tests/marionette/test_refresh_firefox.py TestFirefoxRefresh.testResetEverything | OSError: Process has been unexpectedly closed (Exit code: 0) (Reason: No data received over socket)

Categories

(Firefox :: Migration, defect, P5)

Tracking

()

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure)

Crash Data

Security

(public)

User Story

Description

Comment 1

Comment 2