Closed Bug 1762686 Opened 3 years ago Closed 2 years ago

Intermittent testing/marionette/harness/marionette_harness/tests/unit/test_cli_arguments.py <test-name> | OSError: Process has been unexpectedly closed (Exit code: 572) (Reason: Process killed after 120s becau

Categories

(Testing :: Marionette Client and Harness, defect, P5)

defect

Tracking

(Not tracked)

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

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


INFO -  Application command: Z:\task_164885867147513\build\application\firefox\firefox.exe -no-remote -marionette --wait-for-browser -profile C:\Users\task_164885867147513\AppData\Local\Temp\tmpqjsauqfq.mozrunner
[task 2022-04-02T02:45:42.428Z] 02:45:42     INFO -  DEBUG: Adding blocker AddonManager: shutting down. for phase profile-before-change
[task 2022-04-02T02:45:42.513Z] 02:45:42     INFO -  DEBUG: Adding blocker IOUtils Blocker (profile-before-change) for phase profile-before-change
[task 2022-04-02T02:45:42.517Z] 02:45:42     INFO -  DEBUG: Adding blocker IOUtils Blocker (xpcom-will-shutdown) for phase xpcom-will-shutdown
[task 2022-04-02T02:45:42.655Z] 02:45:42     INFO -  DEBUG: Adding blocker Flush WebExtension StartupCache for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2022-04-02T02:45:42.990Z] 02:45:42     INFO -  DEBUG: Adding blocker JSON store: writing data for phase AddonManager: Waiting for providers to shut down.
[task 2022-04-02T02:45:43.008Z] 02:45:43     INFO -  DEBUG: Adding blocker Update add-on blocklist state into add-on DB for phase AddonManager: Waiting to start provider shutdown.
[task 2022-04-02T02:45:43.021Z] 02:45:43     INFO -  DEBUG: Adding blocker XPIProvider shutdown for phase quit-application-granted
[task 2022-04-02T02:45:43.036Z] 02:45:43     INFO -  DEBUG: Adding blocker XPIProvider for phase AddonManager: Waiting for providers to shut down.
[task 2022-04-02T02:45:43.037Z] 02:45:43     INFO -  DEBUG: Adding blocker ServiceWorkerRegistrar: Flushing data for phase profile-before-change
[task 2022-04-02T02:45:43.044Z] 02:45:43     INFO -  DEBUG: Adding blocker CrashMonitor: Writing notifications to file after receiving profile-before-change and awaiting all checkpoints written for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2022-04-02T02:45:43.104Z] 02:45:43     INFO -  DEBUG: Adding blocker TelemetryController: shutting down for phase profile-before-change-telemetry
[task 2022-04-02T02:45:43.219Z] 02:45:43     INFO -  DEBUG: Adding blocker EnvironmentAddonBuilder for phase AddonManager: Waiting to start provider shutdown.
[task 2022-04-02T02:45:43.247Z] 02:45:43     INFO -  DEBUG: Adding blocker RemoteSettingsClient - finish IDB access. for phase profile-before-change
[task 2022-04-02T02:45:43.266Z] 02:45:43     INFO -  1648867543272	Marionette	INFO	Marionette enabled
[task 2022-04-02T02:45:43.553Z] 02:45:43     INFO -  DEBUG: Adding blocker PermissionManager: Flushing data for phase xpcom-will-shutdown
[task 2022-04-02T02:45:43.616Z] 02:45:43     INFO -  1648867543622	Marionette	TRACE	Received observer notification toplevel-window-ready
[task 2022-04-02T02:45:43.650Z] 02:45:43     INFO -  DEBUG: Completed blocker Update add-on blocklist state into add-on DB for phase AddonManager: Waiting to start provider shutdown.
[task 2022-04-02T02:45:43.672Z] 02:45:43     INFO -  DEBUG: Adding blocker ClientManagerService: start destroying IPC actors early for phase xpcom-will-shutdown
[task 2022-04-02T02:46:10.100Z] 02:46:10     INFO -  DEBUG: Adding blocker MediaShutdownManager: shutdown for phase profile-before-change
[task 2022-04-02T02:46:10.447Z] 02:46:10     INFO -  DEBUG: Adding blocker ServiceWorkerShutdownBlocker: shutting down Service Workers for phase profile-change-teardown
[task 2022-04-02T02:46:10.487Z] 02:46:10     INFO -  DEBUG: Adding blocker GMPProvider for phase AddonManager: Waiting for providers to shut down.
[task 2022-04-02T02:46:10.497Z] 02:46:10     INFO -  DEBUG: Adding blocker ContentParent: id=12700ce44680 for phase xpcom-will-shutdown
[task 2022-04-02T02:46:10.504Z] 02:46:10     INFO -  DEBUG: Adding blocker ContentParent: id=12700ce44680 for phase profile-before-change
[task 2022-04-02T02:46:10.861Z] 02:46:10     INFO -  DEBUG: Adding blocker ContentParent: id=12700ceccf80 for phase xpcom-will-shutdown
[task 2022-04-02T02:46:10.876Z] 02:46:10     INFO -  DEBUG: Adding blocker ContentParent: id=12700ceccf80 for phase profile-before-change
[task 2022-04-02T02:46:11.659Z] 02:46:11     INFO -  DEBUG: Adding blocker ContentParent: id=12700d075a80 for phase xpcom-will-shutdown
[task 2022-04-02T02:46:11.668Z] 02:46:11     INFO -  DEBUG: Adding blocker ContentParent: id=12700d075a80 for phase profile-before-change
[task 2022-04-02T02:46:57.378Z] 02:46:57     INFO -  DEBUG: Adding blocker PageActions: purging unregistered actions from cache for phase profile-before-change
[task 2022-04-02T02:46:57.416Z] 02:46:57     INFO -  DEBUG: Adding blocker Places Clients shutdown for phase profile-change-teardown
[task 2022-04-02T02:46:57.428Z] 02:46:57     INFO -  DEBUG: Adding blocker Places Connection shutdown for phase profile-before-change
[task 2022-04-02T02:46:57.478Z] 02:46:57     INFO -  DEBUG: Adding blocker sanitize.js: Sanitize on shutdown for phase Places Clients shutdown
 INFO -  console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at C:\\Users\\task_164885867147513\\AppData\\Local\\Temp\\tmpqjsauqfq.mozrunner\\search.json.mozlz4", (void 0)))
[task 2022-04-02T02:47:52.454Z] 02:47:52    ERROR -  TEST-UNEXPECTED-ERROR | testing/marionette/harness/marionette_harness/tests/unit/test_cli_arguments.py TestCommandLineArguments.test_debugger_address_cdp_status | OSError: Process has been unexpectedly closed (Exit code: 572) (Reason: Process killed after 120s because no connection to Marionette server could be established. Check gecko.log for errors)
[task 2022-04-02T02:47:52.467Z] 02:47:52     INFO -  Traceback (most recent call last):
[task 2022-04-02T02:47:52.467Z] 02:47:52     INFO -    File "Z:\task_164885867147513\build\venv\lib\site-packages\marionette_harness\marionette_test\testcases.py", line 235, in run
[task 2022-04-02T02:47:52.467Z] 02:47:52     INFO -      self.tearDown()
[task 2022-04-02T02:47:52.468Z] 02:47:52     INFO -    File "Z:\task_164885867147513\build\tests\marionette\tests\testing\marionette\harness\marionette_harness\tests\unit\test_cli_arguments.py", line 24, in tearDown
[task 2022-04-02T02:47:52.468Z] 02:47:52     INFO -      super(TestCommandLineArguments, self).tearDown()
[task 2022-04-02T02:47:52.468Z] 02:47:52     INFO -    File "Z:\task_164885867147513\build\venv\lib\site-packages\marionette_harness\marionette_test\testcases.py", line 412, in tearDown
[task 2022-04-02T02:47:52.468Z] 02:47:52     INFO -      self.marionette.start_session()
[task 2022-04-02T02:47:52.469Z] 02:47:52     INFO -    File "Z:\task_164885867147513\build\venv\lib\site-packages\marionette_driver\decorators.py", line 37, in _
[task 2022-04-02T02:47:52.469Z] 02:47:52     INFO -      m._handle_socket_failure()
[task 2022-04-02T02:47:52.469Z] 02:47:52     INFO -    File "Z:\task_164885867147513\build\venv\lib\site-packages\marionette_driver\marionette.py", line 744, in _handle_socket_failure
[task 2022-04-02T02:47:52.470Z] 02:47:52     INFO -      reraise(

Marionette didn't even successfully initialize here. When the browser window opened something caused a shutdown of the application.

Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Summary: Intermittent testing/marionette/harness/marionette_harness/tests/unit/test_cli_arguments.py TestCommandLineArguments.test_debugger_address_cdp_status | OSError: Process has been unexpectedly closed (Exit code: 572) (Reason: Process killed after 120s becau → Intermittent testing/marionette/harness/marionette_harness/tests/unit/test_cli_arguments.py <test-name> | OSError: Process has been unexpectedly closed (Exit code: 572) (Reason: Process killed after 120s becau
Status: REOPENED → RESOLVED
Closed: 3 years ago3 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 3 years ago3 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

The new failures here will be tracked in bug 1784625 as it happens on a number of marionette tests.

Status: REOPENED → RESOLVED
Closed: 3 years ago3 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 3 years ago3 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 3 years ago2 years ago
Resolution: --- → INCOMPLETE
Product: Testing → Remote Protocol
Moving bug to Testing::Marionette Client and Harness component per bug 1815831.
Component: Marionette → Marionette Client and Harness
Product: Remote Protocol → Testing
You need to log in before you can comment on or make changes to this bug.