1850462 - Intermittent telemetry/marionette/tests/client/test_unicode_encoding.py TestUnicodeEncoding.test_unicode_encoding | OSError: Process has been unexpectedly closed (Exit code: 0) (Reason: Process unexpectedly quit without restarting (exit code: 0))

Status: RESOLVED INCOMPLETE

(Toolkit :: Telemetry, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2023-08-29T03:26:52.723Z] 03:26:52     INFO - TEST-START | telemetry/marionette/tests/client/test_unicode_encoding.py TestUnicodeEncoding.test_unicode_encoding
[task 2023-08-29T03:26:52.728Z] 03:26:52     INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox -no-remote -marionette -profile /builds/worker/workspace/build/tmp4551ymu8.mozrunner
[task 2023-08-29T03:26:53.287Z] 03:26:53     INFO -  [WARN  rkv::backend::impl_safe::environment] `load_ratio()` is irrelevant for this storage backend.
[task 2023-08-29T03:26:53.414Z] 03:26:53     INFO -  1693279613413	Toolkit.Telemetry	TRACE	TelemetryController::observe - profile-after-change notified.
[task 2023-08-29T03:26:53.415Z] 03:26:53     INFO -  1693279613413	Toolkit.Telemetry	TRACE	TelemetryController::setupTelemetry
[task 2023-08-29T03:26:53.419Z] 03:26:53     INFO -  1693279613418	Toolkit.Telemetry	TRACE	TelemetryReportingPolicy::setup
[task 2023-08-29T03:26:53.420Z] 03:26:53     INFO -  1693279613418	Toolkit.Telemetry	CONFIG	TelemetryController::enableTelemetryRecording - canRecordBase:true, canRecordExtended: false
[task 2023-08-29T03:26:53.421Z] 03:26:53     INFO -  1693279613419	Toolkit.Telemetry	TRACE	TelemetrySession::earlyInit
[task 2023-08-29T03:26:53.429Z] 03:26:53     INFO -  1693279613428	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet.
[task 2023-08-29T03:26:53.431Z] 03:26:53     INFO -  1693279613430	Toolkit.Telemetry	TRACE	UpdatePing::init - enabled: true
[task 2023-08-29T03:26:53.443Z] 03:26:53     INFO -  1693279613442	Toolkit.Telemetry	TRACE	TelemetryEnvironment::constructor
[task 2023-08-29T03:26:53.593Z] 03:26:53     INFO -  ATTENTION: default value of option mesa_glthread overridden by environment.
[task 2023-08-29T03:26:53.596Z] 03:26:53     INFO -  [Parent 6095, Renderer] WARNING: Failed to create EGLContext with khr_rbab_attribs: file /builds/worker/checkouts/gecko/gfx/gl/GLContextProviderEGL.cpp:737
[task 2023-08-29T03:26:53.597Z] 03:26:53     INFO -  [Parent 6095, Renderer] WARNING: Failed to create EGLContext with khr_robustness_attribs: file /builds/worker/checkouts/gecko/gfx/gl/GLContextProviderEGL.cpp:749
[task 2023-08-29T03:26:53.604Z] 03:26:53     INFO -  Initializing context 0x7ffac98284a0 surface (nil) on display 0x7ffac9886100
[task 2023-08-29T03:26:53.607Z] 03:26:53     INFO -  GL_VENDOR: VMware, Inc.
[task 2023-08-29T03:26:53.608Z] 03:26:53     INFO -  mVendor: VMware, Inc.
[task 2023-08-29T03:26:53.608Z] 03:26:53     INFO -  GL_RENDERER: llvmpipe (LLVM 10.0.0, 256 bits)
[task 2023-08-29T03:26:53.608Z] 03:26:53     INFO -  mRenderer: Unknown
[task 2023-08-29T03:26:53.609Z] 03:26:53     INFO -  mIsMesa: 1
[task 2023-08-29T03:26:53.610Z] 03:26:53     INFO -  [Parent 6095, Renderer] WARNING: robust_buffer_access_behavior marked as unsupported: file /builds/worker/checkouts/gecko/gfx/gl/GLContextFeatures.cpp:638
[task 2023-08-29T03:26:53.611Z] 03:26:53     INFO -  [Parent 6095, Renderer] WARNING: Robustness supported, strategy is not LOSE_CONTEXT_ON_RESET!: file /builds/worker/checkouts/gecko/gfx/gl/GLContext.cpp:984
[task 2023-08-29T03:26:53.611Z] 03:26:53     INFO -  [Parent 6095, Renderer] WARNING: robustness marked as unsupported: file /builds/worker/checkouts/gecko/gfx/gl/GLContextFeatures.cpp:638
[task 2023-08-29T03:26:53.619Z] 03:26:53     INFO -  1693279613618	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_getGFXData - Only one display adapter detected.
[task 2023-08-29T03:26:53.624Z] 03:26:53     INFO -  1693279613624	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_updateSearchEngine - ignoring early call
[task 2023-08-29T03:26:53.626Z] 03:26:53     INFO -  1693279613625	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_updateAddons
[task 2023-08-29T03:26:53.629Z] 03:26:53     INFO -  1693279613629	Toolkit.Telemetry	TRACE	TelemetryEnvironment::registerChangeListener for CrashAnnotator
[task 2023-08-29T03:26:53.647Z] 03:26:53     INFO -  1693279613647	Marionette	INFO	Marionette enabled
[task 2023-08-29T03:26:53.650Z] 03:26:53     INFO -  1693279613650	Marionette	TRACE	Received observer notification final-ui-startup
[task 2023-08-29T03:26:53.680Z] 03:26:53     INFO -  [Parent 6095, Main Thread] WARNING: Ignoring duplicate observer.: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:2896
[task 2023-08-29T03:26:53.760Z] 03:26:53     INFO -  ATTENTION: default value of option mesa_glthread overridden by environment.
[task 2023-08-29T03:26:53.764Z] 03:26:53     INFO -  [Parent 6095, Main Thread] WARNING: GLX_swap_control unsupported, ASAP mode may still block on buffer swaps.: file /builds/worker/checkouts/gecko/gfx/gl/GLContextProviderGLX.cpp:213
[task 2023-08-29T03:26:53.773Z] 03:26:53     INFO -  [Parent 6095, Main Thread] WARNING: NS_ENSURE_TRUE(mRequest) failed: file /builds/worker/checkouts/gecko/netwerk/base/nsBaseChannel.cpp:901
[task 2023-08-29T03:26:53.775Z] 03:26:53     INFO -  [Parent 6095, Main Thread] WARNING: NS_ENSURE_TRUE(mRequest) failed: file /builds/worker/checkouts/gecko/netwerk/base/nsBaseChannel.cpp:901
[task 2023-08-29T03:26:53.776Z] 03:26:53     INFO -  [Parent 6095, Main Thread] WARNING: NS_ENSURE_TRUE(mRequest) failed: file /builds/worker/checkouts/gecko/netwerk/base/nsBaseChannel.cpp:901
[task 2023-08-29T03:26:53.777Z] 03:26:53     INFO -  [Parent 6095, Main Thread] WARNING: NS_ENSURE_TRUE(mRequest) failed: file /builds/worker/checkouts/gecko/netwerk/base/nsBaseChannel.cpp:901
[task 2023-08-29T03:26:53.777Z] 03:26:53     INFO -  [Parent 6095, Main Thread] WARNING: NS_ENSURE_TRUE(mRequest) failed: file /builds/worker/checkouts/gecko/netwerk/base/nsBaseChannel.cpp:901
[task 2023-08-29T03:26:53.779Z] 03:26:53     INFO -  [Parent 6095, Main Thread] WARNING: NS_ENSURE_TRUE(mRequest) failed: file /builds/worker/checkouts/gecko/netwerk/base/nsBaseChannel.cpp:901
[task 2023-08-29T03:26:53.781Z] 03:26:53     INFO -  [Parent 6095, Main Thread] WARNING: NS_ENSURE_TRUE(mRequest) failed: file /builds/worker/checkouts/gecko/netwerk/base/nsBaseChannel.cpp:901
[task 2023-08-29T03:26:53.782Z] 03:26:53     INFO -  [Parent 6095, Main Thread] WARNING: NS_ENSURE_TRUE(mRequest) failed: file /builds/worker/checkouts/gecko/netwerk/base/nsBaseChannel.cpp:901
[task 2023-08-29T03:26:53.782Z] 03:26:53     INFO -  [Parent 6095, Main Thread] WARNING: NS_ENSURE_TRUE(mRequest) failed: file /builds/worker/checkouts/gecko/netwerk/base/nsBaseChannel.cpp:901
[task 2023-08-29T03:26:53.783Z] 03:26:53     INFO -  [Parent 6095, Main Thread] WARNING: NS_ENSURE_TRUE(mRequest) failed: file /builds/worker/checkouts/gecko/netwerk/base/nsBaseChannel.cpp:901
[task 2023-08-29T03:26:53.784Z] 03:26:53     INFO -  [Parent 6095, Main Thread] WARNING: NS_ENSURE_TRUE(mRequest) failed: file /builds/worker/checkouts/gecko/netwerk/base/nsBaseChannel.cpp:901
[task 2023-08-29T03:26:53.784Z] 03:26:53     INFO -  [Parent 6095, Main Thread] WARNING: NS_ENSURE_TRUE(mRequest) failed: file /builds/worker/checkouts/gecko/netwerk/base/nsBaseChannel.cpp:901
[task 2023-08-29T03:26:53.796Z] 03:26:53     INFO -  1693279613796	Marionette	INFO	Listening on port 2828
[task 2023-08-29T03:26:53.801Z] 03:26:53     INFO -  1693279613800	Marionette	DEBUG	Marionette is listening
[task 2023-08-29T03:26:53.805Z] 03:26:53     INFO -  1693279613805	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_updateAddons: addons differ
[task 2023-08-29T03:26:53.827Z] 03:26:53     INFO -  1693279613827	Marionette	DEBUG	Accepted connection 0 from 127.0.0.1:54974
[task 2023-08-29T03:26:53.886Z] 03:26:53     INFO -  1693279613886	Marionette	DEBUG	Accepted connection 1 from 127.0.0.1:54976
<...>
[task 2023-08-29T03:27:03.653Z] 03:27:03     INFO -  [Parent 6095: StreamTrans #12,SHDRCV]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-08-29T03:27:03.653Z] 03:27:03     INFO -  [Parent 6095: StreamTrans #12,SHDRCV]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-08-29T03:27:03.653Z] 03:27:03     INFO -  [Parent 6095: StreamTrans #19,SHDRCV]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-08-29T03:27:03.653Z] 03:27:03     INFO -  [Parent 6095: StreamTrans #19,SHDRCV]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-08-29T03:27:03.653Z] 03:27:03     INFO -  [Parent 6095: Timer]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-08-29T03:27:03.653Z] 03:27:03     INFO -  [Parent 6095: Timer,SHDRCV]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-08-29T03:27:03.653Z] 03:27:03     INFO -  [Parent 6095: Timer,SHDRCV]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-08-29T03:27:03.653Z] 03:27:03     INFO -  [Parent 6095: BackgroundThreadPool #1,SHDRCV]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-08-29T03:27:03.653Z] 03:27:03     INFO -  [Parent 6095: BackgroundThreadPool #1,SHDRCV]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-08-29T03:27:03.653Z] 03:27:03     INFO -  [Parent 6095: BgIOThreadPool #1,SHDRCV]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-08-29T03:27:03.653Z] 03:27:03     INFO -  [Parent 6095: BgIOThreadPool #1,SHDRCV]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-08-29T03:27:03.653Z] 03:27:03     INFO -  [Parent 6095: Compositor,SHDRCV]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-08-29T03:27:03.653Z] 03:27:03     INFO -  [Parent 6095: Compositor,SHDRCV]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-08-29T03:27:03.655Z] 03:27:03     INFO -  [Parent 6095: Permission,SHDRCV]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-08-29T03:27:03.655Z] 03:27:03     INFO -  [Parent 6095: Permission,SHDRCV]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-08-29T03:27:03.655Z] 03:27:03     INFO -  [Parent 6095: SandboxReporter]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-08-29T03:27:03.659Z] 03:27:03     INFO - pingserver pings_handler received 'first-shutdown' ping
[task 2023-08-29T03:27:04.110Z] 03:27:04     INFO -  [Parent 6095, Main Thread] WARNING: '!top', file /builds/worker/checkouts/gecko/dom/xul/MenuBarListener.cpp:99
[task 2023-08-29T03:27:04.345Z] 03:27:04     INFO -  [Parent 6095: AudioIPC Server RPC]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-08-29T03:27:04.346Z] 03:27:04     INFO -  [Parent 6095: AudioIPC Server Callback]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-08-29T03:27:04.346Z] 03:27:04     INFO -  [Parent 6095: AudioIPC DeviceCollection RPC]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-08-29T03:27:04.349Z] 03:27:04     INFO -  [Parent 6095: SoftwareVsyncThread]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-08-29T03:27:04.349Z] 03:27:04     INFO -  [Parent 6095: SoftwareVsyncThread]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-08-29T03:27:04.365Z] 03:27:04     INFO -  [Parent 6095: JS Watchdog]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-08-29T03:27:04.372Z] 03:27:04     INFO -  [Parent 6095: IPC I/O Parent]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-08-29T03:27:04.372Z] 03:27:04     INFO -  [Parent 6095: IPC I/O Parent]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-08-29T03:27:04.372Z] 03:27:04     INFO -  [Parent 6095: TaskController #1]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-08-29T03:27:04.373Z] 03:27:04     INFO -  [Parent 6095: TaskController #1]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-08-29T03:27:04.373Z] 03:27:04     INFO -  [Parent 6095: TaskController #0]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-08-29T03:27:04.373Z] 03:27:04     INFO -  [Parent 6095: TaskController #0]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-08-29T03:27:04.377Z] 03:27:04     INFO -  [Parent 6095, Main Thread] WARNING: WaylandDisplayRelease(): Wayland display is missing!: file /builds/worker/checkouts/gecko/widget/gtk/nsWaylandDisplay.cpp:31
[task 2023-08-29T03:27:04.378Z] 03:27:04     INFO -  [Parent 6095: Main Thread]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-08-29T03:27:04.378Z] 03:27:04     INFO -  [Parent 6095: Main Thread]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-08-29T03:27:04.566Z] 03:27:04     INFO -  Inconsistency detected by ld.so: ../elf/dl-tls.c: 481: _dl_allocate_tls_init: Assertion `listp->slotinfo[cnt].gen <= GL(dl_tls_generation)' failed!
[task 2023-08-29T03:30:13.059Z] 03:30:13     INFO - TEST-UNEXPECTED-ERROR | telemetry/marionette/tests/client/test_unicode_encoding.py TestUnicodeEncoding.test_unicode_encoding | OSError: Process has been unexpectedly closed (Exit code: 0) (Reason: Process unexpectedly quit without restarting (exit code: 0))
[task 2023-08-29T03:30:13.059Z] 03:30:13     INFO - Traceback (most recent call last):
[task 2023-08-29T03:30:13.059Z] 03:30:13     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_harness/marionette_test/testcases.py", line 198, in run
[task 2023-08-29T03:30:13.059Z] 03:30:13     INFO -     testMethod()
[task 2023-08-29T03:30:13.059Z] 03:30:13     INFO -   File "/builds/worker/workspace/build/tests/telemetry/marionette/tests/client/test_unicode_encoding.py", line 34, in test_unicode_encoding
[task 2023-08-29T03:30:13.059Z] 03:30:13     INFO -     ping1 = self.wait_for_ping(self.restart_browser, MAIN_SHUTDOWN_PING)
[task 2023-08-29T03:30:13.059Z] 03:30:13     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/telemetry_harness/testcase.py", line 138, in wait_for_ping
[task 2023-08-29T03:30:13.059Z] 03:30:13     INFO -     action_func, ping_filter, 1, ping_server=ping_server
[task 2023-08-29T03:30:13.059Z] 03:30:13     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/telemetry_harness/testcase.py", line 124, in wait_for_pings
[task 2023-08-29T03:30:13.059Z] 03:30:13     INFO -     action_func()
[task 2023-08-29T03:30:13.060Z] 03:30:13     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/telemetry_harness/testcase.py", line 144, in restart_browser
[task 2023-08-29T03:30:13.060Z] 03:30:13     INFO -     return self.marionette.restart(clean=False, in_app=True)
[task 2023-08-29T03:30:13.060Z] 03:30:13     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_driver/decorators.py", line 34, in _
[task 2023-08-29T03:30:13.060Z] 03:30:13     INFO -     m._handle_socket_failure()
[task 2023-08-29T03:30:13.060Z] 03:30:13     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_driver/marionette.py", line 800, in _handle_socket_failure
[task 2023-08-29T03:30:13.060Z] 03:30:13     INFO -     IOError, IOError(message.format(returncode=returncode, reason=exc)), tb
[task 2023-08-29T03:30:13.060Z] 03:30:13     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/six.py", line 702, in reraise
[task 2023-08-29T03:30:13.060Z] 03:30:13     INFO -     raise value.with_traceback(tb)
[task 2023-08-29T03:30:13.060Z] 03:30:13     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_driver/decorators.py", line 24, in _
[task 2023-08-29T03:30:13.060Z] 03:30:13     INFO -     return func(*args, **kwargs)
[task 2023-08-29T03:30:13.060Z] 03:30:13     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_driver/marionette.py", line 1237, in restart
[task 2023-08-29T03:30:13.061Z] 03:30:13     INFO -     tb,
[task 2023-08-29T03:30:13.061Z] 03:30:13     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/six.py", line 702, in reraise
[task 2023-08-29T03:30:13.061Z] 03:30:13     INFO -     raise value.with_traceback(tb)
[task 2023-08-29T03:30:13.061Z] 03:30:13     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_driver/marionette.py", line 1217, in restart
[task 2023-08-29T03:30:13.061Z] 03:30:13     INFO -     self.raise_for_port(timeout=timeout_restart, check_process_status=False)
[task 2023-08-29T03:30:13.061Z] 03:30:13     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_driver/marionette.py", line 692, in raise_for_port
[task 2023-08-29T03:30:13.061Z] 03:30:13     INFO -     self.host, self.port
[task 2023-08-29T03:30:13.061Z] 03:30:13     INFO - TEST-INFO took 200333ms
[task 2023-08-29T03:30:13.063Z] 03:30:13    ERROR - test_end for telemetry/marionette/tests/client/test_unicode_encoding.py TestUnicodeEncoding.test_unicode_encoding 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.7/site-packages/marionette_harness/marionette_test/testcases.py\", line 231, in run\n    self.tearDown()\n  File \"/builds/worker/workspace/build/venv/lib/python3.7/site-packages/telemetry_harness/testcase.py\", line 231, in tearDown\n    super(TelemetryTestCase, self).tearDown()\n  File \"/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_harness/runner/mixins/window_manager.py\", line 22, in tearDown\n    if len(self.marionette.chrome_window_handles) > len(self.start_windows):\n  File \"/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_driver/marionette.py\", line 1472, in chrome_window_handles\n    with self.using_context(\"chrome\"):\n  File \"/usr/lib/python3.7/contextlib.py\", line 112, in __enter__\n    return next(self.gen)\n  File \"/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_driver/marionette.py\", line 1541, in using_context\n    scope = self._send_message(\"Marionette:GetContext\", key=\"value\")\n  File \"/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_driver/decorators.py\", line 24, in _\n    return func(*args, **kwargs)\n  File \"/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_driver/marionette.py\", line 712, in _send_message\n    raise errors.InvalidSessionIdException(\"Please start a session\")\n", "extra": {"class_name": "test_unicode_encoding.TestUnicodeEncoding", "method_name": "test_unicode_encoding"}, "test": "telemetry/marionette/tests/client/test_unicode_encoding.py TestUnicodeEncoding.test_unicode_encoding", "status": "ERROR"}
[task 2023-08-29T03:30:13.104Z] 03:30:13     INFO - TEST-START | telemetry/marionette/tests/unit/test_ping_server_received_ping.py TestPingServer.test_ping_server_received_ping
[task 2023-08-29T03:30:13.106Z] 03:30:13     INFO -  Failed to start HTTP server on port 8000; is something already using that port?
[task 2023-08-29T03:30:13.110Z] 03:30:13     INFO - TEST-UNEXPECTED-ERROR | telemetry/marionette/tests/unit/test_ping_server_received_ping.py TestPingServer.test_ping_server_received_ping | OSError: [Errno 98] Address already in use
[task 2023-08-29T03:30:13.110Z] 03:30:13     INFO - Traceback (most recent call last):
[task 2023-08-29T03:30:13.110Z] 03:30:13     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_harness/marionette_test/testcases.py", line 179, in run
[task 2023-08-29T03:30:13.111Z] 03:30:13     INFO -     self.setUp()
[task 2023-08-29T03:30:13.111Z] 03:30:13     INFO -   File "/builds/worker/workspace/build/tests/telemetry/marionette/tests/unit/test_ping_server_received_ping.py", line 12, in setUp
[task 2023-08-29T03:30:13.111Z] 03:30:13     INFO -     super(TestPingServer, self).setUp(*args, **kwargs)
[task 2023-08-29T03:30:13.111Z] 03:30:13     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/telemetry_harness/testcase.py", line 33, in setUp
[task 2023-08-29T03:30:13.111Z] 03:30:13     INFO -     self.testvars["server_root"], self.testvars["server_url"]
[task 2023-08-29T03:30:13.111Z] 03:30:13     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/telemetry_harness/ping_server.py", line 64, in __init__
[task 2023-08-29T03:30:13.111Z] 03:30:13     INFO -     self._httpd = httpd.FixtureServer(server_root, url=url)
[task 2023-08-29T03:30:13.112Z] 03:30:13     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_harness/runner/httpd.py", line 162, in __init__
[task 2023-08-29T03:30:13.112Z] 03:30:13     INFO -     key_file=ssl_key,
[task 2023-08-29T03:30:13.112Z] 03:30:13     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/wptserve/server.py", line 838, in __init__
[task 2023-08-29T03:30:13.112Z] 03:30:13     INFO -     http2=http2)
[task 2023-08-29T03:30:13.112Z] 03:30:13     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/wptserve/server.py", line 192, in __init__
[task 2023-08-29T03:30:13.112Z] 03:30:13     INFO -     super().__init__(hostname_port, request_handler_cls)
[task 2023-08-29T03:30:13.112Z] 03:30:13     INFO -   File "/usr/lib/python3.7/socketserver.py", line 452, in __init__
[task 2023-08-29T03:30:13.113Z] 03:30:13     INFO -     self.server_bind()
[task 2023-08-29T03:30:13.113Z] 03:30:13     INFO -   File "/usr/lib/python3.7/http/server.py", line 137, in server_bind
[task 2023-08-29T03:30:13.113Z] 03:30:13     INFO -     socketserver.TCPServer.server_bind(self)
[task 2023-08-29T03:30:13.113Z] 03:30:13     INFO -   File "/usr/lib/python3.7/socketserver.py", line 466, in server_bind
[task 2023-08-29T03:30:13.113Z] 03:30:13     INFO -     self.socket.bind(self.server_address)
[task 2023-08-29T03:30:13.113Z] 03:30:13     INFO - TEST-INFO took 5ms
[task 2023-08-29T03:30:13.260Z] 03:30:13    ERROR - 'TestPingServer' object has no attribute 'marionette'
[task 2023-08-29T03:30:13.260Z] 03:30:13    ERROR - Traceback (most recent call last):
[task 2023-08-29T03:30:13.261Z] 03:30:13    ERROR - 
[task 2023-08-29T03:30:13.261Z] 03:30:13    ERROR -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_harness/runtests.py", line 105, in cli
[task 2023-08-29T03:30:13.261Z] 03:30:13    ERROR -     failed = harness_instance.run()
[task 2023-08-29T03:30:13.261Z] 03:30:13    ERROR - 
[task 2023-08-29T03:30:13.261Z] 03:30:13    ERROR -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_harness/runtests.py", line 79, in run
[task 2023-08-29T03:30:13.261Z] 03:30:13    ERROR -     runner.run_tests(tests)
[task 2023-08-29T03:30:13.262Z] 03:30:13    ERROR - 
[task 2023-08-29T03:30:13.262Z] 03:30:13    ERROR -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_harness/runner/base.py", line 1019, in run_tests
[task 2023-08-29T03:30:13.262Z] 03:30:13    ERROR -     self.run_test_sets()
[task 2023-08-29T03:30:13.262Z] 03:30:13    ERROR - 
[task 2023-08-29T03:30:13.262Z] 03:30:13    ERROR -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_harness/runner/base.py", line 1245, in run_test_sets
[task 2023-08-29T03:30:13.262Z] 03:30:13    ERROR -     self.run_test_set(self.tests)
[task 2023-08-29T03:30:13.262Z] 03:30:13    ERROR - 
[task 2023-08-29T03:30:13.263Z] 03:30:13    ERROR -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_harness/runner/base.py", line 1215, in run_test_set
[task 2023-08-29T03:30:13.263Z] 03:30:13    ERROR -     self.run_test(test["filepath"], test["expected"])
[task 2023-08-29T03:30:13.263Z] 03:30:13    ERROR - 
[task 2023-08-29T03:30:13.263Z] 03:30:13    ERROR -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_harness/runner/base.py", line 1179, in run_test
[task 2023-08-29T03:30:13.263Z] 03:30:13    ERROR -     results = runner.run(suite)
[task 2023-08-29T03:30:13.263Z] 03:30:13    ERROR - 
[task 2023-08-29T03:30:13.263Z] 03:30:13    ERROR -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_harness/runner/base.py", line 256, in run
[task 2023-08-29T03:30:13.264Z] 03:30:13    ERROR -     result = super(MarionetteTextTestRunner, self).run(test)
[task 2023-08-29T03:30:13.264Z] 03:30:13    ERROR - 
[task 2023-08-29T03:30:13.264Z] 03:30:13    ERROR -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/moztest/adapters/unit.py", line 208, in run
[task 2023-08-29T03:30:13.264Z] 03:30:13    ERROR -     test(result)
[task 2023-08-29T03:30:13.264Z] 03:30:13    ERROR - 
[task 2023-08-29T03:30:13.264Z] 03:30:13    ERROR -   File "/usr/lib/python3.7/unittest/suite.py", line 84, in __call__
[task 2023-08-29T03:30:13.264Z] 03:30:13    ERROR -     return self.run(*args, **kwds)
[task 2023-08-29T03:30:13.265Z] 03:30:13    ERROR - 
[task 2023-08-29T03:30:13.265Z] 03:30:13    ERROR -   File "/usr/lib/python3.7/unittest/suite.py", line 122, in run
[task 2023-08-29T03:30:13.265Z] 03:30:13    ERROR -     test(result)
[task 2023-08-29T03:30:13.265Z] 03:30:13    ERROR - 
[task 2023-08-29T03:30:13.265Z] 03:30:13    ERROR -   File "/usr/lib/python3.7/unittest/case.py", line 676, in __call__
[task 2023-08-29T03:30:13.265Z] 03:30:13    ERROR -     return self.run(*args, **kwds)
[task 2023-08-29T03:30:13.265Z] 03:30:13    ERROR - 
[task 2023-08-29T03:30:13.266Z] 03:30:13    ERROR -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_harness/marionette_test/testcases.py", line 241, in run
[task 2023-08-29T03:30:13.266Z] 03:30:13    ERROR -     self.cleanTest()
[task 2023-08-29T03:30:13.266Z] 03:30:13    ERROR - 
[task 2023-08-29T03:30:13.266Z] 03:30:13    ERROR -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_harness/marionette_test/testcases.py", line 310, in cleanTest
[task 2023-08-29T03:30:13.266Z] 03:30:13    ERROR -     self._delete_session()
[task 2023-08-29T03:30:13.266Z] 03:30:13    ERROR - 
[task 2023-08-29T03:30:13.266Z] 03:30:13    ERROR -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_harness/marionette_test/testcases.py", line 315, in _delete_session
[task 2023-08-29T03:30:13.267Z] 03:30:13    ERROR -     if self.marionette.session is not None:
[task 2023-08-29T03:30:13.267Z] 03:30:13    ERROR - 
[task 2023-08-29T03:30:13.267Z] 03:30:13    ERROR - AttributeError: 'TestPingServer' object has no attribute 'marionette'
[task 2023-08-29T03:30:13.267Z] 03:30:13    ERROR - 
[task 2023-08-29T03:30:13.296Z] 03:30:13     INFO - Return code: 1
[task 2023-08-29T03:30:13.296Z] 03:30:13  WARNING - Got 2 unexpected statuses
[task 2023-08-29T03:30:13.296Z] 03:30:13    ERROR - No suite end message was emitted by this harness.
[task 2023-08-29T03:30:13.296Z] 03:30:13  WARNING - setting return code to 2
[task 2023-08-29T03:30:13.297Z] 03:30:13     INFO - Running post-action listener: _package_coverage_data
[task 2023-08-29T03:30:13.297Z] 03:30:13     INFO - Running post-action listener: _resource_record_post_action
[task 2023-08-29T03:30:13.297Z] 03:30:13     INFO - Running post-action listener: process_java_coverage_data
[task 2023-08-29T03:30:13.297Z] 03:30:13     INFO - [mozharness: 2023-08-29 03:30:13.297769Z] Finished run-tests step (success)
[task 2023-08-29T03:30:13.298Z] 03:30:13     INFO - [mozharness: 2023-08-29 03:30:13.297909Z] Running uninstall step.
[task 2023-08-29T03:30:13.298Z] 03:30:13     INFO - Running pre-action listener: _resource_record_pre_action
[task 2023-08-29T03:30:13.298Z] 03:30:13     INFO - Running main action method: uninstall
[task 2023-08-29T03:30:13.298Z] 03:30:13     INFO - Getting output from command: ['/builds/worker/workspace/build/venv/bin/mozuninstall', '/builds/worker/workspace/build/application']
[task 2023-08-29T03:30:13.299Z] 03:30:13     INFO - Copy/paste: /builds/worker/workspace/build/venv/bin/mozuninstall /builds/worker/workspace/build/application
[task 2023-08-29T03:30:13.548Z] 03:30:13     INFO - Return code: 0
[task 2023-08-29T03:30:13.548Z] 03:30:13     INFO - Running post-action listener: _resource_record_post_action
[task 2023-08-29T03:30:13.548Z] 03:30:13     INFO - [mozharness: 2023-08-29 03:30:13.548767Z] Finished uninstall step (success)
[task 2023-08-29T03:30:13.549Z] 03:30:13     INFO - Running post-run listener: _resource_record_post_run
[task 2023-08-29T03:30:13.593Z] 03:30:13     INFO - Total resource usage - Wall time: 412s; CPU: 37%; Read bytes: 405504; Write bytes: 1414352896; Read time: 56; Write time: 345048
[task 2023-08-29T03:30:13.594Z] 03:30:13     INFO - TinderboxPrint: CPU usage<br/>36.5%
[task 2023-08-29T03:30:13.594Z] 03:30:13     INFO - TinderboxPrint: I/O read bytes / time<br/>405,504 / 56
[task 2023-08-29T03:30:13.595Z] 03:30:13     INFO - TinderboxPrint: I/O write bytes / time<br/>1,414,352,896 / 345,048
[task 2023-08-29T03:30:13.595Z] 03:30:13     INFO - TinderboxPrint: CPU idle<br/>520.2 (63.4%)
[task 2023-08-29T03:30:13.595Z] 03:30:13     INFO - TinderboxPrint: CPU system<br/>31.8 (3.9%)
[task 2023-08-29T03:30:13.595Z] 03:30:13     INFO - TinderboxPrint: CPU user<br/>265.9 (32.4%)
[task 2023-08-29T03:30:13.596Z] 03:30:13     INFO - TinderboxPrint: Swap in / out<br/>0 / 0
[task 2023-08-29T03:30:13.596Z] 03:30:13     INFO - install - Wall time: 13s; CPU: 50%; Read bytes: 0; Write bytes: 27852800; Read time: 0; Write time: 1796
[task 2023-08-29T03:30:13.597Z] 03:30:13     INFO - run-tests - Wall time: 400s; CPU: 36%; Read bytes: 299008; Write bytes: 1384198144; Read time: 56; Write time: 342132
[task 2023-08-29T03:30:13.597Z] 03:30:13     INFO - uninstall - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2023-08-29T03:30:13.631Z] 03:30:13  WARNING - returning nonzero exit status 2
[task 2023-08-29T03:30:13.653Z] cleanup

Comment 1

[Intermittent Failures Robot]

1 failures in 3019 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• linux1804-64-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1850462&startday=2023-08-28&endday=2023-09-03&tree=all

Comment 2

[Intermittent Failures Robot]

2 failures in 3267 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1
• mozilla-esr115: 1

Platform and build breakdown:

• linux1804-64-qr: 1
  • opt: 1
• linux1804-64-tsan-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1850462&startday=2023-09-04&endday=2023-09-10&tree=all

Comment 3

[Intermittent Failures Robot]

1 failures in 3337 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1

Platform and build breakdown:

• windows11-64-2009-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1850462&startday=2023-09-11&endday=2023-09-17&tree=all

Comment 4

[BugBot [:suhaib / :marco/ :calixte]]

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

Comment 5

[Treeherder Bug Filer]

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=437991280&repo=mozilla-beta

Comment 6

[Intermittent Failures Robot]

1 failures in 4108 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 1

Platform and build breakdown:

• linux2204-64-wayland-shippable: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1850462&startday=2023-11-27&endday=2023-12-03&tree=all

Comment 7

[BugBot [:suhaib / :marco/ :calixte]]

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

Comment 8

[Treeherder Bug Filer]

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=467554068&repo=mozilla-beta

Comment 9

[Intermittent Failures Robot]

1 failures in 4124 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 1

Platform and build breakdown:

• linux1804-64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1850462&startday=2024-07-22&endday=2024-07-28&tree=all

Comment 10

[BugBot [:suhaib / :marco/ :calixte]]

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