Closed Bug 1820238 Opened 3 years ago Closed 2 months ago

Intermittent telemetry/marionette/tests/client/test_shutdown_pings_succeed.py TestShutdownPingsSucced.test_shutdown_pings_succeed_pingsender2 | AssertionError: {'event': b'2.0', 'first-shutdown': b'2.0', 'main': b'', 'new-profile': b'2.0'} !=

Categories

(Toolkit :: Telemetry, defect, P5)

defect

Tracking

()

RESOLVED DUPLICATE of bug 2012689

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: assertion, intermittent-failure)

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


[task 2023-03-03T18:28:20.478Z] 18:28:20     INFO - TEST-START | telemetry/marionette/tests/client/test_shutdown_pings_succeed.py TestShutdownPingsSucced.test_shutdown_pings_succeed_pingsender2
[task 2023-03-03T18:28:20.481Z] 18:28:20     INFO - Application command: Z:\task_167786669104418\build\application\firefox\firefox.exe -no-remote -marionette --wait-for-browser -profile Z:\task_167786669104418\build\tmp79mvwgqt.mozrunner
[task 2023-03-03T18:28:20.808Z] 18:28:20     INFO -  1677868100820	Toolkit.Telemetry	TRACE	TelemetryController::observe - profile-after-change notified.
[task 2023-03-03T18:28:20.821Z] 18:28:20     INFO -  1677868100820	Toolkit.Telemetry	TRACE	TelemetryController::setupTelemetry
[task 2023-03-03T18:28:20.821Z] 18:28:20     INFO -  1677868100821	Toolkit.Telemetry	TRACE	TelemetryReportingPolicy::setup
[task 2023-03-03T18:28:20.822Z] 18:28:20     INFO -  1677868100821	Toolkit.Telemetry	CONFIG	TelemetryController::enableTelemetryRecording - canRecordBase:true, canRecordExtended: true
[task 2023-03-03T18:28:20.822Z] 18:28:20     INFO -  1677868100822	Toolkit.Telemetry	TRACE	TelemetrySession::earlyInit
[task 2023-03-03T18:28:20.826Z] 18:28:20     INFO -  1677868100825	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet.
[task 2023-03-03T18:28:20.826Z] 18:28:20     INFO -  1677868100826	Toolkit.Telemetry	TRACE	UpdatePing::init - enabled: true
[task 2023-03-03T18:28:20.831Z] 18:28:20     INFO -  1677868100831	Toolkit.Telemetry	TRACE	TelemetryEnvironment::constructor
[task 2023-03-03T18:28:20.870Z] 18:28:20     INFO -  1677868100878	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_getGFXData - Only one display adapter detected.
[task 2023-03-03T18:28:20.881Z] 18:28:20     INFO -  1677868100881	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_updateSearchEngine - ignoring early call
[task 2023-03-03T18:28:20.882Z] 18:28:20     INFO -  1677868100881	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_updateAddons
[task 2023-03-03T18:28:20.883Z] 18:28:20     INFO -  1677868100883	Toolkit.Telemetry	TRACE	TelemetryEnvironment::registerChangeListener for CrashAnnotator
[task 2023-03-03T18:28:20.891Z] 18:28:20     INFO -  1677868100890	Marionette	INFO	Marionette enabled
[task 2023-03-03T18:28:20.892Z] 18:28:20     INFO -  1677868100892	Marionette	TRACE	Received observer notification final-ui-startup
[task 2023-03-03T18:28:20.893Z] 18:28:20     INFO -  1677868100893	Marionette	INFO	Listening on port 2828
[task 2023-03-03T18:28:20.894Z] 18:28:20     INFO -  1677868100894	Marionette	DEBUG	Marionette is listening
[task 2023-03-03T18:28:20.964Z] 18:28:20     INFO -  1677868100972	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_updateAddons: addons differ
[task 2023-03-03T18:28:21.135Z] 18:28:21     INFO -  1677868101147	Marionette	DEBUG	Accepted connection 0 from 127.0.0.1:50949
[task 2023-03-03T18:28:21.166Z] 18:28:21     INFO -  1677868101174	Marionette	DEBUG	Closed connection 0
<...>
[task 2023-03-03T18:28:24.107Z] 18:28:24     INFO -  [Parent 5456: Timer]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-03-03T18:28:24.107Z] 18:28:24     INFO -  [Parent 5456: Timer,SHDRCV]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-03-03T18:28:24.108Z] 18:28:24     INFO -  [Parent 5456: Timer,SHDRCV]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-03-03T18:28:24.108Z] 18:28:24     INFO -  [Parent 5456: BackgroundThreadPool #3,SHDRCV]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-03-03T18:28:24.108Z] 18:28:24     INFO -  [Parent 5456: BgIOThreadPool #5,SHDRCV]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-03-03T18:28:24.109Z] 18:28:24     INFO -  [Parent 5456: BHMgr Monitor,SHDRCV]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-03-03T18:28:24.110Z] 18:28:24     INFO -  [Parent 5456: BHMgr Processor,SHDRCV]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-03-03T18:28:24.111Z] 18:28:24     INFO -  [Parent 5456: Compositor,SHDRCV]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-03-03T18:28:24.111Z] 18:28:24     INFO -  [Parent 5456: Permission,SHDRCV]: I/glean_core::* [glean_core::dispatcher::global] Failed to launch a task on the queue. Discarding task.
[task 2023-03-03T18:28:25.396Z] 18:28:25     INFO - pingserver pings_handler received 'first-shutdown' ping
[task 2023-03-03T18:28:25.414Z] 18:28:25     INFO - pingserver pings_handler received 'main' ping with reason 'shutdown'
[task 2023-03-03T18:28:25.416Z] 18:28:25     INFO - pingserver pings_handler received 'event' ping
[task 2023-03-03T18:28:25.417Z] 18:28:25     INFO - pingserver pings_handler received 'new-profile' ping
[task 2023-03-03T18:28:25.420Z] 18:28:25     INFO - pingserver pings_handler received 'bhr' ping
[task 2023-03-03T18:28:25.709Z] 18:28:25     INFO - pingserver pings_handler received 'new-profile' ping
[task 2023-03-03T18:28:25.718Z] 18:28:25     INFO - pingserver pings_handler received 'event' ping
[task 2023-03-03T18:28:25.721Z] 18:28:25     INFO - pingserver pings_handler received 'first-shutdown' ping
[task 2023-03-03T18:28:26.274Z] 18:28:26     INFO - TEST-UNEXPECTED-FAIL | telemetry/marionette/tests/client/test_shutdown_pings_succeed.py TestShutdownPingsSucced.test_shutdown_pings_succeed_pingsender2 | AssertionError: {'event': b'2.0', 'first-shutdown': b'2.0', 'main': b'', 'new-profile': b'2.0'} != {'first-shutdown': b'', 'main': b'', 'event': b'', 'new-profile': b''}
[task 2023-03-03T18:28:26.274Z] 18:28:26     INFO - - {'event': b'2.0', 'first-shutdown': b'2.0', 'main': b'', 'new-profile': b'2.0'}
[task 2023-03-03T18:28:26.274Z] 18:28:26     INFO - ?             ---                       ---                                 ---
[task 2023-03-03T18:28:26.274Z] 18:28:26     INFO - 
[task 2023-03-03T18:28:26.274Z] 18:28:26     INFO - + {'event': b'', 'first-shutdown': b'', 'main': b'', 'new-profile': b''}
[task 2023-03-03T18:28:26.287Z] 18:28:26     INFO - Traceback (most recent call last):
[task 2023-03-03T18:28:26.287Z] 18:28:26     INFO -   File "Z:\task_167786669104418\build\venv\lib\site-packages\marionette_harness\marionette_test\testcases.py", line 198, in run
[task 2023-03-03T18:28:26.287Z] 18:28:26     INFO -     testMethod()
[task 2023-03-03T18:28:26.287Z] 18:28:26     INFO -   File "Z:\task_167786669104418\build\venv\lib\site-packages\marionette_harness\marionette_test\testcases.py", line 48, in wrapper
[task 2023-03-03T18:28:26.287Z] 18:28:26     INFO -     return func(self, *args, **kwargs)
[task 2023-03-03T18:28:26.287Z] 18:28:26     INFO -   File "Z:\task_167786669104418\build\tests\telemetry\marionette\tests\client\test_shutdown_pings_succeed.py", line 53, in test_shutdown_pings_succeed
[task 2023-03-03T18:28:26.287Z] 18:28:26     INFO -     self.assertEqual(
[task 2023-03-03T18:28:26.287Z] 18:28:26     INFO - TEST-INFO took 5700ms
[task 2023-03-03T18:28:28.824Z] 18:28:28     INFO - TEST-START | telemetry/marionette/tests/client/test_unicode_encoding.py TestUnicodeEncoding.test_unicode_encoding
Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Summary: Intermittent [tier 2] telemetry/marionette/tests/client/test_shutdown_pings_succeed.py TestShutdownPingsSucced.test_shutdown_pings_succeed_pingsender2 | AssertionError: {'event': b'2.0', 'first-shutdown': b'2.0', 'main': b'', 'new-profile': b'2.0'} != → Intermittent telemetry/marionette/tests/client/test_shutdown_pings_succeed.py TestShutdownPingsSucced.test_shutdown_pings_succeed_pingsender2 | AssertionError: {'event': b'2.0', 'first-shutdown': b'2.0', 'main': b'', 'new-profile': b'2.0'} !=
Status: REOPENED → RESOLVED
Closed: 3 years ago2 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 2 years ago2 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 2 years ago2 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 2 years ago1 year ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

This is the same underlying problem as bug 2012689 but for the second parameterized test instead of the first. Fixed in 149.

Status: REOPENED → RESOLVED
Closed: 1 year ago2 months ago
Duplicate of bug: 2012689
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.