1829496 - Intermittent telemetry/marionette/tests/client/test_subsession_management.py TestSubsessionManagement.test_subsession_management | single tracking bug

Status: RESOLVED INCOMPLETE

(Toolkit :: Telemetry, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2023-04-22T17:18:53.884Z] 17:18:53     INFO - TEST-START | telemetry/marionette/tests/client/test_subsession_management.py TestSubsessionManagement.test_subsession_management
[task 2023-04-22T17:18:53.887Z] 17:18:53     INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox -no-remote -marionette -profile /builds/worker/workspace/build/tmpqmfh5qfr.mozrunner
[task 2023-04-22T17:18:56.062Z] 17:18:56     INFO -  1682183936061	Toolkit.Telemetry	TRACE	TelemetryController::observe - profile-after-change notified.
[task 2023-04-22T17:18:56.068Z] 17:18:56     INFO -  1682183936061	Toolkit.Telemetry	TRACE	TelemetryController::setupTelemetry
[task 2023-04-22T17:18:56.070Z] 17:18:56     INFO -  1682183936062	Toolkit.Telemetry	TRACE	TelemetryController::registerJsProbes - registering builtin JS probes
[task 2023-04-22T17:18:56.072Z] 17:18:56     INFO -  1682183936063	Toolkit.Telemetry	TRACE	TelemetryController::registerScalarProbes - registering scalar builtin JS probes
[task 2023-04-22T17:18:56.074Z] 17:18:56     INFO -  1682183936064	Toolkit.Telemetry	TRACE	TelemetryController::loadProbeDefinitions - no builtin JS probe file ScalarArtifactDefinitions.json
[task 2023-04-22T17:18:56.086Z] 17:18:56     INFO -  1682183936085	Toolkit.Telemetry	TRACE	TelemetryReportingPolicy::setup
[task 2023-04-22T17:18:56.088Z] 17:18:56     INFO -  1682183936086	Toolkit.Telemetry	CONFIG	TelemetryController::enableTelemetryRecording - canRecordBase:true, canRecordExtended: true
[task 2023-04-22T17:18:56.090Z] 17:18:56     INFO -  1682183936088	Toolkit.Telemetry	TRACE	TelemetrySession::earlyInit
[task 2023-04-22T17:18:56.128Z] 17:18:56     INFO -  1682183936128	Toolkit.Telemetry	TRACE	UpdatePing::init - enabled: true
[task 2023-04-22T17:18:56.180Z] 17:18:56     INFO -  1682183936179	Toolkit.Telemetry	TRACE	TelemetryEnvironment::constructor
[task 2023-04-22T17:18:56.732Z] 17:18:56     INFO -  ATTENTION: default value of option mesa_glthread overridden by environment.
[task 2023-04-22T17:18:56.762Z] 17:18:56     INFO -  ATTENTION: default value of option mesa_glthread overridden by environment.
[task 2023-04-22T17:18:56.840Z] 17:18:56     INFO -  1682183936839	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_getGFXData - Only one display adapter detected.
[task 2023-04-22T17:18:56.857Z] 17:18:56     INFO -  1682183936856	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_updateSearchEngine - ignoring early call
[task 2023-04-22T17:18:56.858Z] 17:18:56     INFO -  1682183936858	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_updateAddons
[task 2023-04-22T17:18:56.868Z] 17:18:56     INFO -  1682183936868	Toolkit.Telemetry	TRACE	TelemetryEnvironment::registerChangeListener for CrashAnnotator
[task 2023-04-22T17:18:56.913Z] 17:18:56     INFO -  1682183936913	Marionette	INFO	Marionette enabled
[task 2023-04-22T17:18:56.923Z] 17:18:56     INFO -  1682183936922	Marionette	TRACE	Received observer notification final-ui-startup
[task 2023-04-22T17:18:56.932Z] 17:18:56     INFO -  1682183936932	Marionette	INFO	Listening on port 2828
[task 2023-04-22T17:18:56.933Z] 17:18:56     INFO -  1682183936933	Marionette	DEBUG	Marionette is listening
[task 2023-04-22T17:18:57.464Z] 17:18:57     INFO -  1682183937463	Toolkit.Telemetry	TRACE	TelemetryController::registerEventProbes - registering builtin JS Event probes
[task 2023-04-22T17:18:57.465Z] 17:18:57     INFO -  1682183937464	Toolkit.Telemetry	TRACE	TelemetryController::loadProbeDefinitions - no builtin JS probe file EventArtifactDefinitions.json
[task 2023-04-22T17:18:57.492Z] 17:18:57     INFO -  1682183937491	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_updateAddons: addons differ
[task 2023-04-22T17:18:57.584Z] 17:18:57     INFO -  1682183937583	Marionette	DEBUG	Accepted connection 0 from 127.0.0.1:52992
[task 2023-04-22T17:18:57.731Z] 17:18:57     INFO -  1682183937730	Marionette	DEBUG	Closed connection 0
[task 2023-04-22T17:18:57.737Z] 17:18:57     INFO -  1682183937737	Marionette	DEBUG	Accepted connection 1 from 127.0.0.1:52994
[task 2023-04-22T17:18:57.947Z] 17:18:57     INFO -  1682183937947	Marionette	DEBUG	Closed connection 1
[task 2023-04-22T17:18:57.949Z] 17:18:57     INFO -  1682183937948	Marionette	DEBUG	Accepted connection 2 from 127.0.0.1:52996
[task 2023-04-22T17:18:59.213Z] 17:18:59     INFO -  1682183939213	Marionette	DEBUG	2 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2023-04-22T17:18:59.239Z] 17:18:59     INFO -  1682183939239	Marionette	DEBUG	Waiting for initial application window
[task 2023-04-22T17:18:59.520Z] 17:18:59     INFO -  1682183939519	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - Topic gmp-provider-registered
[task 2023-04-22T17:18:59.784Z] 17:18:59     INFO -  1682183939783	Toolkit.Telemetry	TRACE	TelemetryController::observe - content-process-ready-for-script notified.
[task 2023-04-22T17:18:59.788Z] 17:18:59     INFO -  1682183939787	Toolkit.Telemetry	CONFIG	TelemetryController::enableTelemetryRecording - canRecordBase:true, canRecordExtended: true
[task 2023-04-22T17:19:00.616Z] 17:19:00     INFO -  1682183940615	Toolkit.Telemetry	TRACE	TelemetryController::observe - content-process-ready-for-script notified.
[task 2023-04-22T17:19:00.619Z] 17:19:00     INFO -  1682183940618	Toolkit.Telemetry	CONFIG	TelemetryController::enableTelemetryRecording - canRecordBase:true, canRecordExtended: true
[task 2023-04-22T17:19:01.191Z] 17:19:01     INFO -  1682183941190	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: compositor:created, aData: null
[task 2023-04-22T17:19:02.578Z] 17:19:02     INFO -  1682183942577	Toolkit.Telemetry	TRACE	TelemetrySession::observe - xul-window-visible notified.
[task 2023-04-22T17:19:05.759Z] 17:19:05     INFO -  console.error: ({})
[task 2023-04-22T17:19:05.819Z] 17:19:05     INFO -  1682183945818	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: sessionstore-windows-restored, aData: null
[task 2023-04-22T17:19:05.831Z] 17:19:05     INFO -  1682183945830	Toolkit.Telemetry	TRACE	TelemetrySession::observe - sessionstore-windows-restored notified.
[task 2023-04-22T17:19:05.836Z] 17:19:05     INFO -  1682183945831	Toolkit.Telemetry	TRACE	TelemetrySession::gatherStartup
[task 2023-04-22T17:19:05.839Z] 17:19:05     INFO -  1682183945832	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet.
[task 2023-04-22T17:19:05.842Z] 17:19:05     INFO -  1682183945832	Toolkit.Telemetry	TRACE	TelemetryReportingPolicy::_shouldNotify - User already notified or bypassing the policy.
[task 2023-04-22T17:19:05.941Z] 17:19:05     INFO -  1682183945940	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_startWatchingPrefs - [object Map]
[task 2023-04-22T17:19:06.006Z] 17:19:06     INFO -  1682183946005	Toolkit.Telemetry	TRACE	TelemetrySession::observe - user-interaction-inactive notified.
[task 2023-04-22T17:19:06.119Z] 17:19:06     INFO -  console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at /builds/worker/workspace/build/tmpqmfh5qfr.mozrunner/search.json.mozlz4", (void 0)))
[task 2023-04-22T17:19:06.265Z] 17:19:06     INFO -  1682183946264	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.default.sites
[task 2023-04-22T17:19:06.272Z] 17:19:06     INFO -  1682183946271	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.feeds.section.topstories.options
[task 2023-04-22T17:19:06.277Z] 17:19:06     INFO -  1682183946277	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.feeds.topsites
[task 2023-04-22T17:19:06.283Z] 17:19:06     INFO -  1682183946282	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.hideTopSitesTitle
[task 2023-04-22T17:19:06.288Z] 17:19:06     INFO -  1682183946288	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.showSponsored
[task 2023-04-22T17:19:06.294Z] 17:19:06     INFO -  1682183946293	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.showSponsoredTopSites
[task 2023-04-22T17:19:06.300Z] 17:19:06     INFO -  1682183946299	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.pocketCta
[task 2023-04-22T17:19:06.305Z] 17:19:06     INFO -  1682183946304	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.showSearch
[task 2023-04-22T17:19:06.310Z] 17:19:06     INFO -  1682183946310	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.feeds.snippets
[task 2023-04-22T17:19:06.316Z] 17:19:06     INFO -  1682183946315	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.topSitesRows
[task 2023-04-22T17:19:06.322Z] 17:19:06     INFO -  1682183946322	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.telemetry.ut.events
[task 2023-04-22T17:19:06.328Z] 17:19:06     INFO -  1682183946327	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.telemetry.structuredIngestion.endpoint
[task 2023-04-22T17:19:06.333Z] 17:19:06     INFO -  1682183946332	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.section.highlights.includeVisited
[task 2023-04-22T17:19:06.338Z] 17:19:06     INFO -  1682183946338	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.section.highlights.includeBookmarks
[task 2023-04-22T17:19:06.343Z] 17:19:06     INFO -  1682183946343	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.section.highlights.includePocket
[task 2023-04-22T17:19:06.349Z] 17:19:06     INFO -  1682183946348	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.section.highlights.includeDownloads
[task 2023-04-22T17:19:06.353Z] 17:19:06     INFO -  1682183946352	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.section.highlights.rows
[task 2023-04-22T17:19:06.358Z] 17:19:06     INFO -  1682183946354	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.section.topstories.rows
[task 2023-04-22T17:19:06.364Z] 17:19:06     INFO -  1682183946359	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.sectionOrder
[task 2023-04-22T17:19:06.367Z] 17:19:06     INFO -  1682183946359	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.improvesearch.noDefaultSearchTile
[task 2023-04-22T17:19:06.374Z] 17:19:06     INFO -  1682183946367	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.improvesearch.topSiteSearchShortcuts.searchEngines
[task 2023-04-22T17:19:06.378Z] 17:19:06     INFO -  1682183946368	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.improvesearch.topSiteSearchShortcuts.havePinned
[task 2023-04-22T17:19:06.381Z] 17:19:06     INFO -  1682183946370	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.asrouter.devtoolsEnabled
[task 2023-04-22T17:19:06.388Z] 17:19:06     INFO -  1682183946374	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.asrouter.providers.onboarding
[task 2023-04-22T17:19:06.392Z] 17:19:06     INFO -  1682183946375	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.discoverystream.flight.blocks
[task 2023-04-22T17:19:06.395Z] 17:19:06     INFO -  1682183946376	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.discoverystream.config
[task 2023-04-22T17:19:06.399Z] 17:19:06     INFO -  1682183946377	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.discoverystream.endpoints
[task 2023-04-22T17:19:06.402Z] 17:19:06     INFO -  1682183946377	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.discoverystream.region-basic-layout
[task 2023-04-22T17:19:06.406Z] 17:19:06     INFO -  1682183946379	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.discoverystream.spoc.impressions
[task 2023-04-22T17:19:06.410Z] 17:19:06     INFO -  1682183946380	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.discoverystream.endpointSpocsClear
[task 2023-04-22T17:19:06.413Z] 17:19:06     INFO -  1682183946382	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.discoverystream.rec.impressions
[task 2023-04-22T17:19:06.417Z] 17:19:06     INFO -  1682183946383	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.showRecentSaves
[task 2023-04-22T17:19:06.420Z] 17:19:06     INFO -  1682183946385	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.feeds.aboutpreferences
[task 2023-04-22T17:19:06.424Z] 17:19:06     INFO -  1682183946386	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.feeds.newtabinit
[task 2023-04-22T17:19:06.427Z] 17:19:06     INFO -  1682183946387	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.feeds.places
[task 2023-04-22T17:19:06.430Z] 17:19:06     INFO -  1682183946387	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.feeds.prefs
[task 2023-04-22T17:19:06.433Z] 17:19:06     INFO -  1682183946388	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.feeds.sections
[task 2023-04-22T17:19:06.437Z] 17:19:06     INFO -  1682183946393	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.feeds.section.highlights
[task 2023-04-22T17:19:06.440Z] 17:19:06     INFO -  1682183946394	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.feeds.system.topstories
[task 2023-04-22T17:19:06.444Z] 17:19:06     INFO -  1682183946395	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.feeds.systemtick
[task 2023-04-22T17:19:06.447Z] 17:19:06     INFO -  1682183946397	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.feeds.telemetry
[task 2023-04-22T17:19:06.449Z] 17:19:06     INFO -  1682183946399	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.feeds.favicon
[task 2023-04-22T17:19:06.450Z] 17:19:06     INFO -  1682183946400	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.feeds.system.topsites
[task 2023-04-22T17:19:06.452Z] 17:19:06     INFO -  1682183946403	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.feeds.recommendationprovider
[task 2023-04-22T17:19:06.454Z] 17:19:06     INFO -  1682183946405	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.feeds.discoverystreamfeed
[task 2023-04-22T17:19:06.475Z] 17:19:06     INFO -  1682183946474	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.activity-stream.impressionId
[task 2023-04-22T17:19:06.811Z] 17:19:06     INFO -  1682183946810	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: extensions.webextensions.uuids
[task 2023-04-22T17:19:06.990Z] 17:19:06     INFO -  1682183946989	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.contextual-services.contextId
[task 2023-04-22T17:19:07.104Z] 17:19:07     INFO -  1682183947103	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.urlbar.quicksuggest.migrationVersion
[task 2023-04-22T17:19:07.109Z] 17:19:07     INFO -  1682183947105	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.urlbar.quicksuggest.scenario
[task 2023-04-22T17:19:07.553Z] 17:19:07     INFO -  1682183947553	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: browser-search-service, aData: settings-update-complete
[task 2023-04-22T17:19:08.052Z] 17:19:08     INFO -  1682183948050	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: app.normandy.first_run
[task 2023-04-22T17:19:08.337Z] 17:19:08     INFO -  1682183948336	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: extensions.pictureinpicture.enable_picture_in_picture_overrides
[task 2023-04-22T17:19:08.481Z] 17:19:08     INFO -  1682183948481	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: extensions.webcompat.perform_injections
[task 2023-04-22T17:19:08.494Z] 17:19:08     INFO -  1682183948493	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: extensions.webcompat.perform_ua_overrides
[task 2023-04-22T17:19:08.612Z] 17:19:08     INFO -  1682183948612	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: extensions.webextensions.uuids
[task 2023-04-22T17:19:08.792Z] 17:19:08     INFO -  1682183948791	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: extensions.webcompat.enable_shims
[task 2023-04-22T17:19:09.137Z] 17:19:09     INFO -  1682183949136	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: extensions.webextensions.uuids
[task 2023-04-22T17:19:09.253Z] 17:19:09     INFO -  1682183949252	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: extensions.webextensions.uuids
[task 2023-04-22T17:19:09.602Z] 17:19:09     INFO -  1682183949601	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: extensions.webextensions.uuids
[task 2023-04-22T17:19:09.712Z] 17:19:09     INFO -  1682183949711	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: extensions.webextensions.uuids
[task 2023-04-22T17:19:09.780Z] 17:19:09     INFO -  1682183949779	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: browser-search-service, aData: init-complete
[task 2023-04-22T17:19:09.785Z] 17:19:09     INFO -  1682183949780	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_updateSearchEngine - isInitialized: true
[task 2023-04-22T17:19:09.840Z] 17:19:09     INFO -  1682183949839	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.storageVersion
[task 2023-04-22T17:19:09.930Z] 17:19:09     INFO -  1682183949930	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.urlbar.placeholderName
[task 2023-04-22T17:19:10.300Z] 17:19:10     INFO -  1682183950299	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: extensions.databaseSchema
[task 2023-04-22T17:19:10.334Z] 17:19:10     INFO -  1682183950333	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_onEnvironmentChange for system-info
[task 2023-04-22T17:19:10.339Z] 17:19:10     INFO -  1682183950338	Toolkit.Telemetry	DEBUG	TelemetryEnvironment::_onEnvironmentChange - calling CrashAnnotator
[task 2023-04-22T17:19:10.342Z] 17:19:10     INFO -  1682183950342	Toolkit.Telemetry	TRACE	ClientID::_doLoadClientID
[task 2023-04-22T17:19:10.365Z] 17:19:10     INFO -  1682183950364	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: toolkit.telemetry.cachedClientID
[task 2023-04-22T17:19:10.366Z] 17:19:10     INFO -  1682183950365	Toolkit.Telemetry	TRACE	ClientID::_saveClientID
[task 2023-04-22T17:19:10.376Z] 17:19:10     INFO -  1682183950375	Toolkit.Telemetry	TRACE	ClientID::_doLoadClientID: New client ID loaded and persisted.
[task 2023-04-22T17:19:10.377Z] 17:19:10     INFO -  1682183950376	Toolkit.Telemetry	TRACE	TelemetrySend::setup
[task 2023-04-22T17:19:10.475Z] 17:19:10     INFO -  1682183950474	Toolkit.Telemetry	TRACE	TelemetryStorage::_scanPendingPings
[task 2023-04-22T17:19:10.477Z] 17:19:10     INFO -  1682183950474	Toolkit.Telemetry	TRACE	TelemetryStorage::_migrateAppDataPings
[task 2023-04-22T17:19:10.478Z] 17:19:10     INFO -  1682183950475	Toolkit.Telemetry	TRACE	TelemetryStorage::_iterateAppDataPings
[task 2023-04-22T17:19:10.589Z] 17:19:10     INFO -  1682183950588	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: app.update.lastUpdateTime.region-update-timer
[task 2023-04-22T17:19:10.693Z] 17:19:10     INFO -  1682183950692	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: distribution-customization-complete, aData: null
[task 2023-04-22T17:19:10.698Z] 17:19:10     INFO -  1682183950697	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.bookmarks.restore_default_bookmarks
[task 2023-04-22T17:19:11.098Z] 17:19:11     INFO -  1682183951097	Toolkit.Telemetry	TRACE	TelemetryController::observe - content-process-ready-for-script notified.
[task 2023-04-22T17:19:11.101Z] 17:19:11     INFO -  1682183951100	Toolkit.Telemetry	CONFIG	TelemetryController::enableTelemetryRecording - canRecordBase:true, canRecordExtended: true
[task 2023-04-22T17:19:11.264Z] 17:19:11     INFO -  1682183951259	Toolkit.Telemetry	TRACE	TelemetryStorage::_iterateAppDataPings - the AppData pending pings directory doesn't exist.
[task 2023-04-22T17:19:11.323Z] 17:19:11     INFO -  1682183951323	Toolkit.Telemetry	INFO	TelemetrySend::_checkPendingPings - pending ping count: 0
[task 2023-04-22T17:19:11.325Z] 17:19:11     INFO -  1682183951323	Toolkit.Telemetry	TRACE	TelemetrySend::_checkPendingPings - no pending pings
[task 2023-04-22T17:19:11.325Z] 17:19:11     INFO -  1682183951323	Toolkit.Telemetry	TRACE	TelemetryStorage::_enforcePendingPingsQuota
[task 2023-04-22T17:19:11.327Z] 17:19:11     INFO -  1682183951326	Toolkit.Telemetry	TRACE	TelemetrySend::Scheduler::triggerSendingPings - active send task: false, immediately: true
[task 2023-04-22T17:19:11.327Z] 17:19:11     INFO -  1682183951326	Toolkit.Telemetry	TRACE	TelemetrySend::Scheduler::_doSendTask iteration
[task 2023-04-22T17:19:11.328Z] 17:19:11     INFO -  1682183951327	Toolkit.Telemetry	TRACE	TelemetrySend::Scheduler::_doSendTask - pending: 0, current: 0
[task 2023-04-22T17:19:11.329Z] 17:19:11     INFO -  1682183951328	Toolkit.Telemetry	TRACE	TelemetrySend::Scheduler::_doSendTask - can send - pending: 0, current: 0
[task 2023-04-22T17:19:11.329Z] 17:19:11     INFO -  1682183951328	Toolkit.Telemetry	TRACE	TelemetrySend::Scheduler::_doSendTask - no pending pings, bailing out
[task 2023-04-22T17:19:11.330Z] 17:19:11     INFO -  1682183951330	Toolkit.Telemetry	TRACE	TelemetrySession::delayedInit
[task 2023-04-22T17:19:11.332Z] 17:19:11     INFO -  1682183951332	Toolkit.Telemetry	TRACE	TelemetryStorage::_popAndPerformQueuedOperation - Performing queued operation.
[task 2023-04-22T17:19:11.339Z] 17:19:11     INFO -  1682183951337	Toolkit.Telemetry	INFO	TelemetryStorage::_loadSessionData - can not load session data file: {"operation":"open","path":"/builds/worker/workspace/build/tmpqmfh5qfr.mozrunner/datareporting/session-state.json","unixErrno":2}
[task 2023-04-22T17:19:11.340Z] 17:19:11     INFO -  1682183951339	Toolkit.Telemetry	TRACE	TelemetryStorage::_popAndPerformQueuedOperation - Performing queued operation.
[task 2023-04-22T17:19:11.589Z] 17:19:11     INFO -  1682183951588	Toolkit.Telemetry	TRACE	TelemetryStorage::loadPingfile - unreadable ping /builds/worker/workspace/build/tmpqmfh5qfr.mozrunner/datareporting/aborted-session-ping: {"operation":"open","path":"/builds/worker/workspace/build/tmpqmfh5qfr.mozrunner/datareporting/aborted-session-ping","unixErrno":2}
[task 2023-04-22T17:19:11.591Z] 17:19:11     INFO -  1682183951589	Toolkit.Telemetry	TRACE	TelemetryStorage::loadAbortedSessionPing - no such file
[task 2023-04-22T17:19:11.592Z] 17:19:11     INFO -  1682183951589	Toolkit.Telemetry	TRACE	TelemetryController::checkAbortedSessionPing - found aborted-session ping: false
[task 2023-04-22T17:19:11.593Z] 17:19:11     INFO -  1682183951590	Toolkit.Telemetry	TRACE	TelemetrySession::_saveAbortedSessionPing
[task 2023-04-22T17:19:11.593Z] 17:19:11     INFO -  1682183951590	Toolkit.Telemetry	TRACE	TelemetrySession::getSessionPayload - reason: aborted-session, clearSubsession: false
[task 2023-04-22T17:19:11.596Z] 17:19:11     INFO -  1682183951596	Toolkit.Telemetry	TRACE	TelemetrySession::assemblePayloadWithMeasurements - reason: aborted-session, submitting subsession data: true
[task 2023-04-22T17:19:11.622Z] 17:19:11     INFO -  1682183951621	Toolkit.Telemetry	TRACE	TelemetryController::saveAbortedSessionPing
[task 2023-04-22T17:19:11.623Z] 17:19:11     INFO -  1682183951621	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type main, aOptions {"addClientId":true,"addEnvironment":true}
[task 2023-04-22T17:19:11.647Z] 17:19:11     INFO -  1682183951646	Toolkit.Telemetry	TRACE	TelemetryStorage::saveAbortedSessionPing - ping path: /builds/worker/workspace/build/tmpqmfh5qfr.mozrunner/datareporting/aborted-session-ping
[task 2023-04-22T17:19:11.711Z] 17:19:11     INFO -  1682183951710	Toolkit.Telemetry	TRACE	TelemetryStorage::_popAndPerformQueuedOperation - Performing queued operation.
[task 2023-04-22T17:19:11.712Z] 17:19:11     INFO -  1682183951710	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: /builds/worker/workspace/build/tmpqmfh5qfr.mozrunner/datareporting/aborted-session-ping
[task 2023-04-22T17:19:11.737Z] 17:19:11     INFO -  1682183951736	Toolkit.Telemetry	TRACE	TelemetryEnvironment::registerChangeListener for TelemetrySession::onEnvironmentChange
[task 2023-04-22T17:19:11.747Z] 17:19:11     INFO -  1682183951747	Toolkit.Telemetry	TRACE	TelemetryScheduler::init
[task 2023-04-22T17:19:11.749Z] 17:19:11     INFO -  1682183951747	Toolkit.Telemetry	TRACE	TelemetryScheduler::_rescheduleTimeout - isUserIdle: false
[task 2023-04-22T17:19:11.751Z] 17:19:11     INFO -  1682183951748	Toolkit.Telemetry	TRACE	TelemetryScheduler::_rescheduleTimeout - scheduling next tick for Sat Apr 22 2023 17:24:11 GMT+0000 (Coordinated Universal Time)
[task 2023-04-22T17:19:11.760Z] 17:19:11     INFO -  1682183951759	Toolkit.Telemetry	TRACE	TelemetryController::scheduleNewProfilePing
[task 2023-04-22T17:19:11.783Z] 17:19:11     INFO -  1682183951783	Toolkit.Telemetry	TRACE	TelemetryStorage::cleanArchiveTask
[task 2023-04-22T17:19:11.790Z] 17:19:11     INFO -  1682183951788	Toolkit.Telemetry	TRACE	TelemetryStorage::removeFHRDatabase
[task 2023-04-22T17:19:11.808Z] 17:19:11     INFO -  1682183951808	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: app.update.lastUpdateTime.telemetry_modules_ping
[task 2023-04-22T17:19:11.847Z] 17:19:11     INFO -  1682183951846	Toolkit.Telemetry	TRACE	TelemetryEventPing::::Starting up.
[task 2023-04-22T17:19:12.165Z] 17:19:12     INFO -  [ERROR glean_core] Error setting metrics feature config: Json(Error("EOF while parsing a value", line: 1, column: 0))
[task 2023-04-22T17:19:12.255Z] 17:19:12     INFO -  1682183952254	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.uiCustomization.state
[task 2023-04-22T17:19:12.270Z] 17:19:12     INFO -  1682183952269	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.bookmarks.addedImportButton
[task 2023-04-22T17:19:12.413Z] 17:19:12     INFO -  console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-04-22T17:19:12.435Z] 17:19:12     INFO -  console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-04-22T17:19:12.453Z] 17:19:12     INFO -  console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-04-22T17:19:12.483Z] 17:19:12     INFO -  console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-04-22T17:19:12.704Z] 17:19:12     INFO -  1682183952703	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: browser-search-service, aData: write-settings-to-disk-complete
[task 2023-04-22T17:19:12.949Z] 17:19:12     INFO -  1682183952948	Toolkit.Telemetry	TRACE	TelemetryController::observe - content-process-ready-for-script notified.
[task 2023-04-22T17:19:12.953Z] 17:19:12     INFO -  1682183952952	Toolkit.Telemetry	CONFIG	TelemetryController::enableTelemetryRecording - canRecordBase:true, canRecordExtended: true
[task 2023-04-22T17:19:13.243Z] 17:19:13     INFO -  1682183953242	Toolkit.Telemetry	TRACE	TelemetryController::observe - content-process-ready-for-script notified.
[task 2023-04-22T17:19:13.245Z] 17:19:13     INFO -  1682183953244	Toolkit.Telemetry	CONFIG	TelemetryController::enableTelemetryRecording - canRecordBase:true, canRecordExtended: true
[task 2023-04-22T17:19:13.289Z] 17:19:13     INFO -  1682183953288	Marionette	TRACE	Received observer notification browser-idle-startup-tasks-finished
[task 2023-04-22T17:19:13.398Z] 17:19:13     INFO -  1682183953397	RemoteAgent	TRACE	[9] ProgressListener Start: expectNavigation=false resolveWhenStarted=false unloadTimeout=1600 waitForExplicitStart=false
[task 2023-04-22T17:19:13.401Z] 17:19:13     INFO -  1682183953400	RemoteAgent	TRACE	[9] ProgressListener Setting unload timer (1600ms)
[task 2023-04-22T17:19:13.403Z] 17:19:13     INFO -  1682183953403	RemoteAgent	TRACE	[9] Document already finished loading: about:blank
[task 2023-04-22T17:19:13.404Z] 17:19:13     INFO -  1682183953404	RemoteAgent	TRACE	[9] ProgressListener Stop: has error=false
[task 2023-04-22T17:19:13.516Z] 17:19:13     INFO -  1682183953515	Marionette	DEBUG	2 <- [1,1,null,{"sessionId":"28eaf105-0c3e-4aed-a4b1-e83f2167f07e","capabilities":{"browserName":"firefox","browserVersion":"112.0.2","platformName":"linux","acceptInsecureCerts":false,"pageLoadStrategy":"normal","setWindowRect":true,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"strictFileInteractability":true,"unhandledPromptBehavior":"dismiss and notify","moz:accessibilityChecks":false,"moz:buildID":"20230422163915","moz:headless":false,"moz:platformVersion":"4.4.0-1014-aws","moz:processID":2049,"moz:profile":"/builds/worker/workspace/build/tmpqmfh5qfr.mozrunner","moz:shutdownTimeout":360000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true,"moz:windowless":false,"proxy":{}}}]
[task 2023-04-22T17:19:13.578Z] 17:19:13     INFO -  1682183953578	Marionette	DEBUG	2 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}]
<...>
[task 2023-04-22T17:19:39.841Z] 17:19:39     INFO -  1682183979841	Marionette	DEBUG	Marionette is listening
[task 2023-04-22T17:19:40.029Z] 17:19:40     INFO -  1682183980028	Toolkit.Telemetry	TRACE	TelemetryController::registerEventProbes - registering builtin JS Event probes
[task 2023-04-22T17:19:40.030Z] 17:19:40     INFO -  1682183980029	Toolkit.Telemetry	TRACE	TelemetryController::loadProbeDefinitions - no builtin JS probe file EventArtifactDefinitions.json
[task 2023-04-22T17:19:40.038Z] 17:19:40     INFO -  1682183980038	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_updateAddons: addons differ
[task 2023-04-22T17:19:40.087Z] 17:19:40     INFO -  1682183980086	Marionette	DEBUG	Accepted connection 0 from 127.0.0.1:53230
[task 2023-04-22T17:19:40.111Z] 17:19:40     INFO -  1682183980110	Marionette	DEBUG	Closed connection 0
[task 2023-04-22T17:19:40.113Z] 17:19:40     INFO -  1682183980112	Marionette	DEBUG	Accepted connection 1 from 127.0.0.1:53232
[task 2023-04-22T17:19:40.211Z] 17:19:40     INFO -  1682183980211	Marionette	DEBUG	1 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2023-04-22T17:19:40.224Z] 17:19:40     INFO -  1682183980223	Marionette	DEBUG	Waiting for initial application window
[task 2023-04-22T17:19:41.456Z] 17:19:41     INFO -  1682183981454	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - Topic gmp-provider-registered
[task 2023-04-22T17:19:41.692Z] 17:19:41     INFO -  1682183981691	Toolkit.Telemetry	TRACE	TelemetryController::observe - content-process-ready-for-script notified.
[task 2023-04-22T17:19:41.695Z] 17:19:41     INFO -  1682183981694	Toolkit.Telemetry	CONFIG	TelemetryController::enableTelemetryRecording - canRecordBase:true, canRecordExtended: true
[task 2023-04-22T17:19:41.859Z] 17:19:41     INFO -  1682183981858	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: compositor:created, aData: null
[task 2023-04-22T17:19:43.030Z] 17:19:43     INFO -  1682183983030	Toolkit.Telemetry	TRACE	TelemetrySession::observe - xul-window-visible notified.
[task 2023-04-22T17:19:43.241Z] 17:19:43     INFO -  ==2469==ERROR: ThreadSanitizer failed to allocate 0xff55e2dc9000 (280744343408640) bytes at address 800006a1000 (errno: 12)
[task 2023-04-22T17:19:43.269Z] 17:19:43     INFO -  Exiting due to channel error.
[task 2023-04-22T17:19:44.276Z] 17:19:44     INFO -  Crash Annotation GraphicsCriticalError: |[C0][GFX1-]: CompositorBridgeChild receives IPC close with reason=AbnormalShutdown (t=1.80666)
[task 2023-04-22T17:19:44.285Z] 17:19:44     INFO - TEST-UNEXPECTED-ERROR | telemetry/marionette/tests/client/test_subsession_management.py TestSubsessionManagement.test_subsession_management | OSError: Process has been unexpectedly closed (Exit code: 0) (Reason: Process has been unexpectedly closed (Exit code: 0) (Reason: Process has been unexpectedly closed (Exit code: 0) (Reason: No data received over socket)))
[task 2023-04-22T17:19:44.286Z] 17:19:44     INFO - Traceback (most recent call last):
[task 2023-04-22T17:19:44.287Z] 17:19:44     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_harness/marionette_test/testcases.py", line 198, in run
[task 2023-04-22T17:19:44.288Z] 17:19:44     INFO -     testMethod()
[task 2023-04-22T17:19:44.288Z] 17:19:44     INFO -   File "/builds/worker/workspace/build/tests/telemetry/marionette/tests/client/test_subsession_management.py", line 110, in test_subsession_management
[task 2023-04-22T17:19:44.288Z] 17:19:44     INFO -     ping3 = self.wait_for_ping(self.restart_browser, MAIN_SHUTDOWN_PING)
[task 2023-04-22T17:19:44.288Z] 17:19:44     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/telemetry_harness/testcase.py", line 137, in wait_for_ping
[task 2023-04-22T17:19:44.289Z] 17:19:44     INFO -     action_func, ping_filter, 1, ping_server=ping_server
[task 2023-04-22T17:19:44.289Z] 17:19:44     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/telemetry_harness/testcase.py", line 123, in wait_for_pings
[task 2023-04-22T17:19:44.289Z] 17:19:44     INFO -     action_func()
[task 2023-04-22T17:19:44.289Z] 17:19:44     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/telemetry_harness/testcase.py", line 143, in restart_browser
[task 2023-04-22T17:19:44.289Z] 17:19:44     INFO -     return self.marionette.restart(clean=False, in_app=True)
[task 2023-04-22T17:19:44.289Z] 17:19:44     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_driver/decorators.py", line 34, in _
[task 2023-04-22T17:19:44.290Z] 17:19:44     INFO -     m._handle_socket_failure()
[task 2023-04-22T17:19:44.290Z] 17:19:44     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_driver/marionette.py", line 741, in _handle_socket_failure
[task 2023-04-22T17:19:44.290Z] 17:19:44     INFO -     IOError, IOError(message.format(returncode=returncode, reason=exc)), tb
[task 2023-04-22T17:19:44.290Z] 17:19:44     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/six.py", line 702, in reraise
[task 2023-04-22T17:19:44.290Z] 17:19:44     INFO -     raise value.with_traceback(tb)
[task 2023-04-22T17:19:44.290Z] 17:19:44     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_driver/decorators.py", line 24, in _
[task 2023-04-22T17:19:44.290Z] 17:19:44     INFO -     return func(*args, **kwargs)
[task 2023-04-22T17:19:44.290Z] 17:19:44     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_driver/marionette.py", line 1199, in restart
[task 2023-04-22T17:19:44.290Z] 17:19:44     INFO -     self.start_session(self.requested_capabilities)
[task 2023-04-22T17:19:44.290Z] 17:19:44     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_driver/decorators.py", line 34, in _
[task 2023-04-22T17:19:44.290Z] 17:19:44     INFO -     m._handle_socket_failure()
[task 2023-04-22T17:19:44.290Z] 17:19:44     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_driver/marionette.py", line 741, in _handle_socket_failure
[task 2023-04-22T17:19:44.290Z] 17:19:44     INFO -     IOError, IOError(message.format(returncode=returncode, reason=exc)), tb
[task 2023-04-22T17:19:44.290Z] 17:19:44     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/six.py", line 702, in reraise
[task 2023-04-22T17:19:44.290Z] 17:19:44     INFO -     raise value.with_traceback(tb)
[task 2023-04-22T17:19:44.290Z] 17:19:44     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_driver/decorators.py", line 24, in _
[task 2023-04-22T17:19:44.290Z] 17:19:44     INFO -     return func(*args, **kwargs)
[task 2023-04-22T17:19:44.290Z] 17:19:44     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_driver/marionette.py", line 1258, in start_session
[task 2023-04-22T17:19:44.290Z] 17:19:44     INFO -     resp = self._send_message("WebDriver:NewSession", capabilities)
[task 2023-04-22T17:19:44.290Z] 17:19:44     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_driver/decorators.py", line 34, in _
[task 2023-04-22T17:19:44.290Z] 17:19:44     INFO -     m._handle_socket_failure()
[task 2023-04-22T17:19:44.290Z] 17:19:44     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_driver/marionette.py", line 741, in _handle_socket_failure
[task 2023-04-22T17:19:44.290Z] 17:19:44     INFO -     IOError, IOError(message.format(returncode=returncode, reason=exc)), tb
[task 2023-04-22T17:19:44.290Z] 17:19:44     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/six.py", line 702, in reraise
[task 2023-04-22T17:19:44.290Z] 17:19:44     INFO -     raise value.with_traceback(tb)
[task 2023-04-22T17:19:44.290Z] 17:19:44     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_driver/decorators.py", line 24, in _
[task 2023-04-22T17:19:44.290Z] 17:19:44     INFO -     return func(*args, **kwargs)
[task 2023-04-22T17:19:44.290Z] 17:19:44     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_driver/marionette.py", line 656, in _send_message
[task 2023-04-22T17:19:44.290Z] 17:19:44     INFO -     msg = self.client.request(name, params)
[task 2023-04-22T17:19:44.290Z] 17:19:44     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_driver/transport.py", line 381, in request
[task 2023-04-22T17:19:44.290Z] 17:19:44     INFO -     return self.receive()
[task 2023-04-22T17:19:44.290Z] 17:19:44     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_driver/transport.py", line 228, in receive
[task 2023-04-22T17:19:44.291Z] 17:19:44     INFO -     raise socket.error("No data received over socket")
[task 2023-04-22T17:19:44.291Z] 17:19:44     INFO - TEST-INFO took 50395ms
[task 2023-04-22T17:19:44.291Z] 17:19:44    ERROR - test_end for telemetry/marionette/tests/client/test_subsession_management.py TestSubsessionManagement.test_subsession_management 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 230, 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 1413, 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 1482, 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 653, in _send_message\n    raise errors.InvalidSessionIdException(\"Please start a session\")\n", "extra": {"class_name": "test_subsession_management.TestSubsessionManagement", "method_name": "test_subsession_management"}, "test": "telemetry/marionette/tests/client/test_subsession_management.py TestSubsessionManagement.test_subsession_management", "status": "ERROR"}
[task 2023-04-22T17:19:44.291Z] 17:19:44     INFO - TEST-START | telemetry/marionette/tests/client/test_fog_deletion_request_ping.py TestDeletionRequestPing.test_deletion_request_ping_across_sessions

Comment 1

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-release: 1

Platform and build breakdown:

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

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

Comment 2

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

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

Comment 3

[Treeherder Bug Filer]

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

Comment 4

[Intermittent Failures Robot]

1 failures in 3578 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-tsan-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1829496&startday=2023-05-15&endday=2023-05-21&tree=all

Comment 5

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

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

Comment 6

[Treeherder Bug Filer]

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

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=429390376&repo=autoland

Comment 9

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• linux2204-64-wayland: 1
  • debug: 1

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

Comment 10

[Intermittent Failures Robot]

1 failures in 3850 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-tsan-qr: 1
  • opt: 1

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

Comment 11

[Intermittent Failures Robot]

1 failures in 4018 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-ccov-qr: 1
  • opt: 1

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

Comment 12

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

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

Comment 13

[Treeherder Bug Filer]

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=461034394&repo=autoland

Comment 14

[Intermittent Failures Robot]

1 failures in 3649 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
  • opt: 1

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

Comment 15

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-beta: 1
• mozilla-central: 1

Platform and build breakdown:

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

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1829496&startday=2024-06-24&endday=2024-06-30&tree=all

Comment 16

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 1

Platform and build breakdown:

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

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

Comment 17

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

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