Closed Bug 1686293 Opened 5 years ago Closed 5 years ago

Intermittent telemetry/marionette/tests/client/test_search_counts_across_sessions.py TestSearchCounts.test_search_counts | application crashed [@ Internal_AllowTestSign + 0xf6]

Categories

(Toolkit :: Telemetry, defect)

Product:
Toolkit
Component:
Telemetry
Type:
defect

Tracking

()

Status:
RESOLVED INACTIVE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: crash, intermittent-failure)

Crash Data

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

[task 2021-01-12T17:33:27.269Z] 17:33:27     INFO - TEST-START | telemetry/marionette/tests/client/test_search_counts_across_sessions.py TestSearchCounts.test_search_counts
[task 2021-01-12T17:33:27.269Z] 17:33:27     INFO - Application command: Z:\task_1610470369\build\application\firefox\firefox.exe -no-remote -marionette --wait-for-browser -profile Z:\task_1610470369\build\tmptovsco.mozrunner
[task 2021-01-12T17:33:27.776Z] 17:33:27     INFO -  1610472807770	Toolkit.Telemetry	TRACE	TelemetryController::observe - profile-after-change notified.
[task 2021-01-12T17:33:27.776Z] 17:33:27     INFO -  1610472807770	Toolkit.Telemetry	TRACE	TelemetryController::setupTelemetry
[task 2021-01-12T17:33:27.776Z] 17:33:27     INFO -  1610472807772	Toolkit.Telemetry	TRACE	TelemetryReportingPolicy::setup
[task 2021-01-12T17:33:27.776Z] 17:33:27     INFO -  1610472807772	Toolkit.Telemetry	CONFIG	TelemetryController::enableTelemetryRecording - canRecordBase:true, canRecordExtended: false
[task 2021-01-12T17:33:27.776Z] 17:33:27     INFO -  1610472807772	Toolkit.Telemetry	TRACE	TelemetrySession::earlyInit
[task 2021-01-12T17:33:27.779Z] 17:33:27     INFO -  1610472807778	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet.
[task 2021-01-12T17:33:27.779Z] 17:33:27     INFO -  1610472807779	Toolkit.Telemetry	TRACE	UpdatePing::init - enabled: true
[task 2021-01-12T17:33:27.794Z] 17:33:27     INFO -  1610472807783	Toolkit.Telemetry	TRACE	TelemetryEnvironment::constructor
[task 2021-01-12T17:33:27.809Z] 17:33:27     INFO -  1610472807797	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_getGFXData - Only one display adapter detected.
[task 2021-01-12T17:33:27.809Z] 17:33:27     INFO -  1610472807799	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_updateSearchEngine - ignoring early call
[task 2021-01-12T17:33:27.809Z] 17:33:27     INFO -  1610472807799	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_updateAddons
[task 2021-01-12T17:33:27.809Z] 17:33:27     INFO -  1610472807802	Toolkit.Telemetry	TRACE	TelemetryEnvironment::registerChangeListener for CrashAnnotator
[task 2021-01-12T17:33:27.824Z] 17:33:27     INFO -  1610472807816	Marionette	TRACE	Marionette enabled
[task 2021-01-12T17:33:27.899Z] 17:33:27     INFO -  1610472807896	Marionette	TRACE	Received observer notification toplevel-window-ready
[task 2021-01-12T17:33:27.914Z] 17:33:27     INFO -  1610472807911	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_updateAddons: addons differ
[task 2021-01-12T17:33:28.149Z] 17:33:28     INFO -  1610472808144	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: auto-update-config-change, aData: false
[task 2021-01-12T17:33:28.376Z] 17:33:28     INFO -  1610472808374	Toolkit.Telemetry	TRACE	TelemetryController::observe - app-startup notified.
[task 2021-01-12T17:33:28.376Z] 17:33:28     INFO -  1610472808375	Toolkit.Telemetry	CONFIG	TelemetryController::enableTelemetryRecording - canRecordBase:true, canRecordExtended: false
[task 2021-01-12T17:33:28.415Z] 17:33:28     INFO -  1610472808406	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: compositor:created, aData: null
[task 2021-01-12T17:33:28.470Z] 17:33:28     INFO -  1610472808464	Toolkit.Telemetry	TRACE	TelemetrySession::observe - user-interaction-active notified.
[task 2021-01-12T17:33:28.485Z] 17:33:28     INFO -  1610472808474	Toolkit.Telemetry	TRACE	TelemetryController::observe - app-startup notified.
[task 2021-01-12T17:33:28.485Z] 17:33:28     INFO -  1610472808475	Toolkit.Telemetry	CONFIG	TelemetryController::enableTelemetryRecording - canRecordBase:true, canRecordExtended: false
[task 2021-01-12T17:33:28.500Z] 17:33:28     INFO -  1610472808491	Toolkit.Telemetry	TRACE	TelemetrySession::observe - xul-window-visible notified.
[task 2021-01-12T17:33:28.667Z] 17:33:28     INFO -  console.warn: SearchSettings: "get: No settings file exists, new profile?" (new Error("", "(unknown module)"))
[task 2021-01-12T17:33:28.707Z] 17:33:28     INFO -  1610472808702	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: sessionstore-windows-restored, aData: null
[task 2021-01-12T17:33:28.707Z] 17:33:28     INFO -  1610472808704	Toolkit.Telemetry	TRACE	TelemetrySession::observe - sessionstore-windows-restored notified.
[task 2021-01-12T17:33:28.707Z] 17:33:28     INFO -  1610472808704	Toolkit.Telemetry	TRACE	TelemetrySession::gatherStartup
[task 2021-01-12T17:33:28.707Z] 17:33:28     INFO -  1610472808705	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet.
[task 2021-01-12T17:33:28.708Z] 17:33:28     INFO -  1610472808705	Toolkit.Telemetry	TRACE	TelemetryReportingPolicy::_shouldNotify - User already notified or bypassing the policy.
[task 2021-01-12T17:33:28.808Z] 17:33:28     INFO -  1610472808802	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: browser-search-service, aData: settings-update-complete
[task 2021-01-12T17:33:29.223Z] 17:33:29     INFO -  1610472809212	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_startWatchingPrefs - [object Map]
[task 2021-01-12T17:33:29.238Z] 17:33:29     INFO -  1610472809230	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: extensions.webextensions.uuids
[task 2021-01-12T17:33:29.253Z] 17:33:29     INFO -  1610472809246	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: extensions.webextensions.uuids
[task 2021-01-12T17:33:29.268Z] 17:33:29     INFO -  1610472809257	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: browser-search-service, aData: init-complete
[task 2021-01-12T17:33:29.268Z] 17:33:29     INFO -  1610472809257	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_updateSearchEngine - isInitialized: true
[task 2021-01-12T17:33:29.268Z] 17:33:29     INFO -  1610472809259	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.storageVersion
[task 2021-01-12T17:33:29.268Z] 17:33:29     INFO -  1610472809260	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.urlbar.placeholderName
[task 2021-01-12T17:33:29.287Z] 17:33:29     INFO -  1610472809280	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: network.trr.blocklist_cleanup_done
[task 2021-01-12T17:33:29.287Z] 17:33:29     INFO -  1610472809280	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: app.update.lastUpdateTime.region-update-timer
[task 2021-01-12T17:33:29.322Z] 17:33:29     INFO -  1610472809316	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: distribution-customization-complete, aData: null
[task 2021-01-12T17:33:29.322Z] 17:33:29     INFO -  1610472809317	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.bookmarks.restore_default_bookmarks
[task 2021-01-12T17:33:29.377Z] 17:33:29     INFO -  1610472809371	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.migrationVersion
[task 2021-01-12T17:33:29.377Z] 17:33:29     INFO -  1610472809371	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.cursorToolOnLoad
[task 2021-01-12T17:33:29.377Z] 17:33:29     INFO -  1610472809372	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.defaultZoomValue
[task 2021-01-12T17:33:29.377Z] 17:33:29     INFO -  1610472809372	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.disablePageLabels
[task 2021-01-12T17:33:29.378Z] 17:33:29     INFO -  1610472809372	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.enablePermissions
[task 2021-01-12T17:33:29.378Z] 17:33:29     INFO -  1610472809372	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.enablePrintAutoRotate
[task 2021-01-12T17:33:29.378Z] 17:33:29     INFO -  1610472809372	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.enableScripting
[task 2021-01-12T17:33:29.378Z] 17:33:29     INFO -  1610472809373	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.enableWebGL
[task 2021-01-12T17:33:29.378Z] 17:33:29     INFO -  1610472809373	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.externalLinkTarget
[task 2021-01-12T17:33:29.378Z] 17:33:29     INFO -  1610472809373	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.historyUpdateUrl
[task 2021-01-12T17:33:29.378Z] 17:33:29     INFO -  1610472809373	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.ignoreDestinationZoom
[task 2021-01-12T17:33:29.378Z] 17:33:29     INFO -  1610472809373	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.pdfBugEnabled
[task 2021-01-12T17:33:29.379Z] 17:33:29     INFO -  1610472809373	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.renderer
[task 2021-01-12T17:33:29.379Z] 17:33:29     INFO -  1610472809373	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.sidebarViewOnLoad
[task 2021-01-12T17:33:29.379Z] 17:33:29     INFO -  1610472809374	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.scrollModeOnLoad
[task 2021-01-12T17:33:29.380Z] 17:33:29     INFO -  1610472809374	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.spreadModeOnLoad
[task 2021-01-12T17:33:29.380Z] 17:33:29     INFO -  1610472809374	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.textLayerMode
[task 2021-01-12T17:33:29.380Z] 17:33:29     INFO -  1610472809374	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.useOnlyCssZoom
[task 2021-01-12T17:33:29.381Z] 17:33:29     INFO -  1610472809375	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.viewerCssTheme
[task 2021-01-12T17:33:29.381Z] 17:33:29     INFO -  1610472809375	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.viewOnLoad
[task 2021-01-12T17:33:29.381Z] 17:33:29     INFO -  1610472809375	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.disableAutoFetch
[task 2021-01-12T17:33:29.381Z] 17:33:29     INFO -  1610472809375	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.disableFontFace
[task 2021-01-12T17:33:29.381Z] 17:33:29     INFO -  1610472809375	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.disableRange
[task 2021-01-12T17:33:29.382Z] 17:33:29     INFO -  1610472809375	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.disableStream
[task 2021-01-12T17:33:29.382Z] 17:33:29     INFO -  1610472809377	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.download.viewableInternally.typeWasRegistered.xml
[task 2021-01-12T17:33:29.382Z] 17:33:29     INFO -  1610472809377	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.download.viewableInternally.typeWasRegistered.svg
[task 2021-01-12T17:33:29.382Z] 17:33:29     INFO -  1610472809377	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.download.viewableInternally.typeWasRegistered.webp
[task 2021-01-12T17:33:29.382Z] 17:33:29     INFO -  1610472809378	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.download.viewableInternally.typeWasRegistered.avif
[task 2021-01-12T17:33:29.501Z] 17:33:29     INFO -  1610472809496	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.uiCustomization.state
[task 2021-01-12T17:33:29.501Z] 17:33:29     INFO -  1610472809497	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.bookmarks.addedImportButton
[task 2021-01-12T17:33:29.528Z] 17:33:29     INFO -  1610472809524	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_onEnvironmentChange for system-info
[task 2021-01-12T17:33:29.528Z] 17:33:29     INFO -  1610472809525	Toolkit.Telemetry	DEBUG	TelemetryEnvironment::_onEnvironmentChange - calling CrashAnnotator
[task 2021-01-12T17:33:29.529Z] 17:33:29     INFO -  1610472809525	Toolkit.Telemetry	TRACE	ClientID::_doLoadClientIDs
[task 2021-01-12T17:33:29.529Z] 17:33:29     INFO -  1610472809527	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: toolkit.telemetry.cachedClientID
[task 2021-01-12T17:33:29.529Z] 17:33:29     INFO -  1610472809527	Toolkit.Telemetry	TRACE	ClientID::_saveClientIDs
[task 2021-01-12T17:33:29.549Z] 17:33:29     INFO -  1610472809546	Toolkit.Telemetry	TRACE	ClientID::_doLoadClientIDs: New client IDs loaded and persisted.
[task 2021-01-12T17:33:29.549Z] 17:33:29     INFO -  1610472809546	Toolkit.Telemetry	TRACE	TelemetrySend::setup
[task 2021-01-12T17:33:29.549Z] 17:33:29     INFO -  1610472809546	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet.
[task 2021-01-12T17:33:29.552Z] 17:33:29     INFO -  1610472809550	Toolkit.Telemetry	TRACE	TelemetryStorage::_scanPendingPings
[task 2021-01-12T17:33:29.552Z] 17:33:29     INFO -  1610472809550	Toolkit.Telemetry	TRACE	TelemetryStorage::_migrateAppDataPings
[task 2021-01-12T17:33:29.552Z] 17:33:29     INFO -  1610472809550	Toolkit.Telemetry	TRACE	TelemetryStorage::_iterateAppDataPings
[task 2021-01-12T17:33:29.567Z] 17:33:29     INFO -  1610472809558	Toolkit.Telemetry	INFO	TelemetrySend::_checkPendingPings - pending ping count: 0
[task 2021-01-12T17:33:29.567Z] 17:33:29     INFO -  1610472809558	Toolkit.Telemetry	TRACE	TelemetrySend::_checkPendingPings - no pending pings
[task 2021-01-12T17:33:29.567Z] 17:33:29     INFO -  1610472809558	Toolkit.Telemetry	TRACE	TelemetryStorage::_enforcePendingPingsQuota
[task 2021-01-12T17:33:29.567Z] 17:33:29     INFO -  1610472809559	Toolkit.Telemetry	TRACE	TelemetrySend::Scheduler::triggerSendingPings - active send task: false, immediately: true
[task 2021-01-12T17:33:29.567Z] 17:33:29     INFO -  1610472809559	Toolkit.Telemetry	TRACE	TelemetrySend::Scheduler::_doSendTask iteration
[task 2021-01-12T17:33:29.567Z] 17:33:29     INFO -  1610472809559	Toolkit.Telemetry	TRACE	TelemetrySend::Scheduler::_doSendTask - pending: 0, current: 0
[task 2021-01-12T17:33:29.568Z] 17:33:29     INFO -  1610472809559	Toolkit.Telemetry	TRACE	TelemetrySend::Scheduler::_doSendTask - can send - pending: 0, current: 0
[task 2021-01-12T17:33:29.568Z] 17:33:29     INFO -  1610472809559	Toolkit.Telemetry	TRACE	TelemetrySend::Scheduler::_doSendTask - no pending pings, bailing out
[task 2021-01-12T17:33:29.568Z] 17:33:29     INFO -  1610472809559	Toolkit.Telemetry	TRACE	TelemetrySession::delayedInit
[task 2021-01-12T17:33:29.568Z] 17:33:29     INFO -  1610472809559	Toolkit.Telemetry	TRACE	TelemetryStorage::_popAndPerformQueuedOperation - Performing queued operation.
[task 2021-01-12T17:33:29.568Z] 17:33:29     INFO -  1610472809560	Toolkit.Telemetry	INFO	TelemetryStorage::_loadSessionData - can not load session data file: {"operation":"open","path":"Z:\\task_1610470369\\build\\tmptovsco.mozrunner\\datareporting\\session-state.json","winLastError":2}
[task 2021-01-12T17:33:29.568Z] 17:33:29     INFO -  1610472809561	Toolkit.Telemetry	TRACE	TelemetryStorage::_popAndPerformQueuedOperation - Performing queued operation.
[task 2021-01-12T17:33:29.588Z] 17:33:29     INFO -  1610472809581	Toolkit.Telemetry	TRACE	TelemetryStorage::loadPingfile - unreadable ping Z:\task_1610470369\build\tmptovsco.mozrunner\datareporting\aborted-session-ping: {"operation":"open","path":"Z:\\task_1610470369\\build\\tmptovsco.mozrunner\\datareporting\\aborted-session-ping","winLastError":2}
[task 2021-01-12T17:33:29.588Z] 17:33:29     INFO -  1610472809581	Toolkit.Telemetry	TRACE	TelemetryStorage::loadAbortedSessionPing - no such file
[task 2021-01-12T17:33:29.588Z] 17:33:29     INFO -  1610472809581	Toolkit.Telemetry	TRACE	TelemetryController::checkAbortedSessionPing - found aborted-session ping: false
[task 2021-01-12T17:33:29.588Z] 17:33:29     INFO -  1610472809581	Toolkit.Telemetry	TRACE	TelemetrySession::_saveAbortedSessionPing
[task 2021-01-12T17:33:29.588Z] 17:33:29     INFO -  1610472809581	Toolkit.Telemetry	TRACE	TelemetrySession::getSessionPayload - reason: aborted-session, clearSubsession: false
[task 2021-01-12T17:33:29.589Z] 17:33:29     INFO -  1610472809583	Toolkit.Telemetry	TRACE	TelemetrySession::assemblePayloadWithMeasurements - reason: aborted-session, submitting subsession data: true
[task 2021-01-12T17:33:29.589Z] 17:33:29     INFO -  1610472809585	Toolkit.Telemetry	TRACE	TelemetryController::saveAbortedSessionPing
[task 2021-01-12T17:33:29.589Z] 17:33:29     INFO -  1610472809585	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type main, aOptions {"addClientId":true,"addEnvironment":true}
[task 2021-01-12T17:33:29.596Z] 17:33:29     INFO -  1610472809587	Toolkit.Telemetry	TRACE	TelemetryStorage::saveAbortedSessionPing - ping path: Z:\task_1610470369\build\tmptovsco.mozrunner\datareporting\aborted-session-ping
[task 2021-01-12T17:33:29.596Z] 17:33:29     INFO -  1610472809592	Toolkit.Telemetry	TRACE	TelemetryStorage::_popAndPerformQueuedOperation - Performing queued operation.
[task 2021-01-12T17:33:29.596Z] 17:33:29     INFO -  1610472809592	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: Z:\task_1610470369\build\tmptovsco.mozrunner\datareporting\aborted-session-ping
[task 2021-01-12T17:33:29.596Z] 17:33:29     INFO -  1610472809593	Marionette	TRACE	Received observer notification marionette-startup-requested
[task 2021-01-12T17:33:29.597Z] 17:33:29     INFO -  1610472809593	Marionette	TRACE	Waiting until startup recorder finished recording startup scripts...
[task 2021-01-12T17:33:29.605Z] 17:33:29     INFO -  1610472809599	Toolkit.Telemetry	TRACE	TelemetryEnvironment::registerChangeListener for TelemetrySession::onEnvironmentChange
[task 2021-01-12T17:33:29.605Z] 17:33:29     INFO -  1610472809602	Toolkit.Telemetry	TRACE	TelemetryScheduler::init
[task 2021-01-12T17:33:29.605Z] 17:33:29     INFO -  1610472809602	Toolkit.Telemetry	TRACE	TelemetryScheduler::_rescheduleTimeout - isUserIdle: false
[task 2021-01-12T17:33:29.605Z] 17:33:29     INFO -  1610472809602	Toolkit.Telemetry	TRACE	TelemetryScheduler::_rescheduleTimeout - scheduling next tick for Tue Jan 12 2021 17:38:29 GMT+0000 (Greenwich Mean Time)
[task 2021-01-12T17:33:29.605Z] 17:33:29     INFO -  1610472809602	Toolkit.Telemetry	TRACE	TelemetryController::scheduleNewProfilePing
[task 2021-01-12T17:33:29.605Z] 17:33:29     INFO -  1610472809602	Toolkit.Telemetry	TRACE	TelemetryStorage::cleanArchiveTask
[task 2021-01-12T17:33:29.606Z] 17:33:29     INFO -  1610472809602	Toolkit.Telemetry	TRACE	TelemetryStorage::removeFHRDatabase
[task 2021-01-12T17:33:29.606Z] 17:33:29     INFO -  1610472809603	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: app.update.lastUpdateTime.telemetry_modules_ping
[task 2021-01-12T17:33:29.613Z] 17:33:29     INFO -  1610472809608	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: app.update.lastUpdateTime.telemetry_untrustedmodules_ping
[task 2021-01-12T17:33:29.616Z] 17:33:29     INFO -  1610472809612	Toolkit.Telemetry	TRACE	TelemetryEventPing::::Starting up.
[task 2021-01-12T17:33:29.616Z] 17:33:29     INFO -  1610472809613	Toolkit.Telemetry	TRACE	TelemetryPrioPing::Extended collection disabled. Prio ping disabled.
[task 2021-01-12T17:33:29.616Z] 17:33:29     INFO -  1610472809613	Toolkit.Telemetry	TRACE	TelemetryController::saveUninstallPing
[task 2021-01-12T17:33:29.616Z] 17:33:29     INFO -  1610472809613	Toolkit.Telemetry	INFO	TelemetryController::saveUninstallPing - otherInstalls: 0
[task 2021-01-12T17:33:29.616Z] 17:33:29     INFO -  1610472809613	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type uninstall, aOptions {"addClientId":true,"addEnvironment":true}
[task 2021-01-12T17:33:29.623Z] 17:33:29     INFO -  1610472809620	Toolkit.Telemetry	TRACE	TelemetryStorage::removeUninstallPings - removing: C:\ProgramData\Mozilla\uninstall_ping_C1E6CC71BA9FC624_f8234da1-248d-4df2-83d5-f522c35ff7e9.json
[task 2021-01-12T17:33:29.623Z] 17:33:29     INFO -  1610472809622	Toolkit.Telemetry	TRACE	TelemetryStorage::removeUninstallPings - success
[task 2021-01-12T17:33:29.630Z] 17:33:29     INFO -  1610472809623	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: C:\ProgramData\Mozilla\uninstall_ping_C1E6CC71BA9FC624_3b847b3f-1894-48fc-9ab1-6efa1f78b73a.json
[task 2021-01-12T17:33:29.657Z] 17:33:29     INFO -  1610472809650	Marionette	TRACE	All scripts recorded.
[task 2021-01-12T17:33:29.657Z] 17:33:29     INFO -  1610472809652	Marionette	INFO	Listening on port 2828
[task 2021-01-12T17:33:29.657Z] 17:33:29     INFO -  1610472809652	Marionette	DEBUG	Marionette is listening
[task 2021-01-12T17:33:29.692Z] 17:33:29     INFO -  1610472809685	Toolkit.Telemetry	TRACE	TelemetryController::observe - app-startup notified.
[task 2021-01-12T17:33:29.692Z] 17:33:29     INFO -  1610472809687	Toolkit.Telemetry	CONFIG	TelemetryController::enableTelemetryRecording - canRecordBase:true, canRecordExtended: false
[task 2021-01-12T17:33:29.707Z] 17:33:29     INFO -  1610472809698	Marionette	DEBUG	Accepted connection 0 from 127.0.0.1:49555
[task 2021-01-12T17:33:29.727Z] 17:33:29     INFO -  1610472809723	Marionette	DEBUG	Closed connection 0
[task 2021-01-12T17:33:29.727Z] 17:33:29     INFO -  1610472809724	Marionette	DEBUG	Accepted connection 1 from 127.0.0.1:49556
[task 2021-01-12T17:33:29.742Z] 17:33:29     INFO -  1610472809735	Marionette	DEBUG	1 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2021-01-12T17:33:29.749Z] 17:33:29     INFO -  1610472809746	Marionette	DEBUG	1 <- [1,1,null,{"sessionId":"200af94a-d44d-4aa1-b234-7389c5acd451","capabilities":{"browserName":"firefox","browserVersion":"86.0a ... d\\tmptovsco.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}]
[task 2021-01-12T17:33:29.756Z] 17:33:29     INFO -  1610472809751	Marionette	DEBUG	1 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}]
[task 2021-01-12T17:33:29.756Z] 17:33:29     INFO -  1610472809751	Marionette	DEBUG	1 <- [1,2,null,{"value":null}]
[task 2021-01-12T17:33:29.759Z] 17:33:29     INFO -  1610472809757	Marionette	DEBUG	1 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2021-01-12T17:33:29.759Z] 17:33:29     INFO -  1610472809757	Marionette	DEBUG	1 <- [1,3,null,{"value":null}]
[task 2021-01-12T17:33:29.762Z] 17:33:29     INFO -  1610472809759	Marionette	DEBUG	1 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2021-01-12T17:33:29.762Z] 17:33:29     INFO -  1610472809759	Marionette	DEBUG	1 <- [1,4,null,{"value":null}]
[task 2021-01-12T17:33:29.762Z] 17:33:29     INFO -  1610472809761	Marionette	DEBUG	1 -> [0,5,"WebDriver:GetChromeWindowHandle",{}]
[task 2021-01-12T17:33:29.765Z] 17:33:29     INFO -  1610472809761	Marionette	DEBUG	1 <- [1,5,null,{"value":"6"}]
[task 2021-01-12T17:33:29.765Z] 17:33:29     INFO -  1610472809763	Marionette	DEBUG	1 -> [0,6,"WebDriver:GetChromeWindowHandles",{}]
[task 2021-01-12T17:33:29.765Z] 17:33:29     INFO -  1610472809763	Marionette	DEBUG	1 <- [1,6,null,["6"]]
[task 2021-01-12T17:33:29.768Z] 17:33:29     INFO -  1610472809766	Marionette	DEBUG	1 -> [0,7,"WebDriver:GetWindowHandle",{}]
[task 2021-01-12T17:33:29.768Z] 17:33:29     INFO -  1610472809766	Marionette	DEBUG	1 <- [1,7,null,{"value":"17"}]
[task 2021-01-12T17:33:29.771Z] 17:33:29     INFO -  1610472809768	Marionette	DEBUG	1 -> [0,8,"WebDriver:GetWindowHandles",{}]
[task 2021-01-12T17:33:29.771Z] 17:33:29     INFO -  1610472809768	Marionette	DEBUG	1 <- [1,8,null,["17"]]
[task 2021-01-12T17:33:29.774Z] 17:33:29     INFO -  1610472809772	Marionette	DEBUG	1 -> [0,9,"Marionette:GetContext",{}]
[task 2021-01-12T17:33:29.774Z] 17:33:29     INFO -  1610472809772	Marionette	DEBUG	1 <- [1,9,null,{"value":"content"}]
[task 2021-01-12T17:33:29.777Z] 17:33:29     INFO -  1610472809775	Marionette	DEBUG	1 -> [0,10,"Marionette:SetContext",{"value":"content"}]
[task 2021-01-12T17:33:29.777Z] 17:33:29     INFO -  1610472809775	Marionette	DEBUG	1 <- [1,10,null,{"value":null}]
[task 2021-01-12T17:33:29.784Z] 17:33:29     INFO -  1610472809779	Marionette	DEBUG	1 -> [0,11,"WebDriver:Navigate",{"url":"about:about"}]
[task 2021-01-12T17:33:29.785Z] 17:33:29     INFO -  1610472809783	Marionette	TRACE	[17] MarionetteCommands actor created for window id 2147483649
[task 2021-01-12T17:33:29.792Z] 17:33:29     INFO -  1610472809790	Marionette	TRACE	[17] MarionetteEvents actor created for window id 2147483649
[task 2021-01-12T17:33:29.793Z] 17:33:29     INFO -  1610472809791	Marionette	TRACE	Received event beforeunload for about:blank
[task 2021-01-12T17:33:29.800Z] 17:33:29     INFO -  1610472809797	Marionette	TRACE	Remoteness change detected. Set new top-level browsing context to 36
[task 2021-01-12T17:33:29.819Z] 17:33:29     INFO -  1610472809815	Marionette	TRACE	[36] MarionetteEvents actor created for window id 25
[task 2021-01-12T17:33:29.846Z] 17:33:29     INFO -  1610472809842	Marionette	TRACE	Received event beforeunload for about:blank
[task 2021-01-12T17:33:29.846Z] 17:33:29     INFO -  1610472809843	Marionette	TRACE	Received event pagehide for about:blank
[task 2021-01-12T17:33:29.885Z] 17:33:29     INFO -  1610472809882	Marionette	TRACE	[36] MarionetteEvents actor created for window id 26
[task 2021-01-12T17:33:29.892Z] 17:33:29     INFO -  1610472809886	Marionette	TRACE	Received event DOMContentLoaded for about:about
[task 2021-01-12T17:33:29.927Z] 17:33:29     INFO -  1610472809915	Marionette	TRACE	Received event pageshow for about:about
[task 2021-01-12T17:33:29.927Z] 17:33:29     INFO -  1610472809915	Marionette	DEBUG	1 <- [1,11,null,{"value":null}]
[task 2021-01-12T17:33:29.927Z] 17:33:29     INFO -  1610472809919	Marionette	DEBUG	1 -> [0,12,"Marionette:SetContext",{"value":"content"}]
[task 2021-01-12T17:33:29.927Z] 17:33:29     INFO -  1610472809919	Marionette	DEBUG	1 <- [1,12,null,{"value":null}]
[task 2021-01-12T17:33:29.927Z] 17:33:29     INFO -  1610472809921	Marionette	DEBUG	1 -> [0,13,"Marionette:GetContext",{}]
[task 2021-01-12T17:33:29.927Z] 17:33:29     INFO -  1610472809922	Marionette	DEBUG	1 <- [1,13,null,{"value":"content"}]
[task 2021-01-12T17:33:29.934Z] 17:33:29     INFO -  1610472809926	Marionette	DEBUG	1 -> [0,14,"Marionette:SetContext",{"value":"chrome"}]
[task 2021-01-12T17:33:29.934Z] 17:33:29     INFO -  1610472809926	Marionette	DEBUG	1 <- [1,14,null,{"value":null}]
[task 2021-01-12T17:33:29.934Z] 17:33:29     INFO -  1610472809928	Marionette	DEBUG	1 -> [0,15,"WebDriver:ExecuteAsyncScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"Z:\\task_1610470369\\build ... chService.init().then(function () {\n  resolve(searchService.defaultEngine.identifier);\n});","sandbox":"default","line":37}]
[task 2021-01-12T17:33:29.934Z] 17:33:29     INFO -  1610472809929	Marionette	TRACE	[6] MarionetteCommands actor created for window id 2
[task 2021-01-12T17:33:29.949Z] 17:33:29     INFO -  1610472809939	Marionette	DEBUG	1 <- [1,15,null,{"value":"google-b-d"}]
[task 2021-01-12T17:33:29.949Z] 17:33:29     INFO -  1610472809942	Marionette	DEBUG	1 -> [0,16,"Marionette:SetContext",{"value":"content"}]
[task 2021-01-12T17:33:29.949Z] 17:33:29     INFO -  1610472809942	Marionette	DEBUG	1 <- [1,16,null,{"value":null}]
[task 2021-01-12T17:33:29.949Z] 17:33:29     INFO -  1610472809944	Marionette	DEBUG	1 -> [0,17,"Marionette:GetContext",{}]
[task 2021-01-12T17:33:29.949Z] 17:33:29     INFO -  1610472809944	Marionette	DEBUG	1 <- [1,17,null,{"value":"content"}]
[task 2021-01-12T17:33:29.956Z] 17:33:29     INFO -  1610472809949	Marionette	DEBUG	1 -> [0,18,"Marionette:SetContext",{"value":"chrome"}]
[task 2021-01-12T17:33:29.956Z] 17:33:29     INFO -  1610472809949	Marionette	DEBUG	1 <- [1,18,null,{"value":null}]
[task 2021-01-12T17:33:29.956Z] 17:33:29     INFO -  1610472809950	Marionette	DEBUG	1 -> [0,19,"WebDriver:GetWindowHandle",{}]
[task 2021-01-12T17:33:29.957Z] 17:33:29     INFO -  1610472809951	Marionette	DEBUG	1 <- [1,19,null,{"value":"36"}]
[task 2021-01-12T17:33:29.957Z] 17:33:29     INFO -  1610472809951	Marionette	DEBUG	1 -> [0,20,"WebDriver:GetWindowHandles",{}]
[task 2021-01-12T17:33:29.957Z] 17:33:29     INFO -  1610472809952	Marionette	DEBUG	1 <- [1,20,null,["36"]]
[task 2021-01-12T17:33:29.957Z] 17:33:29     INFO -  1610472809953	Marionette	DEBUG	1 -> [0,21,"WebDriver:NewWindow",{"type":"tab","focus":true,"private":false}]
[task 2021-01-12T17:33:29.964Z] 17:33:29     INFO -  1610472809958	Marionette	TRACE	Received DOM event TabOpen for [object XULElement]
[task 2021-01-12T17:33:29.979Z] 17:33:29     INFO -  1610472809975	Marionette	TRACE	[38] MarionetteEvents actor created for window id 28
[task 2021-01-12T17:33:29.999Z] 17:33:29     INFO -  1610472809996	Marionette	TRACE	Received event beforeunload for about:blank
[task 2021-01-12T17:33:30.014Z] 17:33:30     INFO -  1610472810009	Marionette	TRACE	Received event pagehide for about:blank
[task 2021-01-12T17:33:30.031Z] 17:33:30     INFO -  1610472810022	Marionette	TRACE	[38] MarionetteEvents actor created for window id 6442450945
[task 2021-01-12T17:33:30.031Z] 17:33:30     INFO -  1610472810023	Marionette	TRACE	Received event DOMContentLoaded for about:blank
[task 2021-01-12T17:33:30.031Z] 17:33:30     INFO -  1610472810024	Marionette	TRACE	Received event pageshow for about:blank
[task 2021-01-12T17:33:30.031Z] 17:33:30     INFO -  1610472810024	Marionette	DEBUG	1 <- [1,21,null,{"handle":"38","type":"tab"}]
[task 2021-01-12T17:33:30.066Z] 17:33:30     INFO -  1610472810055	Marionette	DEBUG	1 -> [0,22,"WebDriver:GetWindowHandles",{}]
[task 2021-01-12T17:33:30.066Z] 17:33:30     INFO -  1610472810055	Marionette	DEBUG	1 <- [1,22,null,["36","38"]]
[task 2021-01-12T17:33:30.070Z] 17:33:30     INFO -  1610472810067	Marionette	DEBUG	1 -> [0,23,"WebDriver:GetWindowHandles",{}]
[task 2021-01-12T17:33:30.070Z] 17:33:30     INFO -  1610472810067	Marionette	DEBUG	1 <- [1,23,null,["36","38"]]
[task 2021-01-12T17:33:30.077Z] 17:33:30     INFO -  1610472810074	Marionette	DEBUG	1 -> [0,24,"WebDriver:SwitchToWindow",{"handle":"38","focus":true}]
[task 2021-01-12T17:33:30.077Z] 17:33:30     INFO -  1610472810075	Marionette	DEBUG	1 <- [1,24,null,{"value":null}]
[task 2021-01-12T17:33:30.080Z] 17:33:30     INFO -  1610472810077	Marionette	DEBUG	1 -> [0,25,"Marionette:GetContext",{}]
[task 2021-01-12T17:33:30.080Z] 17:33:30     INFO -  1610472810077	Marionette	DEBUG	1 <- [1,25,null,{"value":"chrome"}]
[task 2021-01-12T17:33:30.083Z] 17:33:30     INFO -  1610472810079	Marionette	DEBUG	1 -> [0,26,"Marionette:SetContext",{"value":"content"}]
[task 2021-01-12T17:33:30.083Z] 17:33:30     INFO -  1610472810080	Marionette	DEBUG	1 <- [1,26,null,{"value":null}]
[task 2021-01-12T17:33:30.090Z] 17:33:30     INFO -  1610472810086	Marionette	DEBUG	1 -> [0,27,"WebDriver:Navigate",{"url":"about:newtab"}]
[task 2021-01-12T17:33:30.093Z] 17:33:30     INFO -  1610472810090	Marionette	TRACE	[38] MarionetteCommands actor created for window id 6442450945
[task 2021-01-12T17:33:30.096Z] 17:33:30     INFO -  1610472810093	Marionette	TRACE	Received event beforeunload for about:blank
[task 2021-01-12T17:33:30.113Z] 17:33:30     INFO -  1610472810103	Marionette	TRACE	Received event pagehide for about:blank
[task 2021-01-12T17:33:30.113Z] 17:33:30     INFO -  1610472810104	Marionette	TRACE	[38] MarionetteEvents actor created for window id 6442450946
[task 2021-01-12T17:33:30.113Z] 17:33:30     INFO -  1610472810110	Marionette	TRACE	Received event DOMContentLoaded for about:blank
[task 2021-01-12T17:33:30.114Z] 17:33:30     INFO -  1610472810111	Marionette	TRACE	Received event pageshow for about:blank
[task 2021-01-12T17:33:30.121Z] 17:33:30     INFO -  1610472810115	Marionette	DEBUG	1 <- [1,27,null,{"value":null}]
[task 2021-01-12T17:33:30.136Z] 17:33:30     INFO -  1610472810127	Marionette	DEBUG	1 -> [0,28,"Marionette:SetContext",{"value":"chrome"}]
[task 2021-01-12T17:33:30.136Z] 17:33:30     INFO -  1610472810127	Marionette	DEBUG	1 <- [1,28,null,{"value":null}]
[task 2021-01-12T17:33:30.136Z] 17:33:30     INFO -  1610472810128	Marionette	DEBUG	1 -> [0,29,"Marionette:GetContext",{}]
[task 2021-01-12T17:33:30.136Z] 17:33:30     INFO -  1610472810129	Marionette	DEBUG	1 <- [1,29,null,{"value":"chrome"}]
[task 2021-01-12T17:33:30.137Z] 17:33:30     INFO -  1610472810130	Marionette	DEBUG	1 -> [0,30,"Marionette:SetContext",{"value":"chrome"}]
[task 2021-01-12T17:33:30.137Z] 17:33:30     INFO -  1610472810131	Marionette	DEBUG	1 <- [1,30,null,{"value":null}]
[task 2021-01-12T17:33:30.138Z] 17:33:30     INFO -  1610472810134	Marionette	DEBUG	1 -> [0,31,"WebDriver:ExecuteScript",{"script":"gURLBar.select();","newSandbox":true,"args":[],"filename":"Z:\\task_1610470369\\build\\venv\\lib\\site-packages\\telemetry_harness\\testcase.py","sandbox":"default","line":83}]
[task 2021-01-12T17:33:30.138Z] 17:33:30     INFO -  1610472810137	Toolkit.Telemetry	TRACE	TelemetryController::observe - app-startup notified.
[task 2021-01-12T17:33:30.141Z] 17:33:30     INFO -  1610472810139	Toolkit.Telemetry	CONFIG	TelemetryController::enableTelemetryRecording - canRecordBase:true, canRecordExtended: false
[task 2021-01-12T17:33:30.144Z] 17:33:30     INFO -  1610472810141	Marionette	DEBUG	1 <- [1,31,null,{"value":null}]
[task 2021-01-12T17:33:30.147Z] 17:33:30     INFO -  1610472810143	Marionette	DEBUG	1 -> [0,32,"WebDriver:FindElement",{"using":"id","value":"urlbar-input"}]
[task 2021-01-12T17:33:30.148Z] 17:33:30     INFO -  1610472810145	Marionette	DEBUG	1 <- [1,32,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"90a7d87a-42c6-4df3-948c-36b9b664bf92"}}]
[task 2021-01-12T17:33:30.163Z] 17:33:30     INFO -  1610472810154	Marionette	DEBUG	1 -> [0,33,"WebDriver:ElementSendKeys",{"text":"","id":"90a7d87a-42c6-4df3-948c-36b9b664bf92"}]
[task 2021-01-12T17:33:30.178Z] 17:33:30     INFO -  1610472810162	Marionette	DEBUG	1 <- [1,33,null,{"value":null}]
[task 2021-01-12T17:33:30.178Z] 17:33:30     INFO -  1610472810167	Marionette	DEBUG	1 -> [0,34,"WebDriver:ElementSendKeys",{"text":"mozilla firefox","id":"90a7d87a-42c6-4df3-948c-36b9b664bf92"}]
[task 2021-01-12T17:33:30.237Z] 17:33:30     INFO -  1610472810233	Marionette	DEBUG	1 <- [1,34,null,{"value":null}]
[task 2021-01-12T17:33:30.237Z] 17:33:30     INFO -  1610472810235	Marionette	DEBUG	1 -> [0,35,"Marionette:SetContext",{"value":"chrome"}]
[task 2021-01-12T17:33:30.238Z] 17:33:30     INFO -  1610472810236	Marionette	DEBUG	1 <- [1,35,null,{"value":null}]
[task 2021-01-12T17:33:30.277Z] 17:33:30     INFO -  1610472810274	Marionette	DEBUG	1 -> [0,36,"Marionette:GetContext",{}]
[task 2021-01-12T17:33:30.277Z] 17:33:30     INFO -  1610472810274	Marionette	DEBUG	1 <- [1,36,null,{"value":"chrome"}]
[task 2021-01-12T17:33:30.332Z] 17:33:30     INFO -  1610472810324	Marionette	DEBUG	1 -> [0,37,"Marionette:SetContext",{"value":"content"}]
[task 2021-01-12T17:33:30.332Z] 17:33:30     INFO -  1610472810324	Marionette	DEBUG	1 <- [1,37,null,{"value":null}]
[task 2021-01-12T17:33:30.347Z] 17:33:30     INFO -  1610472810343	Marionette	DEBUG	1 -> [0,38,"WebDriver:ExecuteScript",{"script":"let location = document.location.toString()\n        function validate(term){\n    ... name":"Z:\\task_1610470369\\build\\venv\\lib\\site-packages\\telemetry_harness\\testcase.py","sandbox":"default","line":100}]
[task 2021-01-12T17:33:30.347Z] 17:33:30     INFO -  1610472810345	Marionette	TRACE	[38] MarionetteCommands actor created for window id 6442450946
[task 2021-01-12T17:33:30.366Z] 17:33:30     INFO -  1610472810360	Marionette	DEBUG	1 <- [1,38,null,{"value":false}]
[task 2021-01-12T17:33:30.381Z] 17:33:30     INFO -  1610472810378	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: browser-search-service, aData: write-settings-to-disk-complete
[task 2021-01-12T17:33:30.564Z] 17:33:30     INFO -  1610472810561	Marionette	TRACE	[38] MarionetteEvents actor created for window id 30
[task 2021-01-12T17:33:30.719Z] 17:33:30     INFO -  1610472810709	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.safebrowsing.provider.mozilla.lastupdatetime
[task 2021-01-12T17:33:30.719Z] 17:33:30     INFO -  1610472810709	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.safebrowsing.provider.mozilla.nextupdatetime
[task 2021-01-12T17:33:30.840Z] 17:33:30     INFO -  1610472810834	Marionette	DEBUG	1 -> [0,39,"WebDriver:ExecuteScript",{"script":"let location = document.location.toString()\n        function validate(term){\n    ... name":"Z:\\task_1610470369\\build\\venv\\lib\\site-packages\\telemetry_harness\\testcase.py","sandbox":"default","line":100}]
[task 2021-01-12T17:33:30.840Z] 17:33:30     INFO -  1610472810836	Marionette	TRACE	[38] MarionetteCommands actor created for window id 2147483650
[task 2021-01-12T17:33:30.847Z] 17:33:30     INFO -  1610472810841	Marionette	DEBUG	1 <- [1,39,null,{"value":true}]
[task 2021-01-12T17:33:30.847Z] 17:33:30     INFO -  1610472810841	Marionette	DEBUG	1 -> [0,40,"Marionette:SetContext",{"value":"chrome"}]
[task 2021-01-12T17:33:30.847Z] 17:33:30     INFO -  1610472810842	Marionette	DEBUG	1 <- [1,40,null,{"value":null}]
[task 2021-01-12T17:33:30.847Z] 17:33:30     INFO -  1610472810843	Marionette	DEBUG	1 -> [0,41,"WebDriver:CloseWindow",{}]
[task 2021-01-12T17:33:30.854Z] 17:33:30     INFO -  1610472810850	Marionette	TRACE	Received DOM event TabClose for [object XULElement]
[task 2021-01-12T17:33:30.857Z] 17:33:30     INFO -  1610472810854	Marionette	TRACE	[38] MarionetteEvents actor created for window id 2147483650
[task 2021-01-12T17:33:30.872Z] 17:33:30     INFO -  1610472810869	Marionette	TRACE	Received observer notification message-manager-disconnect
[task 2021-01-12T17:33:30.872Z] 17:33:30     INFO -  1610472810870	Marionette	DEBUG	1 <- [1,41,null,["36"]]
[task 2021-01-12T17:33:30.879Z] 17:33:30     INFO - wait_for_pings running action 'restart_browser'.
[task 2021-01-12T17:33:30.880Z] 17:33:30     INFO -  1610472810873	Marionette	DEBUG	1 -> [0,42,"WebDriver:SwitchToWindow",{"handle":"36","focus":true}]
[task 2021-01-12T17:33:30.880Z] 17:33:30     INFO -  1610472810874	Marionette	DEBUG	1 <- [1,42,null,{"value":null}]
[task 2021-01-12T17:33:30.880Z] 17:33:30     INFO -  1610472810876	Marionette	DEBUG	1 -> [0,43,"Marionette:SetContext",{"value":"content"}]
[task 2021-01-12T17:33:30.880Z] 17:33:30     INFO -  1610472810876	Marionette	DEBUG	1 <- [1,43,null,{"value":null}]
[task 2021-01-12T17:33:30.880Z] 17:33:30     INFO -  1610472810877	Marionette	DEBUG	1 -> [0,44,"Marionette:GetContext",{}]
[task 2021-01-12T17:33:30.881Z] 17:33:30     INFO -  1610472810878	Marionette	DEBUG	1 <- [1,44,null,{"value":"content"}]
[task 2021-01-12T17:33:30.884Z] 17:33:30     INFO -  1610472810878	Marionette	DEBUG	1 -> [0,45,"Marionette:AcceptConnections",{"value":false}]
[task 2021-01-12T17:33:30.884Z] 17:33:30     INFO -  1610472810879	Marionette	INFO	Stopped listening on port 2828
[task 2021-01-12T17:33:30.884Z] 17:33:30     INFO -  1610472810879	Marionette	DEBUG	1 <- [1,45,null,{"value":null}]
[task 2021-01-12T17:33:30.884Z] 17:33:30     INFO -  1610472810880	Marionette	DEBUG	1 -> [0,46,"Marionette:GetContext",{}]
[task 2021-01-12T17:33:30.884Z] 17:33:30     INFO -  1610472810880	Marionette	DEBUG	1 <- [1,46,null,{"value":"content"}]
[task 2021-01-12T17:33:30.887Z] 17:33:30     INFO -  1610472810882	Marionette	DEBUG	1 -> [0,47,"Marionette:SetContext",{"value":"chrome"}]
[task 2021-01-12T17:33:30.887Z] 17:33:30     INFO -  1610472810882	Marionette	DEBUG	1 <- [1,47,null,{"value":null}]
[task 2021-01-12T17:33:30.887Z] 17:33:30     INFO -  1610472810884	Marionette	DEBUG	1 -> [0,48,"WebDriver:ExecuteScript",{"script":"Components.utils.import(\"resource://gre/modules/Services.jsm\");\n                ... me":"Z:\\task_1610470369\\build\\venv\\lib\\site-packages\\marionette_driver\\marionette.py","sandbox":"default","line":955}]
[task 2021-01-12T17:33:30.890Z] 17:33:30     INFO -  1610472810887	Marionette	DEBUG	1 <- [1,48,null,{"value":false}]
[task 2021-01-12T17:33:30.891Z] 17:33:30     INFO -  1610472810887	Marionette	DEBUG	1 -> [0,49,"Marionette:SetContext",{"value":"content"}]
[task 2021-01-12T17:33:30.891Z] 17:33:30     INFO -  1610472810888	Marionette	DEBUG	1 <- [1,49,null,{"value":null}]
[task 2021-01-12T17:33:30.891Z] 17:33:30     INFO -  1610472810889	Marionette	DEBUG	1 -> [0,50,"Marionette:Quit",{"flags":["eForceQuit","eRestart"]}]
[task 2021-01-12T17:33:30.950Z] 17:33:30     INFO -  1610472810940	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: toolkit.startup.last_success
[task 2021-01-12T17:33:30.950Z] 17:33:30     INFO -  1610472810943	Marionette	TRACE	Received observer notification quit-application
[task 2021-01-12T17:33:30.950Z] 17:33:30     INFO -  1610472810943	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.sessionstore.resume_session_once
[task 2021-01-12T17:33:30.965Z] 17:33:30     INFO -  1610472810952	Marionette	DEBUG	1 <- [1,50,null,{"cause":"restart"}]
[task 2021-01-12T17:33:31.004Z] 17:33:31     INFO -  1610472810998	Marionette	DEBUG	Closed connection 1
[task 2021-01-12T17:33:31.019Z] 17:33:31     INFO -  1610472811008	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: privacy.sanitize.pending
[task 2021-01-12T17:33:31.114Z] 17:33:31     INFO -  1610472811102	Toolkit.Telemetry	TRACE	TelemetryController::shutdown
[task 2021-01-12T17:33:31.114Z] 17:33:31     INFO -  1610472811102	Toolkit.Telemetry	TRACE	TelemetryController::sendNewProfilePing - shutting down: true
[task 2021-01-12T17:33:31.114Z] 17:33:31     INFO -  1610472811102	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - type: new-profile, aOptions: {"addClientId":true,"addEnvironment":true,"usePingSender":true}
[task 2021-01-12T17:33:31.114Z] 17:33:31     INFO -  1610472811103	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type new-profile, aOptions {"addClientId":true,"addEnvironment":true,"usePingSender":true}
[task 2021-01-12T17:33:31.115Z] 17:33:31     INFO -  1610472811103	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - ping assembled, id: af0470ce-c66a-4853-8341-83765c90e266
[task 2021-01-12T17:33:31.115Z] 17:33:31     INFO -  1610472811104	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - ping id: af0470ce-c66a-4853-8341-83765c90e266, options: {"usePingSender":true}
[task 2021-01-12T17:33:31.115Z] 17:33:31     INFO -  1610472811104	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet.
[task 2021-01-12T17:33:31.115Z] 17:33:31     INFO -  1610472811106	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: Z:\task_1610470369\build\tmptovsco.mozrunner\datareporting\archived\2021-01\1610472811103.af0470ce-c66a-4853-8341-83765c90e266.new-profile.jsonlz4
[task 2021-01-12T17:33:31.118Z] 17:33:31     INFO -  1610472811112	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: Z:\task_1610470369\build\tmptovsco.mozrunner\saved-telemetry-pings\af0470ce-c66a-4853-8341-83765c90e266
[task 2021-01-12T17:33:31.125Z] 17:33:31     INFO -  1610472811119	Toolkit.Telemetry	TRACE	TelemetryStorage::savePendingPing - saved ping with id af0470ce-c66a-4853-8341-83765c90e266
[task 2021-01-12T17:33:31.125Z] 17:33:31     INFO -  1610472811119	Toolkit.Telemetry	TRACE	TelemetrySend::_sendWithPingSender - sending af0470ce-c66a-4853-8341-83765c90e266 to http://localhost:8000/pings/submit/telemetry/af0470ce-c66a-4853-8341-83765c90e266/new-profile/Firefox/86.0a1/default/20210112170249?v=4
[task 2021-01-12T17:33:31.125Z] 17:33:31     INFO -  1610472811119	Toolkit.Telemetry	TRACE	TelemetrySend::_sendWithPingSender - too late to send. Batching.
[task 2021-01-12T17:33:31.125Z] 17:33:31     INFO -  1610472811119	Toolkit.Telemetry	TRACE	TelemetrySession::markNewProfilePingSent
[task 2021-01-12T17:33:31.125Z] 17:33:31     INFO -  1610472811119	Toolkit.Telemetry	TRACE	TelemetryStorage::_popAndPerformQueuedOperation - Performing queued operation.
[task 2021-01-12T17:33:31.132Z] 17:33:31     INFO -  1610472811129	Toolkit.Telemetry	TRACE	TelemetryEventPing::::Shutting down.
[task 2021-01-12T17:33:31.132Z] 17:33:31     INFO -  1610472811129	Toolkit.Telemetry	TRACE	TelemetryEventPing::::_submitPing
[task 2021-01-12T17:33:31.133Z] 17:33:31     INFO -  1610472811129	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - type: event, aOptions: {"addClientId":true,"addEnvironment":true,"usePingSender":true}
[task 2021-01-12T17:33:31.133Z] 17:33:31     INFO -  1610472811129	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type event, aOptions {"addClientId":true,"addEnvironment":true,"usePingSender":true}
[task 2021-01-12T17:33:31.134Z] 17:33:31     INFO -  1610472811130	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - ping assembled, id: f711a31d-4a1b-4c10-9a41-d89154371eb7
[task 2021-01-12T17:33:31.135Z] 17:33:31     INFO -  1610472811130	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - ping id: f711a31d-4a1b-4c10-9a41-d89154371eb7, options: {"usePingSender":true}
[task 2021-01-12T17:33:31.135Z] 17:33:31     INFO -  1610472811130	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet.
[task 2021-01-12T17:33:31.135Z] 17:33:31     INFO -  1610472811130	Toolkit.Telemetry	TRACE	TelemetryPrioPing::Shutting down.
[task 2021-01-12T17:33:31.135Z] 17:33:31     INFO -  1610472811131	Toolkit.Telemetry	TRACE	TelemetryPrioPing::_submitPing
[task 2021-01-12T17:33:31.136Z] 17:33:31     INFO -  1610472811131	Toolkit.Telemetry	TRACE	TelemetryPrioPing::nothing to send
[task 2021-01-12T17:33:31.136Z] 17:33:31     INFO -  1610472811131	Toolkit.Telemetry	TRACE	TelemetryReportingPolicy::shutdown
[task 2021-01-12T17:33:31.136Z] 17:33:31     INFO -  1610472811131	Toolkit.Telemetry	TRACE	TelemetryEnvironment::shutdown
[task 2021-01-12T17:33:31.137Z] 17:33:31     INFO -  1610472811131	Toolkit.Telemetry	TRACE	TelemetrySend::Scheduler::shutdown
[task 2021-01-12T17:33:31.138Z] 17:33:31     INFO -  1610472811131	Toolkit.Telemetry	TRACE	TelemetrySend::promisePendingPingActivity - Waiting for ping task
[task 2021-01-12T17:33:31.138Z] 17:33:31     INFO -  1610472811133	Toolkit.Telemetry	TRACE	TelemetryHealthPing::::shutdown()
[task 2021-01-12T17:33:31.139Z] 17:33:31     INFO -  1610472811133	Toolkit.Telemetry	TRACE	TelemetrySession::shutdownChromeProcess
[task 2021-01-12T17:33:31.139Z] 17:33:31     INFO -  1610472811133	Toolkit.Telemetry	TRACE	TelemetryEnvironment::unregisterChangeListener for TelemetrySession::onEnvironmentChange
[task 2021-01-12T17:33:31.139Z] 17:33:31     INFO -  1610472811133	Toolkit.Telemetry	WARN	TelemetryEnvironment::registerChangeListener - already shutdown
[task 2021-01-12T17:33:31.139Z] 17:33:31     INFO -  1610472811133	Toolkit.Telemetry	TRACE	TelemetryScheduler::shutdown
[task 2021-01-12T17:33:31.139Z] 17:33:31     INFO -  1610472811133	Toolkit.Telemetry	TRACE	TelemetrySession::saveShutdownPings
[task 2021-01-12T17:33:31.139Z] 17:33:31     INFO -  1610472811133	Toolkit.Telemetry	TRACE	TelemetrySession::getSessionPayload - reason: shutdown, clearSubsession: false
[task 2021-01-12T17:33:31.139Z] 17:33:31     INFO -  1610472811134	Toolkit.Telemetry	TRACE	TelemetrySession::assemblePayloadWithMeasurements - reason: shutdown, submitting subsession data: true
[task 2021-01-12T17:33:31.146Z] 17:33:31     INFO -  1610472811139	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - type: main, aOptions: {"addClientId":true,"addEnvironment":true,"usePingSender":false}
[task 2021-01-12T17:33:31.146Z] 17:33:31     INFO -  1610472811139	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type main, aOptions {"addClientId":true,"addEnvironment":true,"usePingSender":false}
[task 2021-01-12T17:33:31.147Z] 17:33:31     INFO -  1610472811143	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - ping assembled, id: 6794c858-d047-41ca-b383-235f011a4c1d
[task 2021-01-12T17:33:31.147Z] 17:33:31     INFO -  1610472811143	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - ping id: 6794c858-d047-41ca-b383-235f011a4c1d, options: {"usePingSender":false}
[task 2021-01-12T17:33:31.148Z] 17:33:31     INFO -  1610472811143	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet.
[task 2021-01-12T17:33:31.148Z] 17:33:31     INFO -  1610472811143	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet.
[task 2021-01-12T17:33:31.148Z] 17:33:31     INFO -  1610472811143	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - can't send ping now, persisting to disk - canSendNow: false
[task 2021-01-12T17:33:31.148Z] 17:33:31     INFO -  1610472811143	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - type: first-shutdown, aOptions: {"addClientId":true,"addEnvironment":true,"usePingSender":true}
[task 2021-01-12T17:33:31.148Z] 17:33:31     INFO -  1610472811143	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type first-shutdown, aOptions {"addClientId":true,"addEnvironment":true,"usePingSender":true}
[task 2021-01-12T17:33:31.151Z] 17:33:31     INFO -  1610472811147	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - ping assembled, id: bae6607b-5268-4014-a248-1dea375220a0
[task 2021-01-12T17:33:31.151Z] 17:33:31     INFO -  1610472811147	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - ping id: bae6607b-5268-4014-a248-1dea375220a0, options: {"usePingSender":true}
[task 2021-01-12T17:33:31.151Z] 17:33:31     INFO -  1610472811147	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet.
[task 2021-01-12T17:33:31.151Z] 17:33:31     INFO -  1610472811148	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: Z:\task_1610470369\build\tmptovsco.mozrunner\datareporting\archived\2021-01\1610472811129.f711a31d-4a1b-4c10-9a41-d89154371eb7.event.jsonlz4
[task 2021-01-12T17:33:31.151Z] 17:33:31     INFO -  1610472811149	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: Z:\task_1610470369\build\tmptovsco.mozrunner\saved-telemetry-pings\f711a31d-4a1b-4c10-9a41-d89154371eb7
[task 2021-01-12T17:33:31.158Z] 17:33:31     INFO -  1610472811151	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: Z:\task_1610470369\build\tmptovsco.mozrunner\datareporting\archived\2021-01\1610472811142.6794c858-d047-41ca-b383-235f011a4c1d.main.jsonlz4
[task 2021-01-12T17:33:31.158Z] 17:33:31     INFO -  1610472811153	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: Z:\task_1610470369\build\tmptovsco.mozrunner\saved-telemetry-pings\6794c858-d047-41ca-b383-235f011a4c1d
[task 2021-01-12T17:33:31.158Z] 17:33:31     INFO -  1610472811155	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: Z:\task_1610470369\build\tmptovsco.mozrunner\datareporting\archived\2021-01\1610472811147.bae6607b-5268-4014-a248-1dea375220a0.first-shutdown.jsonlz4
[task 2021-01-12T17:33:31.165Z] 17:33:31     INFO -  1610472811158	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: Z:\task_1610470369\build\tmptovsco.mozrunner\saved-telemetry-pings\bae6607b-5268-4014-a248-1dea375220a0
[task 2021-01-12T17:33:31.180Z] 17:33:31     INFO -  1610472811171	Toolkit.Telemetry	TRACE	TelemetryStorage::savePendingPing - saved ping with id f711a31d-4a1b-4c10-9a41-d89154371eb7
[task 2021-01-12T17:33:31.180Z] 17:33:31     INFO -  1610472811171	Toolkit.Telemetry	TRACE	TelemetrySend::_sendWithPingSender - sending f711a31d-4a1b-4c10-9a41-d89154371eb7 to http://localhost:8000/pings/submit/telemetry/f711a31d-4a1b-4c10-9a41-d89154371eb7/event/Firefox/86.0a1/default/20210112170249?v=4
[task 2021-01-12T17:33:31.180Z] 17:33:31     INFO -  1610472811171	Toolkit.Telemetry	TRACE	TelemetrySend::_sendWithPingSender - too late to send. Batching.
[task 2021-01-12T17:33:31.195Z] 17:33:31     INFO -  1610472811184	Toolkit.Telemetry	TRACE	TelemetryStorage::savePendingPing - saved ping with id 6794c858-d047-41ca-b383-235f011a4c1d
[task 2021-01-12T17:33:31.202Z] 17:33:31     INFO -  1610472811195	Toolkit.Telemetry	TRACE	TelemetryStorage::savePendingPing - saved ping with id bae6607b-5268-4014-a248-1dea375220a0
[task 2021-01-12T17:33:31.202Z] 17:33:31     INFO -  1610472811195	Toolkit.Telemetry	TRACE	TelemetrySend::_sendWithPingSender - sending bae6607b-5268-4014-a248-1dea375220a0 to http://localhost:8000/pings/submit/telemetry/bae6607b-5268-4014-a248-1dea375220a0/first-shutdown/Firefox/86.0a1/default/20210112170249?v=4
[task 2021-01-12T17:33:31.202Z] 17:33:31     INFO -  1610472811195	Toolkit.Telemetry	TRACE	TelemetrySend::_sendWithPingSender - too late to send. Batching.
[task 2021-01-12T17:33:31.202Z] 17:33:31     INFO -  1610472811196	Toolkit.Telemetry	TRACE	TelemetryStorage::_popAndPerformQueuedOperation - Performing queued operation.
[task 2021-01-12T17:33:31.202Z] 17:33:31     INFO -  1610472811197	Toolkit.Telemetry	TRACE	TelemetryStorage::removeAbortedSessionPing - success
[task 2021-01-12T17:33:31.202Z] 17:33:31     INFO -  1610472811198	Toolkit.Telemetry	TRACE	TelemetrySend::flushPingSenderBatch - Sending 3 pings.
[task 2021-01-12T17:33:31.203Z] 17:33:31     INFO -  1610472811199	Toolkit.Telemetry	TRACE	TelemetryStorage::_popAndPerformQueuedOperation - Performing queued operation.
[task 2021-01-12T17:33:31.206Z] 17:33:31     INFO -  1610472811200	Marionette	TRACE	Received observer notification xpcom-will-shutdown
[task 2021-01-12T17:33:31.206Z] 17:33:31     INFO -  1610472811200	Marionette	DEBUG	Marionette stopped listening
[task 2021-01-12T17:33:32.747Z] 17:33:32     INFO - pingserver pings_handler received 'first-shutdown' ping
[task 2021-01-12T17:33:32.764Z] 17:33:32     INFO - pingserver pings_handler received 'main' ping with reason 'shutdown'
[task 2021-01-12T17:33:32.764Z] 17:33:32     INFO - pingserver pings_handler received 'event' ping
[task 2021-01-12T17:33:32.764Z] 17:33:32     INFO - pingserver pings_handler received 'new-profile' ping
[task 2021-01-12T17:33:32.819Z] 17:33:32     INFO - wait_for_pings running action 'install_addon'.
[task 2021-01-12T17:33:32.955Z] 17:33:32     INFO - pingserver pings_handler received 'main' ping with reason 'environment-change'
[task 2021-01-12T17:33:33.513Z] 17:33:33     INFO - pingserver pings_handler received 'new-profile' ping
[task 2021-01-12T17:33:35.049Z] 17:33:35     INFO - wait_for_pings running action 'restart_browser'.
[task 2021-01-12T17:36:45.470Z] 17:36:45     INFO - mozcrash Copy/paste: Z:/task_1610470369/fetches\minidump_stackwalk\minidump_stackwalk.exe Z:\task_1610470369\build\tmptovsco.mozrunner\minidumps\c406b3ab-e9e1-4d69-bce1-0a6b5e08738e.dmp c:\users\task_1610470369\appdata\local\temp\tmp6rmywi
[task 2021-01-12T17:36:51.908Z] 17:36:51     INFO - mozcrash Saved minidump as Z:\task_1610470369\build\blobber_upload_dir\c406b3ab-e9e1-4d69-bce1-0a6b5e08738e.dmp
[task 2021-01-12T17:36:51.908Z] 17:36:51     INFO - mozcrash Saved app info as Z:\task_1610470369\build\blobber_upload_dir\c406b3ab-e9e1-4d69-bce1-0a6b5e08738e.extra
[task 2021-01-12T17:36:51.985Z] 17:36:51     INFO - PROCESS-CRASH | telemetry/marionette/tests/client/test_search_counts_across_sessions.py TestSearchCounts.test_search_counts | application crashed [@ Internal_AllowTestSign + 0xf6]
[task 2021-01-12T17:36:51.985Z] 17:36:51     INFO - Crash dump filename: Z:\task_1610470369\build\tmptovsco.mozrunner\minidumps\c406b3ab-e9e1-4d69-bce1-0a6b5e08738e.dmp
[task 2021-01-12T17:36:51.985Z] 17:36:51     INFO - Operating system: Windows NT
[task 2021-01-12T17:36:51.985Z] 17:36:51     INFO -                   6.1.7601 Service Pack 1
[task 2021-01-12T17:36:51.985Z] 17:36:51     INFO - CPU: x86
[task 2021-01-12T17:36:51.985Z] 17:36:51     INFO -      GenuineIntel family 6 model 63 stepping 2
[task 2021-01-12T17:36:51.985Z] 17:36:51     INFO -      8 CPUs
[task 2021-01-12T17:36:51.985Z] 17:36:51     INFO - 
[task 2021-01-12T17:36:51.985Z] 17:36:51     INFO - GPU: UNKNOWN
[task 2021-01-12T17:36:51.985Z] 17:36:51     INFO - 
[task 2021-01-12T17:36:51.985Z] 17:36:51     INFO - Crash reason:  0xc000000d / 0x00000000
[task 2021-01-12T17:36:51.985Z] 17:36:51     INFO - Crash address: 0x0
[task 2021-01-12T17:36:51.985Z] 17:36:51     INFO - Assertion: Invalid parameter passed to library function (null) in function (null), in file (null)
[task 2021-01-12T17:36:51.986Z] 17:36:51     INFO - Process uptime: 4 seconds
[task 2021-01-12T17:36:51.986Z] 17:36:51     INFO - 
[task 2021-01-12T17:36:51.986Z] 17:36:51     INFO - Thread 31 (crashed)
[task 2021-01-12T17:36:51.986Z] 17:36:51     INFO -  0  ucrtbase.dll!Internal_AllowTestSign + 0xf6
[task 2021-01-12T17:36:51.986Z] 17:36:51     INFO -     eip = 0x6b810d6b   esp = 0x0ce2f78c   ebp = 0x0ce2f7b4   ebx = 0x0ce2f198
[task 2021-01-12T17:36:51.986Z] 17:36:51     INFO -     esi = 0x00b60040   edi = 0x0ce2f4a0   eax = 0x0ce2f140   ecx = 0x00000000
[task 2021-01-12T17:36:51.986Z] 17:36:51     INFO -     edx = 0x0ce2f4a0   efl = 0x00000216
[task 2021-01-12T17:36:51.986Z] 17:36:51     INFO -     Found by: given as instruction pointer in context
[task 2021-01-12T17:36:51.986Z] 17:36:51     INFO -  1  ucrtbase.dll!Internal_AllowTestSign + 0x126
[task 2021-01-12T17:36:51.986Z] 17:36:51     INFO -     eip = 0x6b810d9b   esp = 0x0ce2f7bc   ebp = 0x0ce2f818   ebx = 0x00000000
[task 2021-01-12T17:36:51.986Z] 17:36:51     INFO -     Found by: call frame info
[task 2021-01-12T17:36:51.986Z] 17:36:51     INFO -  2  xul.dll + 0x5c359
[task 2021-01-12T17:36:51.986Z] 17:36:51     INFO -     eip = 0x57dec359   esp = 0x0ce2f820   ebp = 0x0ce2f83c   ebx = 0x00000000
[task 2021-01-12T17:36:51.986Z] 17:36:51     INFO -     Found by: call frame info
[task 2021-01-12T17:36:51.986Z] 17:36:51     INFO -  3  xul.dll + 0x5c3d1
[task 2021-01-12T17:36:51.986Z] 17:36:51     INFO -     eip = 0x57dec3d1   esp = 0x0ce2f844   ebp = 0x0ce2f854
[task 2021-01-12T17:36:51.987Z] 17:36:51     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:36:51.987Z] 17:36:51     INFO -  4  xul.dll + 0x5d7370
[task 2021-01-12T17:36:51.987Z] 17:36:51     INFO -     eip = 0x58367370   esp = 0x0ce2f85c   ebp = 0x0ce2f864
[task 2021-01-12T17:36:51.987Z] 17:36:51     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:36:51.987Z] 17:36:51     INFO -  5  xul.dll + 0x718b27
[task 2021-01-12T17:36:51.987Z] 17:36:51     INFO -     eip = 0x584a8b27   esp = 0x0ce2f86c   ebp = 0x0ce2f9ec
[task 2021-01-12T17:36:51.987Z] 17:36:51     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:36:51.987Z] 17:36:51     INFO -  6  xul.dll + 0x65e1b6
[task 2021-01-12T17:36:51.987Z] 17:36:51     INFO -     eip = 0x583ee1b6   esp = 0x0ce2f9f4   ebp = 0x0ce2fa80
[task 2021-01-12T17:36:51.987Z] 17:36:51     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:36:51.987Z] 17:36:51     INFO -  7  xul.dll + 0x5d4065
[task 2021-01-12T17:36:51.987Z] 17:36:51     INFO -     eip = 0x58364065   esp = 0x0ce2fa88   ebp = 0x0ce2faa4
[task 2021-01-12T17:36:51.987Z] 17:36:51     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:36:51.987Z] 17:36:51     INFO -  8  xul.dll + 0x5d330b
[task 2021-01-12T17:36:51.987Z] 17:36:51     INFO -     eip = 0x5836330b   esp = 0x0ce2faac   ebp = 0x0ce2fb1c
[task 2021-01-12T17:36:51.987Z] 17:36:51     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:36:51.987Z] 17:36:51     INFO -  9  xul.dll + 0x5d3953
[task 2021-01-12T17:36:51.988Z] 17:36:51     INFO -     eip = 0x58363953   esp = 0x0ce2fb24   ebp = 0x0ce2fb48
[task 2021-01-12T17:36:51.988Z] 17:36:51     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:36:51.988Z] 17:36:51     INFO - 10  xul.dll + 0x5d3a85
[task 2021-01-12T17:36:51.988Z] 17:36:51     INFO -     eip = 0x58363a85   esp = 0x0ce2fb50   ebp = 0x0ce2fb5c
[task 2021-01-12T17:36:51.988Z] 17:36:51     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:36:51.988Z] 17:36:51     INFO - 11  xul.dll + 0xe5f90
[task 2021-01-12T17:36:51.988Z] 17:36:51     INFO -     eip = 0x57e75f90   esp = 0x0ce2fb64   ebp = 0x0ce2fc24
[task 2021-01-12T17:36:51.988Z] 17:36:51     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:36:51.988Z] 17:36:51     INFO - 12  xul.dll + 0xe9c0f
[task 2021-01-12T17:36:51.988Z] 17:36:51     INFO -     eip = 0x57e79c0f   esp = 0x0ce2fc2c   ebp = 0x0ce2fc48
[task 2021-01-12T17:36:51.988Z] 17:36:51     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:36:51.988Z] 17:36:51     INFO - 13  xul.dll + 0x5d61c1
[task 2021-01-12T17:36:51.988Z] 17:36:51     INFO -     eip = 0x583661c1   esp = 0x0ce2fc50   ebp = 0x0ce2fc78
[task 2021-01-12T17:36:51.988Z] 17:36:51     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:36:51.988Z] 17:36:51     INFO - 14  xul.dll + 0x5a63f9
[task 2021-01-12T17:36:51.988Z] 17:36:51     INFO -     eip = 0x583363f9   esp = 0x0ce2fc80   ebp = 0x0ce2fcb0
[task 2021-01-12T17:36:51.989Z] 17:36:51     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:36:51.989Z] 17:36:51     INFO - 15  xul.dll + 0x5a6356
[task 2021-01-12T17:36:51.989Z] 17:36:51     INFO -     eip = 0x58336356   esp = 0x0ce2fcb8   ebp = 0x0ce2fcd0
[task 2021-01-12T17:36:51.989Z] 17:36:51     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:36:51.989Z] 17:36:51     INFO - 16  xul.dll + 0xe3ab5
[task 2021-01-12T17:36:51.989Z] 17:36:51     INFO -     eip = 0x57e73ab5   esp = 0x0ce2fcd8   ebp = 0x0ce2fdb4
[task 2021-01-12T17:36:51.989Z] 17:36:51     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:36:51.989Z] 17:36:51     INFO - 17  nss3.dll + 0x104fa4
[task 2021-01-12T17:36:51.989Z] 17:36:51     INFO -     eip = 0x6b054fa4   esp = 0x0ce2fdbc   ebp = 0x0ce2fddc
[task 2021-01-12T17:36:51.989Z] 17:36:51     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:36:51.989Z] 17:36:51     INFO - 18  nss3.dll + 0xf8896
[task 2021-01-12T17:36:51.989Z] 17:36:51     INFO -     eip = 0x6b048896   esp = 0x0ce2fde4   ebp = 0x0ce2fdec
[task 2021-01-12T17:36:51.989Z] 17:36:51     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:36:51.989Z] 17:36:51     INFO - 19  ucrtbase.dll!GetPrivateProfileStringA + 0x8e
[task 2021-01-12T17:36:51.989Z] 17:36:51     INFO -     eip = 0x6b7ae16f   esp = 0x0ce2fdf4   ebp = 0x0ce2fe28
[task 2021-01-12T17:36:51.989Z] 17:36:51     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:36:51.990Z] 17:36:51     INFO - 20  kernel32.dll!BaseThreadInitThunk + 0x12
[task 2021-01-12T17:36:51.990Z] 17:36:51     INFO -     eip = 0x756eef3c   esp = 0x0ce2fe30   ebp = 0x0ce2fe34
[task 2021-01-12T17:36:51.990Z] 17:36:51     INFO -     Found by: call frame info
[task 2021-01-12T17:36:51.990Z] 17:36:51     INFO - 21  ntdll.dll!BaseCheckVDMp + 0x8ff
[task 2021-01-12T17:36:51.990Z] 17:36:51     INFO -     eip = 0x77033618   esp = 0x0ce2fe3c   ebp = 0x0ce2fe74
[task 2021-01-12T17:36:51.990Z] 17:36:51     INFO -     Found by: call frame info
[task 2021-01-12T17:36:51.990Z] 17:36:51     INFO - 22  ntdll.dll!BaseCheckVDMp + 0x8d2
[task 2021-01-12T17:36:51.990Z] 17:36:51     INFO -     eip = 0x770335eb   esp = 0x0ce2fe7c   ebp = 0x0ce2fe8c
[task 2021-01-12T17:36:51.990Z] 17:36:51     INFO -     Found by: call frame info```

5 months without a notice.

Status: NEW → RESOLVED
Closed: 5 years ago
Resolution: --- → INACTIVE
You need to log in before you can comment on or make changes to this bug.