1701874 - Perma linux ccov [tier 2] toolkit/components/telemetry/tests/unit/test_TelemetrySend.js | xpcshell return code: -11

Status: RESOLVED INCOMPLETE

(Toolkit :: Telemetry, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2021-03-30T05:49:20.128Z] 05:49:20     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_webextensions_valid.js | took 2878ms
[task 2021-03-30T05:49:20.135Z] 05:49:20     INFO -  TEST-START | toolkit/components/telemetry/tests/unit/test_TelemetrySend.js
[task 2021-03-30T05:49:23.780Z] 05:49:23  WARNING -  TEST-UNEXPECTED-FAIL | toolkit/components/telemetry/tests/unit/test_TelemetrySend.js | xpcshell return code: -11
[task 2021-03-30T05:49:23.780Z] 05:49:23     INFO -  TEST-INFO took 3645ms
[task 2021-03-30T05:49:23.780Z] 05:49:23     INFO -  >>>>>>>
[task 2021-03-30T05:49:23.780Z] 05:49:23     INFO -  PID 31026 | [CodeCoverage] Setting handlers for process 31026.
[task 2021-03-30T05:49:23.780Z] 05:49:23     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2021-03-30T05:49:23.780Z] 05:49:23     INFO -  (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2021-03-30T05:49:23.781Z] 05:49:23     INFO -  (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2021-03-30T05:49:23.781Z] 05:49:23     INFO -  running event loop
[task 2021-03-30T05:49:23.781Z] 05:49:23     INFO -  toolkit/components/telemetry/tests/unit/test_TelemetrySend.js | Starting test_setup
[task 2021-03-30T05:49:23.782Z] 05:49:23     INFO -  (xpcshell/head.js) | test test_setup pending (2)
[task 2021-03-30T05:49:23.782Z] 05:49:23     INFO -  (xpcshell/head.js) | test run_next_test 0 finished (2)
[task 2021-03-30T05:49:23.782Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360460	addons.manager	DEBUG	Application has been upgraded"
[task 2021-03-30T05:49:23.782Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360461	addons.manager	DEBUG	Loaded provider scope for resource://gre/modules/addons/XPIProvider.jsm: ["XPIProvider", "XPIInternal"]"
[task 2021-03-30T05:49:23.782Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360468	addons.manager	DEBUG	Loaded provider scope for resource://gre/modules/addons/GMPProvider.jsm"
[task 2021-03-30T05:49:23.783Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360470	addons.manager	DEBUG	Loaded provider scope for resource://gre/modules/addons/PluginProvider.jsm"
[task 2021-03-30T05:49:23.783Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360471	addons.manager	DEBUG	Starting provider: XPIProvider"
[task 2021-03-30T05:49:23.783Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360471	addons.xpi	DEBUG	startup"
[task 2021-03-30T05:49:23.783Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360472	addons.xpi	INFO	SystemAddonLocation directory is missing"
[task 2021-03-30T05:49:23.783Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360486	addons.xpi	INFO	Removing all system add-on upgrades."
[task 2021-03-30T05:49:23.784Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360486	addons.xpi	DEBUG	checkForChanges"
[task 2021-03-30T05:49:23.784Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360486	addons.xpi	DEBUG	Loaded add-on state: ${}"
[task 2021-03-30T05:49:23.784Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360488	addons.xpi	DEBUG	New add-on [e-mail] in app-system-defaults"
[task 2021-03-30T05:49:23.784Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360489	addons.xpi	WARN	Can't get modified time of /tmp/xpc-profile-460f7y/sysfeatures/app0/[e-mail]"
[task 2021-03-30T05:49:23.784Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360489	addons.xpi	DEBUG	scanForChanges changed: true, state: {}"
[task 2021-03-30T05:49:23.785Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360499	addons.xpi-utils	DEBUG	Synchronously loading the add-ons database"
[task 2021-03-30T05:49:23.785Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360500	addons.xpi-utils	DEBUG	Starting async load of XPI database /tmp/xpc-profile-460f7y/extensions.json"
[task 2021-03-30T05:49:23.785Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360503	addons.xpi-utils	DEBUG	New add-on [e-mail] installed in app-system-defaults"
[task 2021-03-30T05:49:23.786Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360507	addons.xpi-utils	WARN	addMetadata: Add-on [e-mail] is invalid: [Exception... "Component returned failure code: 0x80520006 (NS_ERROR_FILE_TARGET_DOES_NOT_EXIST) [nsIFile.isFile]"  nsresult: "0x80520006 (NS_ERROR_FILE_TARGET_DOES_NOT_EXIST)"  location: "JS frame :: resource://gre/modules/addons/XPIInstall.jsm :: get :: line 232"  data: no] Stack trace: get()@resource://gre/modules/addons/XPIInstall.jsm:232
[task 2021-03-30T05:49:23.786Z] 05:49:23     INFO -  syncLoadManifest()@resource://gre/modules/addons/XPIInstall.jsm:751
[task 2021-03-30T05:49:23.786Z] 05:49:23     INFO -  addMetadata()@resource://gre/modules/addons/XPIDatabase.jsm:2826
[task 2021-03-30T05:49:23.787Z] 05:49:23     INFO -  processFileChanges()@resource://gre/modules/addons/XPIDatabase.jsm:3291
[task 2021-03-30T05:49:23.787Z] 05:49:23     INFO -  checkForChanges()@resource://gre/modules/addons/XPIProvider.jsm:3023
[task 2021-03-30T05:49:23.787Z] 05:49:23     INFO -  startup()@resource://gre/modules/addons/XPIProvider.jsm:2470
[task 2021-03-30T05:49:23.787Z] 05:49:23     INFO -  callProvider()@resource://gre/modules/AddonManager.jsm:230
[task 2021-03-30T05:49:23.788Z] 05:49:23     INFO -  _startProvider()@resource://gre/modules/AddonManager.jsm:601
[task 2021-03-30T05:49:23.788Z] 05:49:23     INFO -  startup()@resource://gre/modules/AddonManager.jsm:825
[task 2021-03-30T05:49:23.788Z] 05:49:23     INFO -  startup()@resource://gre/modules/AddonManager.jsm:3522
[task 2021-03-30T05:49:23.788Z] 05:49:23     INFO -  observe()@resource://gre/modules/addonManager.js:87
[task 2021-03-30T05:49:23.788Z] 05:49:23     INFO -  promiseStartupManager()@resource://testing-common/AddonTestUtils.jsm:942
[task 2021-03-30T05:49:23.789Z] 05:49:23     INFO -  loadAddonManager()@/builds/worker/workspace/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/head.js:293
[task 2021-03-30T05:49:23.789Z] 05:49:23     INFO -  _do_main()@/builds/worker/workspace/build/tests/xpcshell/head.js:241
[task 2021-03-30T05:49:23.789Z] 05:49:23     INFO -  _execute_test()@/builds/worker/workspace/build/tests/xpcshell/head.js:598
[task 2021-03-30T05:49:23.789Z] 05:49:23     INFO -  -e:1"
[task 2021-03-30T05:49:23.790Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360508	addons.xpi-utils	WARN	Could not uninstall invalid item from locked install location"
[task 2021-03-30T05:49:23.790Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360510	addons.xpi-utils	DEBUG	Updating add-on states"
[task 2021-03-30T05:49:23.791Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360511	addons.xpi-utils	DEBUG	Synchronously loading the add-ons database"
[task 2021-03-30T05:49:23.791Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360513	addons.manager	DEBUG	Registering shutdown blocker for XPIProvider"
[task 2021-03-30T05:49:23.791Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360514	addons.manager	DEBUG	Provider finished startup: XPIProvider"
[task 2021-03-30T05:49:23.792Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360514	addons.manager	DEBUG	Starting provider: PluginProvider"
[task 2021-03-30T05:49:23.792Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360514	addons.manager	DEBUG	Registering shutdown blocker for PluginProvider"
[task 2021-03-30T05:49:23.792Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360514	addons.manager	DEBUG	Provider finished startup: PluginProvider"
[task 2021-03-30T05:49:23.793Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360514	addons.manager	DEBUG	Completed startup sequence"
[task 2021-03-30T05:49:23.793Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360567	Toolkit.Telemetry	TRACE	TelemetryEnvironment::constructor"
[task 2021-03-30T05:49:23.794Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360653	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_getGFXData - Only one display adapter detected."
[task 2021-03-30T05:49:23.794Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360657	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_updateSearchEngine - ignoring early call"
[task 2021-03-30T05:49:23.795Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360657	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_updateAddons"
[task 2021-03-30T05:49:23.795Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360663	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_updateAddons: addons differ"
[task 2021-03-30T05:49:23.796Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360663	addons.xpi-utils	DEBUG	XPI Database saved, setting schema version preference to 33"
[task 2021-03-30T05:49:23.796Z] 05:49:23     INFO -  (xpcshell/head.js) | test run_next_test 1 pending (2)
[task 2021-03-30T05:49:23.796Z] 05:49:23     INFO -  (xpcshell/head.js) | test test_setup finished (2)
[task 2021-03-30T05:49:23.796Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360668	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_startWatchingPrefs - [object Map]"
[task 2021-03-30T05:49:23.797Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360668	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_stopWatchingPrefs"
[task 2021-03-30T05:49:23.797Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360669	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_updateSearchEngine - ignoring early call"
[task 2021-03-30T05:49:23.798Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360669	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_startWatchingPrefs - [object Map]"
[task 2021-03-30T05:49:23.798Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360669	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: toolkit.telemetry.healthping.enabled"
[task 2021-03-30T05:49:23.798Z] 05:49:23     INFO -  toolkit/components/telemetry/tests/unit/test_TelemetrySend.js | Starting test_sendPendingPings
[task 2021-03-30T05:49:23.799Z] 05:49:23     INFO -  (xpcshell/head.js) | test test_sendPendingPings pending (2)
[task 2021-03-30T05:49:23.799Z] 05:49:23     INFO -  (xpcshell/head.js) | test run_next_test 1 finished (2)
[task 2021-03-30T05:49:23.799Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360673	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - type: test-sendPendingPings-A, aOptions: {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.800Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360674	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type test-sendPendingPings-A, aOptions {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.800Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360674	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - ping assembled, id: 93bd0011-2c8f-4e1c-bee0-a00000000000"
[task 2021-03-30T05:49:23.801Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360675	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - ping id: 93bd0011-2c8f-4e1c-bee0-a00000000000, options: {"usePingSender":false}"
[task 2021-03-30T05:49:23.802Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360675	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.802Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360675	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.802Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360675	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - can't send ping now, persisting to disk - canSendNow: false"
[task 2021-03-30T05:49:23.803Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360678	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/datareporting/archived/2021-03/1617098400000.93bd0011-2c8f-4e1c-bee0-a00000000000.test-sendPendingPings-A.jsonlz4"
[task 2021-03-30T05:49:23.803Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360682	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/saved-telemetry-pings/93bd0011-2c8f-4e1c-bee0-a00000000000"
[task 2021-03-30T05:49:23.804Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360682	Toolkit.Telemetry	TRACE	TelemetryStorage::savePendingPing - saved ping with id 93bd0011-2c8f-4e1c-bee0-a00000000000"
[task 2021-03-30T05:49:23.804Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360684	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - type: test-sendPendingPings-A, aOptions: {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.805Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360684	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type test-sendPendingPings-A, aOptions {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.805Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360684	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - ping assembled, id: 93bd0011-2c8f-4e1c-bee0-a00000000001"
[task 2021-03-30T05:49:23.806Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360685	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - ping id: 93bd0011-2c8f-4e1c-bee0-a00000000001, options: {"usePingSender":false}"
[task 2021-03-30T05:49:23.807Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360685	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.810Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360685	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.810Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360685	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - can't send ping now, persisting to disk - canSendNow: false"
[task 2021-03-30T05:49:23.810Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360687	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/datareporting/archived/2021-03/1617098400000.93bd0011-2c8f-4e1c-bee0-a00000000001.test-sendPendingPings-A.jsonlz4"
[task 2021-03-30T05:49:23.810Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360688	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/saved-telemetry-pings/93bd0011-2c8f-4e1c-bee0-a00000000001"
[task 2021-03-30T05:49:23.811Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360690	Toolkit.Telemetry	TRACE	TelemetryStorage::savePendingPing - saved ping with id 93bd0011-2c8f-4e1c-bee0-a00000000001"
[task 2021-03-30T05:49:23.811Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360691	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - type: test-sendPendingPings-A, aOptions: {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.811Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360692	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type test-sendPendingPings-A, aOptions {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.811Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360692	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - ping assembled, id: 93bd0011-2c8f-4e1c-bee0-a00000000002"
[task 2021-03-30T05:49:23.812Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360692	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - ping id: 93bd0011-2c8f-4e1c-bee0-a00000000002, options: {"usePingSender":false}"
[task 2021-03-30T05:49:23.812Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360692	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.812Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360693	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.813Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360693	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - can't send ping now, persisting to disk - canSendNow: false"
[task 2021-03-30T05:49:23.813Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360695	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/datareporting/archived/2021-03/1617098400000.93bd0011-2c8f-4e1c-bee0-a00000000002.test-sendPendingPings-A.jsonlz4"
[task 2021-03-30T05:49:23.813Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360696	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/saved-telemetry-pings/93bd0011-2c8f-4e1c-bee0-a00000000002"
[task 2021-03-30T05:49:23.813Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360698	Toolkit.Telemetry	TRACE	TelemetryStorage::savePendingPing - saved ping with id 93bd0011-2c8f-4e1c-bee0-a00000000002"
[task 2021-03-30T05:49:23.814Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360699	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - type: test-sendPendingPings-A, aOptions: {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.814Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360699	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type test-sendPendingPings-A, aOptions {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.814Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360699	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - ping assembled, id: 93bd0011-2c8f-4e1c-bee0-a00000000003"
[task 2021-03-30T05:49:23.814Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360700	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - ping id: 93bd0011-2c8f-4e1c-bee0-a00000000003, options: {"usePingSender":false}"
[task 2021-03-30T05:49:23.815Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360700	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.815Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360700	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.815Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360700	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - can't send ping now, persisting to disk - canSendNow: false"
[task 2021-03-30T05:49:23.815Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360702	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/datareporting/archived/2021-03/1617098400000.93bd0011-2c8f-4e1c-bee0-a00000000003.test-sendPendingPings-A.jsonlz4"
[task 2021-03-30T05:49:23.815Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360703	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/saved-telemetry-pings/93bd0011-2c8f-4e1c-bee0-a00000000003"
[task 2021-03-30T05:49:23.816Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360705	Toolkit.Telemetry	TRACE	TelemetryStorage::savePendingPing - saved ping with id 93bd0011-2c8f-4e1c-bee0-a00000000003"
[task 2021-03-30T05:49:23.816Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360706	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - type: test-sendPendingPings-A, aOptions: {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.816Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360706	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type test-sendPendingPings-A, aOptions {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.816Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360706	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - ping assembled, id: 93bd0011-2c8f-4e1c-bee0-a00000000004"
[task 2021-03-30T05:49:23.816Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360706	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - ping id: 93bd0011-2c8f-4e1c-bee0-a00000000004, options: {"usePingSender":false}"
[task 2021-03-30T05:49:23.816Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360706	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.816Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360706	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.816Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360706	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - can't send ping now, persisting to disk - canSendNow: false"
[task 2021-03-30T05:49:23.817Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360708	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/datareporting/archived/2021-03/1617098400000.93bd0011-2c8f-4e1c-bee0-a00000000004.test-sendPendingPings-A.jsonlz4"
[task 2021-03-30T05:49:23.817Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360709	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/saved-telemetry-pings/93bd0011-2c8f-4e1c-bee0-a00000000004"
[task 2021-03-30T05:49:23.817Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360711	Toolkit.Telemetry	TRACE	TelemetryStorage::savePendingPing - saved ping with id 93bd0011-2c8f-4e1c-bee0-a00000000004"
[task 2021-03-30T05:49:23.817Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360712	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - type: test-sendPendingPings-A, aOptions: {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.817Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360712	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type test-sendPendingPings-A, aOptions {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.817Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360712	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - ping assembled, id: 93bd0011-2c8f-4e1c-bee0-a00000000005"
[task 2021-03-30T05:49:23.817Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360713	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - ping id: 93bd0011-2c8f-4e1c-bee0-a00000000005, options: {"usePingSender":false}"
[task 2021-03-30T05:49:23.817Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360713	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.817Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360713	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.817Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360713	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - can't send ping now, persisting to disk - canSendNow: false"
[task 2021-03-30T05:49:23.817Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360715	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/datareporting/archived/2021-03/1617098400000.93bd0011-2c8f-4e1c-bee0-a00000000005.test-sendPendingPings-A.jsonlz4"
[task 2021-03-30T05:49:23.818Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360716	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/saved-telemetry-pings/93bd0011-2c8f-4e1c-bee0-a00000000005"
[task 2021-03-30T05:49:23.818Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360718	Toolkit.Telemetry	TRACE	TelemetryStorage::savePendingPing - saved ping with id 93bd0011-2c8f-4e1c-bee0-a00000000005"
[task 2021-03-30T05:49:23.818Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360719	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - type: test-sendPendingPings-A, aOptions: {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.818Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360719	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type test-sendPendingPings-A, aOptions {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.818Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360720	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - ping assembled, id: 93bd0011-2c8f-4e1c-bee0-a00000000006"
[task 2021-03-30T05:49:23.819Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360720	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - ping id: 93bd0011-2c8f-4e1c-bee0-a00000000006, options: {"usePingSender":false}"
[task 2021-03-30T05:49:23.819Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360720	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.819Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360720	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.820Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360720	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - can't send ping now, persisting to disk - canSendNow: false"
[task 2021-03-30T05:49:23.820Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360722	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/datareporting/archived/2021-03/1617098400000.93bd0011-2c8f-4e1c-bee0-a00000000006.test-sendPendingPings-A.jsonlz4"
[task 2021-03-30T05:49:23.820Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360723	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/saved-telemetry-pings/93bd0011-2c8f-4e1c-bee0-a00000000006"
[task 2021-03-30T05:49:23.820Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360724	Toolkit.Telemetry	TRACE	TelemetryStorage::savePendingPing - saved ping with id 93bd0011-2c8f-4e1c-bee0-a00000000006"
[task 2021-03-30T05:49:23.820Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360725	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - type: test-sendPendingPings-A, aOptions: {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.820Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360726	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type test-sendPendingPings-A, aOptions {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.821Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360726	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - ping assembled, id: 93bd0011-2c8f-4e1c-bee0-a00000000007"
[task 2021-03-30T05:49:23.821Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360726	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - ping id: 93bd0011-2c8f-4e1c-bee0-a00000000007, options: {"usePingSender":false}"
[task 2021-03-30T05:49:23.821Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360726	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.822Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360726	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.822Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360726	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - can't send ping now, persisting to disk - canSendNow: false"
[task 2021-03-30T05:49:23.822Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360728	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/datareporting/archived/2021-03/1617098400000.93bd0011-2c8f-4e1c-bee0-a00000000007.test-sendPendingPings-A.jsonlz4"
[task 2021-03-30T05:49:23.822Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360729	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/saved-telemetry-pings/93bd0011-2c8f-4e1c-bee0-a00000000007"
[task 2021-03-30T05:49:23.822Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360731	Toolkit.Telemetry	TRACE	TelemetryStorage::savePendingPing - saved ping with id 93bd0011-2c8f-4e1c-bee0-a00000000007"
[task 2021-03-30T05:49:23.822Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360732	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - type: test-sendPendingPings-A, aOptions: {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.823Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360732	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type test-sendPendingPings-A, aOptions {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.823Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360732	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - ping assembled, id: 93bd0011-2c8f-4e1c-bee0-a00000000008"
[task 2021-03-30T05:49:23.824Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360733	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - ping id: 93bd0011-2c8f-4e1c-bee0-a00000000008, options: {"usePingSender":false}"
[task 2021-03-30T05:49:23.824Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360733	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.824Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360733	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.824Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360733	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - can't send ping now, persisting to disk - canSendNow: false"
[task 2021-03-30T05:49:23.824Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360735	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/datareporting/archived/2021-03/1617098400000.93bd0011-2c8f-4e1c-bee0-a00000000008.test-sendPendingPings-A.jsonlz4"
[task 2021-03-30T05:49:23.824Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360736	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/saved-telemetry-pings/93bd0011-2c8f-4e1c-bee0-a00000000008"
[task 2021-03-30T05:49:23.824Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360737	Toolkit.Telemetry	TRACE	TelemetryStorage::savePendingPing - saved ping with id 93bd0011-2c8f-4e1c-bee0-a00000000008"
[task 2021-03-30T05:49:23.824Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360738	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - type: test-sendPendingPings-A, aOptions: {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.824Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360738	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type test-sendPendingPings-A, aOptions {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.824Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360738	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - ping assembled, id: 93bd0011-2c8f-4e1c-bee0-a00000000009"
[task 2021-03-30T05:49:23.824Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360739	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - ping id: 93bd0011-2c8f-4e1c-bee0-a00000000009, options: {"usePingSender":false}"
[task 2021-03-30T05:49:23.824Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360739	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.824Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360739	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.824Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360739	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - can't send ping now, persisting to disk - canSendNow: false"
[task 2021-03-30T05:49:23.824Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360741	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/datareporting/archived/2021-03/1617098400000.93bd0011-2c8f-4e1c-bee0-a00000000009.test-sendPendingPings-A.jsonlz4"
[task 2021-03-30T05:49:23.824Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360742	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/saved-telemetry-pings/93bd0011-2c8f-4e1c-bee0-a00000000009"
[task 2021-03-30T05:49:23.824Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360744	Toolkit.Telemetry	TRACE	TelemetryStorage::savePendingPing - saved ping with id 93bd0011-2c8f-4e1c-bee0-a00000000009"
[task 2021-03-30T05:49:23.824Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360745	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - type: test-sendPendingPings-A, aOptions: {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.824Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360745	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type test-sendPendingPings-A, aOptions {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.824Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360745	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - ping assembled, id: 93bd0011-2c8f-4e1c-bee0-a00000000010"
[task 2021-03-30T05:49:23.825Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360746	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - ping id: 93bd0011-2c8f-4e1c-bee0-a00000000010, options: {"usePingSender":false}"
[task 2021-03-30T05:49:23.825Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360746	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.826Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360746	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.826Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360746	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - can't send ping now, persisting to disk - canSendNow: false"
[task 2021-03-30T05:49:23.826Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360748	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/datareporting/archived/2021-03/1617098400000.93bd0011-2c8f-4e1c-bee0-a00000000010.test-sendPendingPings-A.jsonlz4"
[task 2021-03-30T05:49:23.826Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360749	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/saved-telemetry-pings/93bd0011-2c8f-4e1c-bee0-a00000000010"
[task 2021-03-30T05:49:23.826Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360750	Toolkit.Telemetry	TRACE	TelemetryStorage::savePendingPing - saved ping with id 93bd0011-2c8f-4e1c-bee0-a00000000010"
[task 2021-03-30T05:49:23.826Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360752	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - type: test-sendPendingPings-A, aOptions: {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.827Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360752	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type test-sendPendingPings-A, aOptions {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.827Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360752	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - ping assembled, id: 93bd0011-2c8f-4e1c-bee0-a00000000011"
[task 2021-03-30T05:49:23.827Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360752	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - ping id: 93bd0011-2c8f-4e1c-bee0-a00000000011, options: {"usePingSender":false}"
[task 2021-03-30T05:49:23.828Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360752	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.828Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360752	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.828Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360752	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - can't send ping now, persisting to disk - canSendNow: false"
[task 2021-03-30T05:49:23.828Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360754	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/datareporting/archived/2021-03/1617098400000.93bd0011-2c8f-4e1c-bee0-a00000000011.test-sendPendingPings-A.jsonlz4"
[task 2021-03-30T05:49:23.828Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360755	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/saved-telemetry-pings/93bd0011-2c8f-4e1c-bee0-a00000000011"
[task 2021-03-30T05:49:23.828Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360756	Toolkit.Telemetry	TRACE	TelemetryStorage::savePendingPing - saved ping with id 93bd0011-2c8f-4e1c-bee0-a00000000011"
[task 2021-03-30T05:49:23.828Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360757	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - type: test-sendPendingPings-A, aOptions: {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.829Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360757	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type test-sendPendingPings-A, aOptions {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.829Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360757	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - ping assembled, id: 93bd0011-2c8f-4e1c-bee0-a00000000012"
[task 2021-03-30T05:49:23.830Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360757	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - ping id: 93bd0011-2c8f-4e1c-bee0-a00000000012, options: {"usePingSender":false}"
[task 2021-03-30T05:49:23.830Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360757	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.830Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360757	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.830Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360757	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - can't send ping now, persisting to disk - canSendNow: false"
[task 2021-03-30T05:49:23.830Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360759	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/datareporting/archived/2021-03/1617098400000.93bd0011-2c8f-4e1c-bee0-a00000000012.test-sendPendingPings-A.jsonlz4"
[task 2021-03-30T05:49:23.830Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360760	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/saved-telemetry-pings/93bd0011-2c8f-4e1c-bee0-a00000000012"
[task 2021-03-30T05:49:23.830Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360761	Toolkit.Telemetry	TRACE	TelemetryStorage::savePendingPing - saved ping with id 93bd0011-2c8f-4e1c-bee0-a00000000012"
[task 2021-03-30T05:49:23.830Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360762	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - type: test-sendPendingPings-A, aOptions: {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.831Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360762	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type test-sendPendingPings-A, aOptions {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.832Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360762	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - ping assembled, id: 93bd0011-2c8f-4e1c-bee0-a00000000013"
[task 2021-03-30T05:49:23.832Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360762	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - ping id: 93bd0011-2c8f-4e1c-bee0-a00000000013, options: {"usePingSender":false}"
[task 2021-03-30T05:49:23.832Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360763	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.834Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360763	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.834Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360763	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - can't send ping now, persisting to disk - canSendNow: false"
[task 2021-03-30T05:49:23.834Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360764	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/datareporting/archived/2021-03/1617098400000.93bd0011-2c8f-4e1c-bee0-a00000000013.test-sendPendingPings-A.jsonlz4"
[task 2021-03-30T05:49:23.834Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360765	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/saved-telemetry-pings/93bd0011-2c8f-4e1c-bee0-a00000000013"
[task 2021-03-30T05:49:23.834Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360766	Toolkit.Telemetry	TRACE	TelemetryStorage::savePendingPing - saved ping with id 93bd0011-2c8f-4e1c-bee0-a00000000013"
[task 2021-03-30T05:49:23.834Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360767	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - type: test-sendPendingPings-A, aOptions: {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.834Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360767	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type test-sendPendingPings-A, aOptions {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.835Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360767	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - ping assembled, id: 93bd0011-2c8f-4e1c-bee0-a00000000014"
[task 2021-03-30T05:49:23.835Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360768	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - ping id: 93bd0011-2c8f-4e1c-bee0-a00000000014, options: {"usePingSender":false}"
[task 2021-03-30T05:49:23.835Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360768	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.835Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360768	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.835Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360768	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - can't send ping now, persisting to disk - canSendNow: false"
[task 2021-03-30T05:49:23.835Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360769	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/datareporting/archived/2021-03/1617098400000.93bd0011-2c8f-4e1c-bee0-a00000000014.test-sendPendingPings-A.jsonlz4"
[task 2021-03-30T05:49:23.836Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360770	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/saved-telemetry-pings/93bd0011-2c8f-4e1c-bee0-a00000000014"
[task 2021-03-30T05:49:23.836Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360771	Toolkit.Telemetry	TRACE	TelemetryStorage::savePendingPing - saved ping with id 93bd0011-2c8f-4e1c-bee0-a00000000014"
[task 2021-03-30T05:49:23.836Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360772	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - type: test-sendPendingPings-A, aOptions: {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.836Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360772	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type test-sendPendingPings-A, aOptions {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.836Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360772	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - ping assembled, id: 93bd0011-2c8f-4e1c-bee0-a00000000015"
[task 2021-03-30T05:49:23.836Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360773	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - ping id: 93bd0011-2c8f-4e1c-bee0-a00000000015, options: {"usePingSender":false}"
[task 2021-03-30T05:49:23.836Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360773	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.837Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360773	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.838Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360773	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - can't send ping now, persisting to disk - canSendNow: false"
[task 2021-03-30T05:49:23.838Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360774	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/datareporting/archived/2021-03/1617098400000.93bd0011-2c8f-4e1c-bee0-a00000000015.test-sendPendingPings-A.jsonlz4"
[task 2021-03-30T05:49:23.838Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360775	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/saved-telemetry-pings/93bd0011-2c8f-4e1c-bee0-a00000000015"
[task 2021-03-30T05:49:23.838Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360777	Toolkit.Telemetry	TRACE	TelemetryStorage::savePendingPing - saved ping with id 93bd0011-2c8f-4e1c-bee0-a00000000015"
[task 2021-03-30T05:49:23.839Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360778	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - type: test-sendPendingPings-A, aOptions: {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.839Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360778	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type test-sendPendingPings-A, aOptions {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.839Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360778	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - ping assembled, id: 93bd0011-2c8f-4e1c-bee0-a00000000016"
[task 2021-03-30T05:49:23.839Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360778	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - ping id: 93bd0011-2c8f-4e1c-bee0-a00000000016, options: {"usePingSender":false}"
[task 2021-03-30T05:49:23.839Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360778	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.839Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360778	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.839Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360778	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - can't send ping now, persisting to disk - canSendNow: false"
[task 2021-03-30T05:49:23.841Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360780	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/datareporting/archived/2021-03/1617098400000.93bd0011-2c8f-4e1c-bee0-a00000000016.test-sendPendingPings-A.jsonlz4"
[task 2021-03-30T05:49:23.841Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360781	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/saved-telemetry-pings/93bd0011-2c8f-4e1c-bee0-a00000000016"
[task 2021-03-30T05:49:23.841Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360782	Toolkit.Telemetry	TRACE	TelemetryStorage::savePendingPing - saved ping with id 93bd0011-2c8f-4e1c-bee0-a00000000016"
[task 2021-03-30T05:49:23.841Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360783	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - type: test-sendPendingPings-A, aOptions: {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.842Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360783	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type test-sendPendingPings-A, aOptions {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.842Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360783	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - ping assembled, id: 93bd0011-2c8f-4e1c-bee0-a00000000017"
[task 2021-03-30T05:49:23.842Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360783	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - ping id: 93bd0011-2c8f-4e1c-bee0-a00000000017, options: {"usePingSender":false}"
[task 2021-03-30T05:49:23.842Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360783	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.842Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360783	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.842Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360783	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - can't send ping now, persisting to disk - canSendNow: false"
[task 2021-03-30T05:49:23.843Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360785	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/datareporting/archived/2021-03/1617098400000.93bd0011-2c8f-4e1c-bee0-a00000000017.test-sendPendingPings-A.jsonlz4"
[task 2021-03-30T05:49:23.844Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360786	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/saved-telemetry-pings/93bd0011-2c8f-4e1c-bee0-a00000000017"
[task 2021-03-30T05:49:23.844Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360787	Toolkit.Telemetry	TRACE	TelemetryStorage::savePendingPing - saved ping with id 93bd0011-2c8f-4e1c-bee0-a00000000017"
[task 2021-03-30T05:49:23.844Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360788	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - type: test-sendPendingPings-A, aOptions: {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.844Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360788	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type test-sendPendingPings-A, aOptions {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.844Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360788	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - ping assembled, id: 93bd0011-2c8f-4e1c-bee0-a00000000018"
[task 2021-03-30T05:49:23.844Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360788	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - ping id: 93bd0011-2c8f-4e1c-bee0-a00000000018, options: {"usePingSender":false}"
[task 2021-03-30T05:49:23.844Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360788	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.845Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360788	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.845Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360788	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - can't send ping now, persisting to disk - canSendNow: false"
[task 2021-03-30T05:49:23.845Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360790	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/datareporting/archived/2021-03/1617098400000.93bd0011-2c8f-4e1c-bee0-a00000000018.test-sendPendingPings-A.jsonlz4"
[task 2021-03-30T05:49:23.845Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360791	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/saved-telemetry-pings/93bd0011-2c8f-4e1c-bee0-a00000000018"
[task 2021-03-30T05:49:23.846Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360792	Toolkit.Telemetry	TRACE	TelemetryStorage::savePendingPing - saved ping with id 93bd0011-2c8f-4e1c-bee0-a00000000018"
[task 2021-03-30T05:49:23.846Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360793	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - type: test-sendPendingPings-A, aOptions: {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.847Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360793	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type test-sendPendingPings-A, aOptions {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.847Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360793	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - ping assembled, id: 93bd0011-2c8f-4e1c-bee0-a00000000019"
[task 2021-03-30T05:49:23.847Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360794	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - ping id: 93bd0011-2c8f-4e1c-bee0-a00000000019, options: {"usePingSender":false}"
[task 2021-03-30T05:49:23.847Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360794	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.848Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360794	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.848Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360794	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - can't send ping now, persisting to disk - canSendNow: false"
[task 2021-03-30T05:49:23.848Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360795	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/datareporting/archived/2021-03/1617098400000.93bd0011-2c8f-4e1c-bee0-a00000000019.test-sendPendingPings-A.jsonlz4"
[task 2021-03-30T05:49:23.848Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360796	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/saved-telemetry-pings/93bd0011-2c8f-4e1c-bee0-a00000000019"
[task 2021-03-30T05:49:23.848Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360797	Toolkit.Telemetry	TRACE	TelemetryStorage::savePendingPing - saved ping with id 93bd0011-2c8f-4e1c-bee0-a00000000019"
[task 2021-03-30T05:49:23.848Z] 05:49:23     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_TelemetrySend.js | test_sendPendingPings - [test_sendPendingPings : 173] Should have correct pending ping count - 20 == 20
[task 2021-03-30T05:49:23.848Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360800	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - type: test-sendPendingPings-B, aOptions: {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.854Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360800	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type test-sendPendingPings-B, aOptions {"addClientId":false,"addEnvironment":false,"usePingSender":false}"
[task 2021-03-30T05:49:23.854Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360800	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - ping assembled, id: 93bd0011-2c8f-4e1c-bee0-b00000000000"
[task 2021-03-30T05:49:23.854Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360800	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - ping id: 93bd0011-2c8f-4e1c-bee0-b00000000000, options: {"usePingSender":false}"
[task 2021-03-30T05:49:23.854Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360800	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.854Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360800	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
[task 2021-03-30T05:49:23.854Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360800	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - can't send ping now, persisting to disk - canSendNow: false"
[task 2021-03-30T05:49:23.855Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360802	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/datareporting/archived/2021-03/1617098700000.93bd0011-2c8f-4e1c-bee0-b00000000000.test-sendPendingPings-B.jsonlz4"
[task 2021-03-30T05:49:23.855Z] 05:49:23     INFO -  "CONSOLE_MESSAGE: (info) 1617083360803	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /tmp/xpc-profile-460f7y/saved-telemetry-pings/93bd0011-2c8f-4e1c-bee0-b00000000000"

Comment 1

[Cosmin Sabou [:CosminS]]

Chris, this still fails on Linux 18.04 x64 CCov opt after the test was re-enabled in Bug 1457984 https://hg.mozilla.org/mozilla-central/rev/42807ce93df81a7b12807c1e5bd3fd686371c56d. Could you please take a look? Thank you.

Comment 2

[Chris H-C :chutten]

So it seems the actual problem is

mozilla::detail::MutexImpl::mutexLock: pthread_mutex_lock failed: Invalid argument which goes all SIGSEV after the test completes successfully. (Here's a link to the log line)

The only history on this I can find in BMO is bug 1598184 from a year ago where an end-user reported it happened once and then WFM.

Here's the stack:

Thread 37 "RunProcess" received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7fffc39ff700 (LWP 1459956)]
0x00005555556dbe16 in mozilla::detail::MutexImpl::mutexLock (this=<optimized out>) at /home/chutten/gecko/mozglue/misc/Mutex_posix.cpp:96
96	  TRY_CALL_PTHREADS(
(gdb) where
#0  0x00005555556dbe16 in mozilla::detail::MutexImpl::mutexLock() (this=<optimized out>) at /home/chutten/gecko/mozglue/misc/Mutex_posix.cpp:96
#1  mozilla::detail::MutexImpl::lock() (this=<optimized out>) at /home/chutten/gecko/mozglue/misc/Mutex_posix.cpp:118
#2  0x00007fffe72203d5 in PSMutex::Lock() (this=0x7ffff5bcf630 <gPSMutex>) at /home/chutten/gecko/tools/profiler/core/platform.cpp:306
#3  0x00007fffe7194044 in PSAutoLock::PSAutoLock(PSMutex&) (this=0x7fffc39fe270, aMutex=...) at /home/chutten/gecko/tools/profiler/core/platform.cpp:382
#4  profiler_unregister_thread() () at /home/chutten/gecko/tools/profiler/core/platform.cpp:5277
#5  0x00007fffda4807f5 in mozilla::AutoProfilerRegisterThread::~AutoProfilerRegisterThread() (this=0x7fffc39fe328)
    at /home/chutten/gecko/obj-ccov-x86_64-pc-linux-gnu/dist/include/GeckoProfiler.h:585
#6  mozilla::detail::MaybeStorage<mozilla::AutoProfilerRegisterThread, false>::~MaybeStorage() (this=0x7fffc39fe328)
    at /home/chutten/gecko/obj-ccov-x86_64-pc-linux-gnu/dist/include/mozilla/Maybe.h:268
#7  nsProcess::Monitor(void*) (aArg=<optimized out>) at /home/chutten/gecko/xpcom/threads/nsProcessCommon.cpp:190
#8  0x00007ffff7f5b689 in _pt_root (arg=0x7fffc62b2160) at /home/chutten/gecko/nsprpub/pr/src/pthreads/ptthread.c:201
#9  0x00007ffff7f8e609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#10 0x00007fffcf354293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

I don't know any of this code. Looking at AutoProfilerRegisterThread's hglog I see a :gerald in there most recently. Anything stick out from this? Happening reliably at the end of running ./mach test toolkit/components/telemetry/tests/unit/test_TelemetrySend.js on Linux x64 with a .mozconfig like so:

mk_add_options MOZ_OBJDIR=@TOPSRCDIR@/obj-ccov-@CONFIG_GUESS@
ac_add_options --disable-install-strip
ac_add_options --disable-elf-hack
ac_add_options --disable-sandbox
ac_add_options --disable-dmd
ac_add_options --disable-profiling
ac_add_options --disable-warnings-as-errors
ac_add_options --enable-coverage

CLANG_LIB_DIR=/home/chutten/.mozbuild/clang/lib/clang/11.0.1/lib/linux
export LDFLAGS="--coverage -L$CLANG_LIB_DIR"
export LIBS="-lclang_rt.profile-x86_64"
export RUSTFLAGS="-Ccodegen-units=1 -Zprofile -Cpanic=abort -Zpanic_abort_tests -Clink-dead-code -Coverflow-checks=off"
export RUSTDOCFLAGS="-Cpanic=abort"

And with a rustup override set nightly on TOPSRCDIR so that the -Z RUSTFLAGS actually work. (Not sure that they're necessary to reproduce, but I was aiming to mimic the ccov build as precisely as possible and haven't trimmed down the mozconfig)

...huh. I see --disable-profiling and yet there's a lot of profiler in the stack. Maybe that's a thing? (I have no idea)

Comment 3

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

(In reply to Chris H-C :chutten from comment #2)

[...]
The only history on this I can find in BMO is bug 1598184 from a year ago where an end-user reported it happened once and then WFM.

Here's the stack:
[...]

To clarify, is that stack from bug 1598184, or is it from the recent test_TelemetrySend.js test failures?

The profiler mutex gPSMutex is global-static, so it should only get destroyed at the end of the program after main ends.
~AutoProfilerRegisterThread() should be called near the end of a (non-main) thread's life, but still inside its thread-main function.
Can threads outlive the main thread and global variable destruction? If that possible it would be bad and we'd want to fix that.

Or can you think of another reason for this pthread_mutex_lock crash? Maybe a nearby buffer overrun trampled the mutex data?

And as you noticed, --disable-profiling is present, so this profiler code should not even be compiled! 🤔

Back to you Chris.
If the stack you gave was not from the test, It'd be great if you/someone could capture one.
Otherwise I could try to investigate next week. I may need some guidance to run&debug this test...

Comment 4

[Chris H-C :chutten]

Gah, sorry for the lack of clarity. The stack's from my run of the test, not from bug 1598184.

To run and debug, I had reliable reproduction on Linux x64 by modifying .mozconfig as I said, calling rustup override set nightly, then running ./mach xpcshell-test --debugger gdb toolkit/components/telemetry/tests/unit/test_TelemetrySend.js as many times as I like.

As for your theories, well it does crash after the final test case runs, so it is definitely during shutdown. It's definitely not being called on the main thread. I can't comment about whether other threads can outlive the main thread... though since I still have this set up I can recrash this and check.

(gdb) info threads
  Id   Target Id                                          Frame 
  1    Thread 0x7fffcdaab280 (LWP 1461597) "xpcshell"     0x00007ffff7f999af in msync (addr=0x7fffcadc1000, length=254456, flags=4) at ../sysdeps/unix/sysv/linux/msync.c:25
  28   Thread 0x7fffcd28f700 (LWP 1461632) "gmain"        0x00007fffcf347aff in __GI___poll (fds=0x7fffca161808, nfds=1, timeout=-1) at ../sysdeps/unix/sysv/linux/poll.c:29
  29   Thread 0x7fffc9af7700 (LWP 1461633) "gdbus"        0x00007fffcf347aff in __GI___poll (fds=0x7fffca1b9b00, nfds=2, timeout=-1) at ../sysdeps/unix/sysv/linux/poll.c:29
  33   Thread 0x7fffc86b5700 (LWP 1461637) "dconf worker" 0x00007fffcf347aff in __GI___poll (fds=0x7fffcc9aa6e0, nfds=1, timeout=-1) at ../sysdeps/unix/sysv/linux/poll.c:29
* 37   Thread 0x7fffc39ff700 (LWP 1461646) "RunProcess"   0x00005555556dbe16 in mozilla::detail::MutexImpl::mutexLock (this=<optimized out>)
    at /home/chutten/gecko/mozglue/misc/Mutex_posix.cpp:96
  39   Thread 0x7fffc31bd700 (LWP 1461649) "RunProcess"   0x00007fffcf317dff in __GI___wait4 (pid=1461648, stat_loc=0x7fffc31bc324, options=0, usage=0x0)
    at ../sysdeps/unix/sysv/linux/wait4.c:27

Looks as though gmain is there, but given this is xpcshell not firefox I wonder if that difference is the problematic part?

I suppose it's not unreasonable that there'd be a buffer overrun somewhere. If I bring myself up to frame #2 I can read this (gPSMutex) and get:

#2  0x00007fffe72203d5 in PSMutex::Lock (this=0x7ffff5bcf630 <gPSMutex>) at /home/chutten/gecko/tools/profiler/core/platform.cpp:306
306	    ::mozilla::detail::MutexImpl::lock();
(gdb) p *this
$2 = {<mozilla::detail::MutexImpl> = {platformData_ = {0x0, 0x0, 0x5ffffffff, 0x0, 0x0}}, 
  mOwningThreadId = {<mozilla::detail::AtomicBaseIncDec<int, mozilla::SequentiallyConsistent>> = {<mozilla::detail::AtomicBase<int, mozilla::SequentiallyConsistent>> = {
        mValue = {<std::__atomic_base<int>> = {static _S_alignment = 4, _M_i = 0}, static is_always_lock_free = true}}, <No data fields>}, <No data fields>}}

The addresses all seem fine, though, up in 7ffff land.

I'm wondering if --disable-profiling isn't enough and we also need to unset MOZ_GECKO_PROFILER somehow else? *checks* Yeah, if I just ./mach run this, I can check AppConstants.MOZ_GECKO_PROFILER is true. ...come to think of it, where is --disable-profiling implemented? moz.configure has stuff for --enable-profiling (for jprof) but nothing on --disable-profiling (maybe I'm off in the weeds here and am missing something obvious)

Comment 5

[Intermittent Failures Robot]

19 failures in 3125 pushes (0.006 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 19

Platform and build breakdown:

• linux1804-64-ccov: 19
  • opt: 19

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1701874&startday=2021-03-29&endday=2021-04-04&tree=all

Comment 6

[Intermittent Failures Robot]

16 failures in 3854 pushes (0.004 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 16

Platform and build breakdown:

• linux1804-64-ccov: 16
  • opt: 16

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1701874&startday=2021-04-05&endday=2021-04-11&tree=all

Comment 7

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

(In reply to Chris H-C :chutten from comment #2)

...huh. I see --disable-profiling and yet there's a lot of profiler in the stack. Maybe that's a thing? (I have no idea)

Actually, --disable-profiling has nothing to do with MOZ_GECKO_PROFILER! (I was wrong in comment 3 as well.)
The Gecko Profiler is always built on all supported platforms, basically Windows, Mac, Linux&Android, so it's normal to see things like ~AutoProfilerRegisterThread() running -- but they should not crash of course.
When I really really want not to build it, I have a local patch that renames MOZ_GECKO_PROFILER to something else in the configuration file.

(I haven't had time to investigate the issue further.)

Comment 8

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

Re-NI:myself to continue investigating.

Comment 9

[Intermittent Failures Robot]

19 failures in 4255 pushes (0.004 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 19

Platform and build breakdown:

• linux1804-64-ccov: 19
  • opt: 19

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1701874&startday=2021-04-12&endday=2021-04-18&tree=all

Comment 10

[Intermittent Failures Robot]

19 failures in 3224 pushes (0.006 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 19

Platform and build breakdown:

• linux1804-64-ccov: 19
  • opt: 19

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1701874&startday=2021-04-19&endday=2021-04-25&tree=all

Comment 11

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

Attachment: Bug 1701874 - disable test_TelemetrySend.js on Linux code coverage for permanent failure. r=#intermittent-reviewers DONTBUILD

Comment 12

[Intermittent Failures Robot]

20 failures in 3706 pushes (0.005 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 20

Platform and build breakdown:

• linux1804-64-ccov: 20
  • opt: 20

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1701874&startday=2021-04-26&endday=2021-05-02&tree=all

Comment 13

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/39eb02319beb
disable test_TelemetrySend.js on Linux code coverage for permanent failure. r=intermittent-reviewers,jmaher DONTBUILD

Comment 14

[Narcis Beleuzu [:NarcisB]]

https://hg.mozilla.org/mozilla-central/rev/39eb02319beb

Comment 15

[Intermittent Failures Robot]

5 failures in 3279 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 5

Platform and build breakdown:

• linux1804-64-ccov: 5
  • opt: 5

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1701874&startday=2021-05-03&endday=2021-05-09&tree=all