Closed Bug 1686292 Opened 3 years ago Closed 3 years ago

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

Categories

(Toolkit :: Telemetry, defect)

Product:
Toolkit
Component:
Telemetry
Type:
defect

Tracking

()

Status:
RESOLVED DUPLICATE of bug 1686387

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=326478964&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/KZ7vxnxtSoyri2BcSLLGxA/runs/0/artifacts/public/logs/live_backing.log

[task 2021-01-12T17:55:05.673Z] 17:55:05     INFO - TEST-START | telemetry/marionette/tests/client/test_search_counts_across_sessions.py TestSearchCounts.test_search_counts
[task 2021-01-12T17:55:05.674Z] 17:55:05     INFO - Application command: Z:\task_1610473700\build\application\firefox\firefox.exe -no-remote -marionette --wait-for-browser -profile Z:\task_1610473700\build\tmpcibe1s.mozrunner
[task 2021-01-12T17:55:06.181Z] 17:55:06     INFO -  1610474106176	Toolkit.Telemetry	TRACE	TelemetryController::observe - profile-after-change notified.
[task 2021-01-12T17:55:06.181Z] 17:55:06     INFO -  1610474106177	Toolkit.Telemetry	TRACE	TelemetryController::setupTelemetry
[task 2021-01-12T17:55:06.181Z] 17:55:06     INFO -  1610474106178	Toolkit.Telemetry	TRACE	TelemetryReportingPolicy::setup
[task 2021-01-12T17:55:06.181Z] 17:55:06     INFO -  1610474106178	Toolkit.Telemetry	CONFIG	TelemetryController::enableTelemetryRecording - canRecordBase:true, canRecordExtended: false
[task 2021-01-12T17:55:06.181Z] 17:55:06     INFO -  1610474106178	Toolkit.Telemetry	TRACE	TelemetrySession::earlyInit
[task 2021-01-12T17:55:06.188Z] 17:55:06     INFO -  1610474106184	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet.
[task 2021-01-12T17:55:06.188Z] 17:55:06     INFO -  1610474106185	Toolkit.Telemetry	TRACE	UpdatePing::init - enabled: true
[task 2021-01-12T17:55:06.195Z] 17:55:06     INFO -  1610474106190	Toolkit.Telemetry	TRACE	TelemetryEnvironment::constructor
[task 2021-01-12T17:55:06.210Z] 17:55:06     INFO -  1610474106203	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_getGFXData - Only one display adapter detected.
[task 2021-01-12T17:55:06.210Z] 17:55:06     INFO -  1610474106206	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_updateSearchEngine - ignoring early call
[task 2021-01-12T17:55:06.210Z] 17:55:06     INFO -  1610474106206	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_updateAddons
[task 2021-01-12T17:55:06.210Z] 17:55:06     INFO -  1610474106210	Toolkit.Telemetry	TRACE	TelemetryEnvironment::registerChangeListener for CrashAnnotator
[task 2021-01-12T17:55:06.230Z] 17:55:06     INFO -  1610474106222	Marionette	TRACE	Marionette enabled
[task 2021-01-12T17:55:06.309Z] 17:55:06     INFO -  1610474106302	Marionette	TRACE	Received observer notification toplevel-window-ready
[task 2021-01-12T17:55:06.324Z] 17:55:06     INFO -  1610474106319	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_updateAddons: addons differ
[task 2021-01-12T17:55:06.559Z] 17:55:06     INFO -  1610474106552	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: auto-update-config-change, aData: false
[task 2021-01-12T17:55:06.780Z] 17:55:06     INFO -  1610474106778	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: compositor:created, aData: null
[task 2021-01-12T17:55:06.787Z] 17:55:06     INFO -  1610474106782	Toolkit.Telemetry	TRACE	TelemetryController::observe - app-startup notified.
[task 2021-01-12T17:55:06.787Z] 17:55:06     INFO -  1610474106784	Toolkit.Telemetry	CONFIG	TelemetryController::enableTelemetryRecording - canRecordBase:true, canRecordExtended: false
[task 2021-01-12T17:55:06.868Z] 17:55:06     INFO -  1610474106867	Toolkit.Telemetry	TRACE	TelemetrySession::observe - user-interaction-active notified.
[task 2021-01-12T17:55:06.888Z] 17:55:06     INFO -  1610474106882	Toolkit.Telemetry	TRACE	TelemetryController::observe - app-startup notified.
[task 2021-01-12T17:55:06.888Z] 17:55:06     INFO -  1610474106884	Toolkit.Telemetry	CONFIG	TelemetryController::enableTelemetryRecording - canRecordBase:true, canRecordExtended: false
[task 2021-01-12T17:55:06.903Z] 17:55:06     INFO -  1610474106895	Toolkit.Telemetry	TRACE	TelemetrySession::observe - xul-window-visible notified.
[task 2021-01-12T17:55:07.062Z] 17:55:07     INFO -  console.warn: SearchSettings: "get: No settings file exists, new profile?" (new Error("", "(unknown module)"))
[task 2021-01-12T17:55:07.103Z] 17:55:07     INFO -  1610474107102	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: sessionstore-windows-restored, aData: null
[task 2021-01-12T17:55:07.103Z] 17:55:07     INFO -  1610474107103	Toolkit.Telemetry	TRACE	TelemetrySession::observe - sessionstore-windows-restored notified.
[task 2021-01-12T17:55:07.106Z] 17:55:07     INFO -  1610474107103	Toolkit.Telemetry	TRACE	TelemetrySession::gatherStartup
[task 2021-01-12T17:55:07.106Z] 17:55:07     INFO -  1610474107104	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet.
[task 2021-01-12T17:55:07.106Z] 17:55:07     INFO -  1610474107104	Toolkit.Telemetry	TRACE	TelemetryReportingPolicy::_shouldNotify - User already notified or bypassing the policy.
[task 2021-01-12T17:55:07.201Z] 17:55:07     INFO -  1610474107199	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: browser-search-service, aData: settings-update-complete
[task 2021-01-12T17:55:07.608Z] 17:55:07     INFO -  1610474107604	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_startWatchingPrefs - [object Map]
[task 2021-01-12T17:55:07.628Z] 17:55:07     INFO -  1610474107622	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: extensions.webextensions.uuids
[task 2021-01-12T17:55:07.643Z] 17:55:07     INFO -  1610474107638	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: extensions.webextensions.uuids
[task 2021-01-12T17:55:07.658Z] 17:55:07     INFO -  1610474107651	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: browser-search-service, aData: init-complete
[task 2021-01-12T17:55:07.658Z] 17:55:07     INFO -  1610474107651	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_updateSearchEngine - isInitialized: true
[task 2021-01-12T17:55:07.658Z] 17:55:07     INFO -  1610474107653	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.newtabpage.storageVersion
[task 2021-01-12T17:55:07.658Z] 17:55:07     INFO -  1610474107654	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.urlbar.placeholderName
[task 2021-01-12T17:55:07.677Z] 17:55:07     INFO -  1610474107674	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: network.trr.blocklist_cleanup_done
[task 2021-01-12T17:55:07.678Z] 17:55:07     INFO -  1610474107674	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: app.update.lastUpdateTime.region-update-timer
[task 2021-01-12T17:55:07.697Z] 17:55:07     INFO -  1610474107694	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: distribution-customization-complete, aData: null
[task 2021-01-12T17:55:07.698Z] 17:55:07     INFO -  1610474107694	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.bookmarks.restore_default_bookmarks
[task 2021-01-12T17:55:07.798Z] 17:55:07     INFO -  1610474107795	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.migrationVersion
[task 2021-01-12T17:55:07.798Z] 17:55:07     INFO -  1610474107796	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.cursorToolOnLoad
[task 2021-01-12T17:55:07.798Z] 17:55:07     INFO -  1610474107796	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.defaultZoomValue
[task 2021-01-12T17:55:07.798Z] 17:55:07     INFO -  1610474107796	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.disablePageLabels
[task 2021-01-12T17:55:07.798Z] 17:55:07     INFO -  1610474107796	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.enablePermissions
[task 2021-01-12T17:55:07.798Z] 17:55:07     INFO -  1610474107796	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.enablePrintAutoRotate
[task 2021-01-12T17:55:07.798Z] 17:55:07     INFO -  1610474107797	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.enableScripting
[task 2021-01-12T17:55:07.805Z] 17:55:07     INFO -  1610474107797	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.enableWebGL
[task 2021-01-12T17:55:07.805Z] 17:55:07     INFO -  1610474107797	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.externalLinkTarget
[task 2021-01-12T17:55:07.805Z] 17:55:07     INFO -  1610474107797	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.historyUpdateUrl
[task 2021-01-12T17:55:07.805Z] 17:55:07     INFO -  1610474107797	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.ignoreDestinationZoom
[task 2021-01-12T17:55:07.805Z] 17:55:07     INFO -  1610474107797	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.pdfBugEnabled
[task 2021-01-12T17:55:07.805Z] 17:55:07     INFO -  1610474107798	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.renderer
[task 2021-01-12T17:55:07.805Z] 17:55:07     INFO -  1610474107798	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.sidebarViewOnLoad
[task 2021-01-12T17:55:07.806Z] 17:55:07     INFO -  1610474107798	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.scrollModeOnLoad
[task 2021-01-12T17:55:07.806Z] 17:55:07     INFO -  1610474107799	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.spreadModeOnLoad
[task 2021-01-12T17:55:07.806Z] 17:55:07     INFO -  1610474107799	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.textLayerMode
[task 2021-01-12T17:55:07.806Z] 17:55:07     INFO -  1610474107799	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.useOnlyCssZoom
[task 2021-01-12T17:55:07.806Z] 17:55:07     INFO -  1610474107799	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.viewerCssTheme
[task 2021-01-12T17:55:07.806Z] 17:55:07     INFO -  1610474107799	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.viewOnLoad
[task 2021-01-12T17:55:07.806Z] 17:55:07     INFO -  1610474107799	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.disableAutoFetch
[task 2021-01-12T17:55:07.806Z] 17:55:07     INFO -  1610474107799	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.disableFontFace
[task 2021-01-12T17:55:07.806Z] 17:55:07     INFO -  1610474107800	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.disableRange
[task 2021-01-12T17:55:07.807Z] 17:55:07     INFO -  1610474107800	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: pdfjs.disableStream
[task 2021-01-12T17:55:07.807Z] 17:55:07     INFO -  1610474107801	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.download.viewableInternally.typeWasRegistered.xml
[task 2021-01-12T17:55:07.807Z] 17:55:07     INFO -  1610474107802	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.download.viewableInternally.typeWasRegistered.svg
[task 2021-01-12T17:55:07.807Z] 17:55:07     INFO -  1610474107802	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.download.viewableInternally.typeWasRegistered.webp
[task 2021-01-12T17:55:07.807Z] 17:55:07     INFO -  1610474107803	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.download.viewableInternally.typeWasRegistered.avif
[task 2021-01-12T17:55:07.822Z] 17:55:07     INFO -  1610474107816	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.uiCustomization.state
[task 2021-01-12T17:55:07.822Z] 17:55:07     INFO -  1610474107817	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.bookmarks.addedImportButton
[task 2021-01-12T17:55:07.861Z] 17:55:07     INFO -  1610474107856	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_onEnvironmentChange for system-info
[task 2021-01-12T17:55:07.861Z] 17:55:07     INFO -  1610474107857	Toolkit.Telemetry	DEBUG	TelemetryEnvironment::_onEnvironmentChange - calling CrashAnnotator
[task 2021-01-12T17:55:07.861Z] 17:55:07     INFO -  1610474107858	Toolkit.Telemetry	TRACE	ClientID::_doLoadClientIDs
[task 2021-01-12T17:55:07.864Z] 17:55:07     INFO -  1610474107860	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: toolkit.telemetry.cachedClientID
[task 2021-01-12T17:55:07.864Z] 17:55:07     INFO -  1610474107860	Toolkit.Telemetry	TRACE	ClientID::_saveClientIDs
[task 2021-01-12T17:55:07.879Z] 17:55:07     INFO -  1610474107870	Toolkit.Telemetry	TRACE	ClientID::_doLoadClientIDs: New client IDs loaded and persisted.
[task 2021-01-12T17:55:07.879Z] 17:55:07     INFO -  1610474107870	Toolkit.Telemetry	TRACE	TelemetrySend::setup
[task 2021-01-12T17:55:07.879Z] 17:55:07     INFO -  1610474107871	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet.
[task 2021-01-12T17:55:07.879Z] 17:55:07     INFO -  1610474107875	Toolkit.Telemetry	TRACE	TelemetryStorage::_scanPendingPings
[task 2021-01-12T17:55:07.879Z] 17:55:07     INFO -  1610474107875	Toolkit.Telemetry	TRACE	TelemetryStorage::_migrateAppDataPings
[task 2021-01-12T17:55:07.879Z] 17:55:07     INFO -  1610474107875	Toolkit.Telemetry	TRACE	TelemetryStorage::_iterateAppDataPings
[task 2021-01-12T17:55:07.894Z] 17:55:07     INFO -  1610474107885	Toolkit.Telemetry	INFO	TelemetrySend::_checkPendingPings - pending ping count: 0
[task 2021-01-12T17:55:07.894Z] 17:55:07     INFO -  1610474107885	Toolkit.Telemetry	TRACE	TelemetrySend::_checkPendingPings - no pending pings
[task 2021-01-12T17:55:07.894Z] 17:55:07     INFO -  1610474107885	Toolkit.Telemetry	TRACE	TelemetryStorage::_enforcePendingPingsQuota
[task 2021-01-12T17:55:07.894Z] 17:55:07     INFO -  1610474107885	Toolkit.Telemetry	TRACE	TelemetrySend::Scheduler::triggerSendingPings - active send task: false, immediately: true
[task 2021-01-12T17:55:07.894Z] 17:55:07     INFO -  1610474107885	Toolkit.Telemetry	TRACE	TelemetrySend::Scheduler::_doSendTask iteration
[task 2021-01-12T17:55:07.895Z] 17:55:07     INFO -  1610474107886	Toolkit.Telemetry	TRACE	TelemetrySend::Scheduler::_doSendTask - pending: 0, current: 0
[task 2021-01-12T17:55:07.895Z] 17:55:07     INFO -  1610474107886	Toolkit.Telemetry	TRACE	TelemetrySend::Scheduler::_doSendTask - can send - pending: 0, current: 0
[task 2021-01-12T17:55:07.895Z] 17:55:07     INFO -  1610474107886	Toolkit.Telemetry	TRACE	TelemetrySend::Scheduler::_doSendTask - no pending pings, bailing out
[task 2021-01-12T17:55:07.895Z] 17:55:07     INFO -  1610474107886	Toolkit.Telemetry	TRACE	TelemetrySession::delayedInit
[task 2021-01-12T17:55:07.895Z] 17:55:07     INFO -  1610474107886	Toolkit.Telemetry	TRACE	TelemetryStorage::_popAndPerformQueuedOperation - Performing queued operation.
[task 2021-01-12T17:55:07.895Z] 17:55:07     INFO -  1610474107887	Toolkit.Telemetry	INFO	TelemetryStorage::_loadSessionData - can not load session data file: {"operation":"open","path":"Z:\\task_1610473700\\build\\tmpcibe1s.mozrunner\\datareporting\\session-state.json","winLastError":2}
[task 2021-01-12T17:55:07.895Z] 17:55:07     INFO -  1610474107887	Toolkit.Telemetry	TRACE	TelemetryStorage::_popAndPerformQueuedOperation - Performing queued operation.
[task 2021-01-12T17:55:07.934Z] 17:55:07     INFO -  1610474107927	Toolkit.Telemetry	TRACE	TelemetryStorage::loadPingfile - unreadable ping Z:\task_1610473700\build\tmpcibe1s.mozrunner\datareporting\aborted-session-ping: {"operation":"open","path":"Z:\\task_1610473700\\build\\tmpcibe1s.mozrunner\\datareporting\\aborted-session-ping","winLastError":2}
[task 2021-01-12T17:55:07.934Z] 17:55:07     INFO -  1610474107927	Toolkit.Telemetry	TRACE	TelemetryStorage::loadAbortedSessionPing - no such file
[task 2021-01-12T17:55:07.934Z] 17:55:07     INFO -  1610474107927	Toolkit.Telemetry	TRACE	TelemetryController::checkAbortedSessionPing - found aborted-session ping: false
[task 2021-01-12T17:55:07.935Z] 17:55:07     INFO -  1610474107927	Toolkit.Telemetry	TRACE	TelemetrySession::_saveAbortedSessionPing
[task 2021-01-12T17:55:07.935Z] 17:55:07     INFO -  1610474107927	Toolkit.Telemetry	TRACE	TelemetrySession::getSessionPayload - reason: aborted-session, clearSubsession: false
[task 2021-01-12T17:55:07.935Z] 17:55:07     INFO -  1610474107928	Toolkit.Telemetry	TRACE	TelemetrySession::assemblePayloadWithMeasurements - reason: aborted-session, submitting subsession data: true
[task 2021-01-12T17:55:07.935Z] 17:55:07     INFO -  1610474107930	Toolkit.Telemetry	TRACE	TelemetryController::saveAbortedSessionPing
[task 2021-01-12T17:55:07.935Z] 17:55:07     INFO -  1610474107930	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type main, aOptions {"addClientId":true,"addEnvironment":true}
[task 2021-01-12T17:55:07.936Z] 17:55:07     INFO -  1610474107932	Toolkit.Telemetry	TRACE	TelemetryStorage::saveAbortedSessionPing - ping path: Z:\task_1610473700\build\tmpcibe1s.mozrunner\datareporting\aborted-session-ping
[task 2021-01-12T17:55:07.938Z] 17:55:07     INFO -  1610474107935	Toolkit.Telemetry	TRACE	TelemetryStorage::_popAndPerformQueuedOperation - Performing queued operation.
[task 2021-01-12T17:55:07.938Z] 17:55:07     INFO -  1610474107935	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: Z:\task_1610473700\build\tmpcibe1s.mozrunner\datareporting\aborted-session-ping
[task 2021-01-12T17:55:07.941Z] 17:55:07     INFO -  1610474107938	Marionette	TRACE	Received observer notification marionette-startup-requested
[task 2021-01-12T17:55:07.941Z] 17:55:07     INFO -  1610474107938	Marionette	TRACE	Waiting until startup recorder finished recording startup scripts...
[task 2021-01-12T17:55:07.960Z] 17:55:07     INFO -  1610474107951	Toolkit.Telemetry	TRACE	TelemetryEnvironment::registerChangeListener for TelemetrySession::onEnvironmentChange
[task 2021-01-12T17:55:07.960Z] 17:55:07     INFO -  1610474107953	Toolkit.Telemetry	TRACE	TelemetryScheduler::init
[task 2021-01-12T17:55:07.960Z] 17:55:07     INFO -  1610474107953	Toolkit.Telemetry	TRACE	TelemetryScheduler::_rescheduleTimeout - isUserIdle: false
[task 2021-01-12T17:55:07.960Z] 17:55:07     INFO -  1610474107953	Toolkit.Telemetry	TRACE	TelemetryScheduler::_rescheduleTimeout - scheduling next tick for Tue Jan 12 2021 18:00:07 GMT+0000 (Greenwich Mean Time)
[task 2021-01-12T17:55:07.960Z] 17:55:07     INFO -  1610474107954	Toolkit.Telemetry	TRACE	TelemetryController::scheduleNewProfilePing
[task 2021-01-12T17:55:07.960Z] 17:55:07     INFO -  1610474107954	Toolkit.Telemetry	TRACE	TelemetryStorage::cleanArchiveTask
[task 2021-01-12T17:55:07.960Z] 17:55:07     INFO -  1610474107954	Toolkit.Telemetry	TRACE	TelemetryStorage::removeFHRDatabase
[task 2021-01-12T17:55:07.960Z] 17:55:07     INFO -  1610474107955	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: app.update.lastUpdateTime.telemetry_modules_ping
[task 2021-01-12T17:55:07.964Z] 17:55:07     INFO -  1610474107961	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: app.update.lastUpdateTime.telemetry_untrustedmodules_ping
[task 2021-01-12T17:55:07.967Z] 17:55:07     INFO -  1610474107965	Toolkit.Telemetry	TRACE	TelemetryEventPing::::Starting up.
[task 2021-01-12T17:55:07.967Z] 17:55:07     INFO -  1610474107965	Toolkit.Telemetry	TRACE	TelemetryPrioPing::Extended collection disabled. Prio ping disabled.
[task 2021-01-12T17:55:07.967Z] 17:55:07     INFO -  1610474107965	Toolkit.Telemetry	TRACE	TelemetryController::saveUninstallPing
[task 2021-01-12T17:55:07.968Z] 17:55:07     INFO -  1610474107966	Toolkit.Telemetry	INFO	TelemetryController::saveUninstallPing - otherInstalls: 0
[task 2021-01-12T17:55:07.968Z] 17:55:07     INFO -  1610474107966	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type uninstall, aOptions {"addClientId":true,"addEnvironment":true}
[task 2021-01-12T17:55:07.984Z] 17:55:07     INFO -  1610474107980	Toolkit.Telemetry	TRACE	TelemetryStorage::removeUninstallPings - removing: C:\ProgramData\Mozilla\uninstall_ping_18C8E6A2DFC4D9E4_7442f2fb-3a51-4865-861d-f6a31703ba64.json
[task 2021-01-12T17:55:07.986Z] 17:55:07     INFO -  1610474107983	Toolkit.Telemetry	TRACE	TelemetryStorage::removeUninstallPings - success
[task 2021-01-12T17:55:07.989Z] 17:55:07     INFO -  1610474107985	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: C:\ProgramData\Mozilla\uninstall_ping_18C8E6A2DFC4D9E4_2a20d032-4674-45ce-aad7-80cba7883f1a.json
[task 2021-01-12T17:55:08.044Z] 17:55:08     INFO -  1610474108038	Marionette	TRACE	All scripts recorded.
[task 2021-01-12T17:55:08.044Z] 17:55:08     INFO -  1610474108039	Marionette	INFO	Listening on port 2828
[task 2021-01-12T17:55:08.044Z] 17:55:08     INFO -  1610474108040	Marionette	DEBUG	Marionette is listening
[task 2021-01-12T17:55:08.051Z] 17:55:08     INFO -  1610474108047	Toolkit.Telemetry	TRACE	TelemetryController::observe - app-startup notified.
[task 2021-01-12T17:55:08.051Z] 17:55:08     INFO -  1610474108048	Toolkit.Telemetry	CONFIG	TelemetryController::enableTelemetryRecording - canRecordBase:true, canRecordExtended: false
[task 2021-01-12T17:55:08.106Z] 17:55:08     INFO -  1610474108096	Marionette	DEBUG	Accepted connection 0 from 127.0.0.1:49544
[task 2021-01-12T17:55:08.106Z] 17:55:08     INFO -  1610474108103	Marionette	DEBUG	Closed connection 0
[task 2021-01-12T17:55:08.106Z] 17:55:08     INFO -  1610474108104	Marionette	DEBUG	Accepted connection 1 from 127.0.0.1:49545
[task 2021-01-12T17:55:08.113Z] 17:55:08     INFO -  1610474108111	Marionette	DEBUG	1 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2021-01-12T17:55:08.128Z] 17:55:08     INFO -  1610474108123	Marionette	DEBUG	1 <- [1,1,null,{"sessionId":"1aca40ff-905b-40e3-9aec-503d7f44e74f","capabilities":{"browserName":"firefox","browserVersion":"86.0a ... d\\tmpcibe1s.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}]
[task 2021-01-12T17:55:08.135Z] 17:55:08     INFO -  1610474108130	Marionette	DEBUG	1 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}]
[task 2021-01-12T17:55:08.135Z] 17:55:08     INFO -  1610474108130	Marionette	DEBUG	1 <- [1,2,null,{"value":null}]
[task 2021-01-12T17:55:08.142Z] 17:55:08     INFO -  1610474108138	Marionette	DEBUG	1 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2021-01-12T17:55:08.142Z] 17:55:08     INFO -  1610474108138	Marionette	DEBUG	1 <- [1,3,null,{"value":null}]
[task 2021-01-12T17:55:08.143Z] 17:55:08     INFO -  1610474108141	Marionette	DEBUG	1 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2021-01-12T17:55:08.143Z] 17:55:08     INFO -  1610474108141	Marionette	DEBUG	1 <- [1,4,null,{"value":null}]
[task 2021-01-12T17:55:08.146Z] 17:55:08     INFO -  1610474108143	Marionette	DEBUG	1 -> [0,5,"WebDriver:GetChromeWindowHandle",{}]
[task 2021-01-12T17:55:08.146Z] 17:55:08     INFO -  1610474108143	Marionette	DEBUG	1 <- [1,5,null,{"value":"6"}]
[task 2021-01-12T17:55:08.146Z] 17:55:08     INFO -  1610474108144	Marionette	DEBUG	1 -> [0,6,"WebDriver:GetChromeWindowHandles",{}]
[task 2021-01-12T17:55:08.147Z] 17:55:08     INFO -  1610474108144	Marionette	DEBUG	1 <- [1,6,null,["6"]]
[task 2021-01-12T17:55:08.148Z] 17:55:08     INFO -  1610474108145	Marionette	DEBUG	1 -> [0,7,"WebDriver:GetWindowHandle",{}]
[task 2021-01-12T17:55:08.148Z] 17:55:08     INFO -  1610474108146	Marionette	DEBUG	1 <- [1,7,null,{"value":"17"}]
[task 2021-01-12T17:55:08.148Z] 17:55:08     INFO -  1610474108147	Marionette	DEBUG	1 -> [0,8,"WebDriver:GetWindowHandles",{}]
[task 2021-01-12T17:55:08.148Z] 17:55:08     INFO -  1610474108147	Marionette	DEBUG	1 <- [1,8,null,["17"]]
[task 2021-01-12T17:55:08.155Z] 17:55:08     INFO -  1610474108148	Marionette	DEBUG	1 -> [0,9,"Marionette:GetContext",{}]
[task 2021-01-12T17:55:08.155Z] 17:55:08     INFO -  1610474108149	Marionette	DEBUG	1 <- [1,9,null,{"value":"content"}]
[task 2021-01-12T17:55:08.155Z] 17:55:08     INFO -  1610474108153	Marionette	DEBUG	1 -> [0,10,"Marionette:SetContext",{"value":"content"}]
[task 2021-01-12T17:55:08.155Z] 17:55:08     INFO -  1610474108153	Marionette	DEBUG	1 <- [1,10,null,{"value":null}]
[task 2021-01-12T17:55:08.158Z] 17:55:08     INFO -  1610474108155	Marionette	DEBUG	1 -> [0,11,"WebDriver:Navigate",{"url":"about:about"}]
[task 2021-01-12T17:55:08.165Z] 17:55:08     INFO -  1610474108160	Marionette	TRACE	[17] MarionetteCommands actor created for window id 2147483649
[task 2021-01-12T17:55:08.165Z] 17:55:08     INFO -  1610474108162	Marionette	TRACE	[17] MarionetteEvents actor created for window id 2147483649
[task 2021-01-12T17:55:08.165Z] 17:55:08     INFO -  1610474108163	Marionette	TRACE	Received event beforeunload for about:blank
[task 2021-01-12T17:55:08.172Z] 17:55:08     INFO -  1610474108169	Marionette	TRACE	Remoteness change detected. Set new top-level browsing context to 36
[task 2021-01-12T17:55:08.191Z] 17:55:08     INFO -  1610474108188	Marionette	TRACE	[36] MarionetteEvents actor created for window id 25
[task 2021-01-12T17:55:08.218Z] 17:55:08     INFO -  1610474108216	Marionette	TRACE	Received event beforeunload for about:blank
[task 2021-01-12T17:55:08.218Z] 17:55:08     INFO -  1610474108216	Marionette	TRACE	Received event pagehide for about:blank
[task 2021-01-12T17:55:08.257Z] 17:55:08     INFO -  1610474108253	Marionette	TRACE	[36] MarionetteEvents actor created for window id 26
[task 2021-01-12T17:55:08.260Z] 17:55:08     INFO -  1610474108257	Marionette	TRACE	Received event DOMContentLoaded for about:about
[task 2021-01-12T17:55:08.295Z] 17:55:08     INFO -  1610474108286	Marionette	TRACE	Received event pageshow for about:about
[task 2021-01-12T17:55:08.295Z] 17:55:08     INFO -  1610474108286	Marionette	DEBUG	1 <- [1,11,null,{"value":null}]
[task 2021-01-12T17:55:08.302Z] 17:55:08     INFO -  1610474108297	Marionette	DEBUG	1 -> [0,12,"Marionette:SetContext",{"value":"content"}]
[task 2021-01-12T17:55:08.302Z] 17:55:08     INFO -  1610474108297	Marionette	DEBUG	1 <- [1,12,null,{"value":null}]
[task 2021-01-12T17:55:08.302Z] 17:55:08     INFO -  1610474108299	Marionette	DEBUG	1 -> [0,13,"Marionette:GetContext",{}]
[task 2021-01-12T17:55:08.302Z] 17:55:08     INFO -  1610474108299	Marionette	DEBUG	1 <- [1,13,null,{"value":"content"}]
[task 2021-01-12T17:55:08.302Z] 17:55:08     INFO -  1610474108300	Marionette	DEBUG	1 -> [0,14,"Marionette:SetContext",{"value":"chrome"}]
[task 2021-01-12T17:55:08.303Z] 17:55:08     INFO -  1610474108301	Marionette	DEBUG	1 <- [1,14,null,{"value":null}]
[task 2021-01-12T17:55:08.306Z] 17:55:08     INFO -  1610474108302	Marionette	DEBUG	1 -> [0,15,"WebDriver:ExecuteAsyncScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"Z:\\task_1610473700\\build ... chService.init().then(function () {\n  resolve(searchService.defaultEngine.identifier);\n});","sandbox":"default","line":37}]
[task 2021-01-12T17:55:08.313Z] 17:55:08     INFO -  1610474108308	Marionette	TRACE	[6] MarionetteCommands actor created for window id 2
[task 2021-01-12T17:55:08.313Z] 17:55:08     INFO -  1610474108310	Marionette	DEBUG	1 <- [1,15,null,{"value":"google-b-d"}]
[task 2021-01-12T17:55:08.349Z] 17:55:08     INFO -  1610474108340	Marionette	DEBUG	1 -> [0,16,"Marionette:SetContext",{"value":"content"}]
[task 2021-01-12T17:55:08.349Z] 17:55:08     INFO -  1610474108340	Marionette	DEBUG	1 <- [1,16,null,{"value":null}]
[task 2021-01-12T17:55:08.349Z] 17:55:08     INFO -  1610474108343	Marionette	DEBUG	1 -> [0,17,"Marionette:GetContext",{}]
[task 2021-01-12T17:55:08.349Z] 17:55:08     INFO -  1610474108343	Marionette	DEBUG	1 <- [1,17,null,{"value":"content"}]
[task 2021-01-12T17:55:08.349Z] 17:55:08     INFO -  1610474108345	Marionette	DEBUG	1 -> [0,18,"Marionette:SetContext",{"value":"chrome"}]
[task 2021-01-12T17:55:08.349Z] 17:55:08     INFO -  1610474108345	Marionette	DEBUG	1 <- [1,18,null,{"value":null}]
[task 2021-01-12T17:55:08.356Z] 17:55:08     INFO -  1610474108351	Marionette	DEBUG	1 -> [0,19,"WebDriver:GetWindowHandle",{}]
[task 2021-01-12T17:55:08.356Z] 17:55:08     INFO -  1610474108352	Marionette	DEBUG	1 <- [1,19,null,{"value":"36"}]
[task 2021-01-12T17:55:08.371Z] 17:55:08     INFO -  1610474108367	Marionette	DEBUG	1 -> [0,20,"WebDriver:GetWindowHandles",{}]
[task 2021-01-12T17:55:08.371Z] 17:55:08     INFO -  1610474108367	Marionette	DEBUG	1 <- [1,20,null,["36"]]
[task 2021-01-12T17:55:08.371Z] 17:55:08     INFO -  1610474108368	Marionette	DEBUG	1 -> [0,21,"WebDriver:NewWindow",{"type":"tab","focus":true,"private":false}]
[task 2021-01-12T17:55:08.378Z] 17:55:08     INFO -  1610474108375	Marionette	TRACE	Received DOM event TabOpen for [object XULElement]
[task 2021-01-12T17:55:08.393Z] 17:55:08     INFO -  1610474108388	Marionette	TRACE	[38] MarionetteEvents actor created for window id 28
[task 2021-01-12T17:55:08.420Z] 17:55:08     INFO -  1610474108415	Marionette	TRACE	Received event beforeunload for about:blank
[task 2021-01-12T17:55:08.435Z] 17:55:08     INFO -  1610474108425	Marionette	TRACE	Received event pagehide for about:blank
[task 2021-01-12T17:55:08.438Z] 17:55:08     INFO -  1610474108435	Marionette	TRACE	[38] MarionetteEvents actor created for window id 6442450945
[task 2021-01-12T17:55:08.438Z] 17:55:08     INFO -  1610474108435	Marionette	TRACE	Received event DOMContentLoaded for about:blank
[task 2021-01-12T17:55:08.446Z] 17:55:08     INFO -  1610474108441	Marionette	TRACE	Received event pageshow for about:blank
[task 2021-01-12T17:55:08.446Z] 17:55:08     INFO -  1610474108442	Marionette	DEBUG	1 <- [1,21,null,{"handle":"38","type":"tab"}]
[task 2021-01-12T17:55:08.446Z] 17:55:08     INFO -  1610474108444	Marionette	DEBUG	1 -> [0,22,"WebDriver:GetWindowHandles",{}]
[task 2021-01-12T17:55:08.447Z] 17:55:08     INFO -  1610474108444	Marionette	DEBUG	1 <- [1,22,null,["36","38"]]
[task 2021-01-12T17:55:08.447Z] 17:55:08     INFO -  1610474108445	Marionette	DEBUG	1 -> [0,23,"WebDriver:GetWindowHandles",{}]
[task 2021-01-12T17:55:08.447Z] 17:55:08     INFO -  1610474108445	Marionette	DEBUG	1 <- [1,23,null,["36","38"]]
[task 2021-01-12T17:55:08.450Z] 17:55:08     INFO -  1610474108446	Marionette	DEBUG	1 -> [0,24,"WebDriver:SwitchToWindow",{"handle":"38","focus":true}]
[task 2021-01-12T17:55:08.450Z] 17:55:08     INFO -  1610474108447	Marionette	DEBUG	1 <- [1,24,null,{"value":null}]
[task 2021-01-12T17:55:08.450Z] 17:55:08     INFO -  1610474108448	Marionette	DEBUG	1 -> [0,25,"Marionette:GetContext",{}]
[task 2021-01-12T17:55:08.451Z] 17:55:08     INFO -  1610474108448	Marionette	DEBUG	1 <- [1,25,null,{"value":"chrome"}]
[task 2021-01-12T17:55:08.451Z] 17:55:08     INFO -  1610474108449	Marionette	DEBUG	1 -> [0,26,"Marionette:SetContext",{"value":"content"}]
[task 2021-01-12T17:55:08.451Z] 17:55:08     INFO -  1610474108449	Marionette	DEBUG	1 <- [1,26,null,{"value":null}]
[task 2021-01-12T17:55:08.466Z] 17:55:08     INFO -  1610474108458	Marionette	DEBUG	1 -> [0,27,"WebDriver:Navigate",{"url":"about:newtab"}]
[task 2021-01-12T17:55:08.466Z] 17:55:08     INFO -  1610474108461	Marionette	TRACE	[38] MarionetteCommands actor created for window id 6442450945
[task 2021-01-12T17:55:08.466Z] 17:55:08     INFO -  1610474108463	Marionette	TRACE	Received event beforeunload for about:blank
[task 2021-01-12T17:55:08.473Z] 17:55:08     INFO -  1610474108467	Marionette	TRACE	Received event pagehide for about:blank
[task 2021-01-12T17:55:08.476Z] 17:55:08     INFO -  1610474108474	Marionette	TRACE	[38] MarionetteEvents actor created for window id 6442450946
[task 2021-01-12T17:55:08.479Z] 17:55:08     INFO -  1610474108476	Marionette	TRACE	Received event DOMContentLoaded for about:blank
[task 2021-01-12T17:55:08.479Z] 17:55:08     INFO -  1610474108476	Marionette	TRACE	Received event pageshow for about:blank
[task 2021-01-12T17:55:08.482Z] 17:55:08     INFO -  1610474108479	Marionette	DEBUG	1 <- [1,27,null,{"value":null}]
[task 2021-01-12T17:55:08.485Z] 17:55:08     INFO -  1610474108483	Marionette	DEBUG	1 -> [0,28,"Marionette:SetContext",{"value":"chrome"}]
[task 2021-01-12T17:55:08.485Z] 17:55:08     INFO -  1610474108483	Marionette	DEBUG	1 <- [1,28,null,{"value":null}]
[task 2021-01-12T17:55:08.485Z] 17:55:08     INFO -  1610474108484	Marionette	DEBUG	1 -> [0,29,"Marionette:GetContext",{}]
[task 2021-01-12T17:55:08.486Z] 17:55:08     INFO -  1610474108484	Marionette	DEBUG	1 <- [1,29,null,{"value":"chrome"}]
[task 2021-01-12T17:55:08.488Z] 17:55:08     INFO -  1610474108485	Marionette	DEBUG	1 -> [0,30,"Marionette:SetContext",{"value":"chrome"}]
[task 2021-01-12T17:55:08.488Z] 17:55:08     INFO -  1610474108485	Marionette	DEBUG	1 <- [1,30,null,{"value":null}]
[task 2021-01-12T17:55:08.495Z] 17:55:08     INFO -  1610474108492	Marionette	DEBUG	1 -> [0,31,"WebDriver:ExecuteScript",{"script":"gURLBar.select();","newSandbox":true,"args":[],"filename":"Z:\\task_1610473700\\build\\venv\\lib\\site-packages\\telemetry_harness\\testcase.py","sandbox":"default","line":83}]
[task 2021-01-12T17:55:08.502Z] 17:55:08     INFO -  1610474108497	Marionette	DEBUG	1 <- [1,31,null,{"value":null}]
[task 2021-01-12T17:55:08.502Z] 17:55:08     INFO -  1610474108498	Marionette	DEBUG	1 -> [0,32,"WebDriver:FindElement",{"using":"id","value":"urlbar-input"}]
[task 2021-01-12T17:55:08.502Z] 17:55:08     INFO -  1610474108500	Marionette	DEBUG	1 <- [1,32,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"d5093df5-6615-418b-b3c3-924bd2aa4242"}}]
[task 2021-01-12T17:55:08.505Z] 17:55:08     INFO -  1610474108502	Marionette	DEBUG	1 -> [0,33,"WebDriver:ElementSendKeys",{"text":"","id":"d5093df5-6615-418b-b3c3-924bd2aa4242"}]
[task 2021-01-12T17:55:08.520Z] 17:55:08     INFO -  1610474108517	Marionette	DEBUG	1 <- [1,33,null,{"value":null}]
[task 2021-01-12T17:55:08.523Z] 17:55:08     INFO -  1610474108518	Marionette	DEBUG	1 -> [0,34,"WebDriver:ElementSendKeys",{"text":"mozilla firefox","id":"d5093df5-6615-418b-b3c3-924bd2aa4242"}]
[task 2021-01-12T17:55:08.550Z] 17:55:08     INFO -  1610474108547	Toolkit.Telemetry	TRACE	TelemetryController::observe - app-startup notified.
[task 2021-01-12T17:55:08.550Z] 17:55:08     INFO -  1610474108548	Toolkit.Telemetry	CONFIG	TelemetryController::enableTelemetryRecording - canRecordBase:true, canRecordExtended: false
[task 2021-01-12T17:55:08.593Z] 17:55:08     INFO -  1610474108590	Marionette	DEBUG	1 <- [1,34,null,{"value":null}]
[task 2021-01-12T17:55:08.600Z] 17:55:08     INFO -  1610474108595	Marionette	DEBUG	1 -> [0,35,"Marionette:SetContext",{"value":"chrome"}]
[task 2021-01-12T17:55:08.600Z] 17:55:08     INFO -  1610474108596	Marionette	DEBUG	1 <- [1,35,null,{"value":null}]
[task 2021-01-12T17:55:08.675Z] 17:55:08     INFO -  1610474108668	Marionette	DEBUG	1 -> [0,36,"Marionette:GetContext",{}]
[task 2021-01-12T17:55:08.675Z] 17:55:08     INFO -  1610474108669	Marionette	DEBUG	1 <- [1,36,null,{"value":"chrome"}]
[task 2021-01-12T17:55:08.710Z] 17:55:08     INFO -  1610474108701	Marionette	DEBUG	1 -> [0,37,"Marionette:SetContext",{"value":"content"}]
[task 2021-01-12T17:55:08.710Z] 17:55:08     INFO -  1610474108701	Marionette	DEBUG	1 <- [1,37,null,{"value":null}]
[task 2021-01-12T17:55:08.725Z] 17:55:08     INFO -  1610474108719	Marionette	DEBUG	1 -> [0,38,"WebDriver:ExecuteScript",{"script":"let location = document.location.toString()\n        function validate(term){\n    ... name":"Z:\\task_1610473700\\build\\venv\\lib\\site-packages\\telemetry_harness\\testcase.py","sandbox":"default","line":100}]
[task 2021-01-12T17:55:08.725Z] 17:55:08     INFO -  1610474108721	Marionette	TRACE	[38] MarionetteCommands actor created for window id 6442450946
[task 2021-01-12T17:55:08.728Z] 17:55:08     INFO -  1610474108725	Marionette	DEBUG	1 <- [1,38,null,{"value":false}]
[task 2021-01-12T17:55:08.735Z] 17:55:08     INFO -  1610474108732	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: browser-search-service, aData: write-settings-to-disk-complete
[task 2021-01-12T17:55:08.934Z] 17:55:08     INFO -  1610474108931	Marionette	TRACE	[38] MarionetteEvents actor created for window id 30
[task 2021-01-12T17:55:09.210Z] 17:55:09     INFO -  1610474109203	Marionette	DEBUG	1 -> [0,39,"WebDriver:ExecuteScript",{"script":"let location = document.location.toString()\n        function validate(term){\n    ... name":"Z:\\task_1610473700\\build\\venv\\lib\\site-packages\\telemetry_harness\\testcase.py","sandbox":"default","line":100}]
[task 2021-01-12T17:55:09.210Z] 17:55:09     INFO -  1610474109204	Marionette	TRACE	[38] MarionetteCommands actor created for window id 2147483650
[task 2021-01-12T17:55:09.211Z] 17:55:09     INFO -  1610474109208	Marionette	DEBUG	1 <- [1,39,null,{"value":true}]
[task 2021-01-12T17:55:09.212Z] 17:55:09     INFO -  1610474109209	Marionette	DEBUG	1 -> [0,40,"Marionette:SetContext",{"value":"chrome"}]
[task 2021-01-12T17:55:09.212Z] 17:55:09     INFO -  1610474109210	Marionette	DEBUG	1 <- [1,40,null,{"value":null}]
[task 2021-01-12T17:55:09.212Z] 17:55:09     INFO -  1610474109211	Marionette	DEBUG	1 -> [0,41,"WebDriver:CloseWindow",{}]
[task 2021-01-12T17:55:09.231Z] 17:55:09     INFO -  1610474109219	Marionette	TRACE	Received DOM event TabClose for [object XULElement]
[task 2021-01-12T17:55:09.231Z] 17:55:09     INFO -  1610474109222	Marionette	TRACE	[38] MarionetteEvents actor created for window id 2147483650
[task 2021-01-12T17:55:09.246Z] 17:55:09     INFO -  1610474109238	Marionette	TRACE	Received observer notification message-manager-disconnect
[task 2021-01-12T17:55:09.246Z] 17:55:09     INFO -  1610474109239	Marionette	DEBUG	1 <- [1,41,null,["36"]]
[task 2021-01-12T17:55:09.250Z] 17:55:09     INFO - wait_for_pings running action 'restart_browser'.
[task 2021-01-12T17:55:09.250Z] 17:55:09     INFO -  1610474109244	Marionette	DEBUG	1 -> [0,42,"WebDriver:SwitchToWindow",{"handle":"36","focus":true}]
[task 2021-01-12T17:55:09.250Z] 17:55:09     INFO -  1610474109245	Marionette	DEBUG	1 <- [1,42,null,{"value":null}]
[task 2021-01-12T17:55:09.250Z] 17:55:09     INFO -  1610474109246	Marionette	DEBUG	1 -> [0,43,"Marionette:SetContext",{"value":"content"}]
[task 2021-01-12T17:55:09.250Z] 17:55:09     INFO -  1610474109246	Marionette	DEBUG	1 <- [1,43,null,{"value":null}]
[task 2021-01-12T17:55:09.251Z] 17:55:09     INFO -  1610474109247	Marionette	DEBUG	1 -> [0,44,"Marionette:GetContext",{}]
[task 2021-01-12T17:55:09.251Z] 17:55:09     INFO -  1610474109248	Marionette	DEBUG	1 <- [1,44,null,{"value":"content"}]
[task 2021-01-12T17:55:09.251Z] 17:55:09     INFO -  1610474109249	Marionette	DEBUG	1 -> [0,45,"Marionette:AcceptConnections",{"value":false}]
[task 2021-01-12T17:55:09.251Z] 17:55:09     INFO -  1610474109249	Marionette	INFO	Stopped listening on port 2828
[task 2021-01-12T17:55:09.251Z] 17:55:09     INFO -  1610474109249	Marionette	DEBUG	1 <- [1,45,null,{"value":null}]
[task 2021-01-12T17:55:09.254Z] 17:55:09     INFO -  1610474109250	Marionette	DEBUG	1 -> [0,46,"Marionette:GetContext",{}]
[task 2021-01-12T17:55:09.254Z] 17:55:09     INFO -  1610474109251	Marionette	DEBUG	1 <- [1,46,null,{"value":"content"}]
[task 2021-01-12T17:55:09.254Z] 17:55:09     INFO -  1610474109251	Marionette	DEBUG	1 -> [0,47,"Marionette:SetContext",{"value":"chrome"}]
[task 2021-01-12T17:55:09.254Z] 17:55:09     INFO -  1610474109252	Marionette	DEBUG	1 <- [1,47,null,{"value":null}]
[task 2021-01-12T17:55:09.257Z] 17:55:09     INFO -  1610474109254	Marionette	DEBUG	1 -> [0,48,"WebDriver:ExecuteScript",{"script":"Components.utils.import(\"resource://gre/modules/Services.jsm\");\n                ... me":"Z:\\task_1610473700\\build\\venv\\lib\\site-packages\\marionette_driver\\marionette.py","sandbox":"default","line":955}]
[task 2021-01-12T17:55:09.258Z] 17:55:09     INFO -  1610474109256	Marionette	DEBUG	1 <- [1,48,null,{"value":false}]
[task 2021-01-12T17:55:09.258Z] 17:55:09     INFO -  1610474109257	Marionette	DEBUG	1 -> [0,49,"Marionette:SetContext",{"value":"content"}]
[task 2021-01-12T17:55:09.261Z] 17:55:09     INFO -  1610474109258	Marionette	DEBUG	1 <- [1,49,null,{"value":null}]
[task 2021-01-12T17:55:09.261Z] 17:55:09     INFO -  1610474109259	Marionette	DEBUG	1 -> [0,50,"Marionette:Quit",{"flags":["eForceQuit","eRestart"]}]
[task 2021-01-12T17:55:09.304Z] 17:55:09     INFO -  1610474109300	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: toolkit.startup.last_success
[task 2021-01-12T17:55:09.304Z] 17:55:09     INFO -  1610474109302	Marionette	TRACE	Received observer notification quit-application
[task 2021-01-12T17:55:09.304Z] 17:55:09     INFO -  1610474109302	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.sessionstore.resume_session_once
[task 2021-01-12T17:55:09.315Z] 17:55:09     INFO -  1610474109310	Marionette	DEBUG	1 <- [1,50,null,{"cause":"restart"}]
[task 2021-01-12T17:55:09.355Z] 17:55:09     INFO -  JavaScript error: resource://gre/modules/UrlClassifierListManager.jsm, line 691: TypeError: can't access property "provider", this.tablesData[table] is undefined
[task 2021-01-12T17:55:09.371Z] 17:55:09     INFO -  1610474109358	Marionette	DEBUG	Closed connection 1
[task 2021-01-12T17:55:09.374Z] 17:55:09     INFO -  1610474109370	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: privacy.sanitize.pending
[task 2021-01-12T17:55:09.469Z] 17:55:09     INFO -  1610474109460	Toolkit.Telemetry	TRACE	TelemetryController::shutdown
[task 2021-01-12T17:55:09.469Z] 17:55:09     INFO -  1610474109460	Toolkit.Telemetry	TRACE	TelemetryController::sendNewProfilePing - shutting down: true
[task 2021-01-12T17:55:09.469Z] 17:55:09     INFO -  1610474109460	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - type: new-profile, aOptions: {"addClientId":true,"addEnvironment":true,"usePingSender":true}
[task 2021-01-12T17:55:09.469Z] 17:55:09     INFO -  1610474109460	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type new-profile, aOptions {"addClientId":true,"addEnvironment":true,"usePingSender":true}
[task 2021-01-12T17:55:09.469Z] 17:55:09     INFO -  1610474109461	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - ping assembled, id: 1c846c1a-c497-42b7-88a9-e3bbfc662ae8
[task 2021-01-12T17:55:09.469Z] 17:55:09     INFO -  1610474109462	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - ping id: 1c846c1a-c497-42b7-88a9-e3bbfc662ae8, options: {"usePingSender":true}
[task 2021-01-12T17:55:09.469Z] 17:55:09     INFO -  1610474109462	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet.
[task 2021-01-12T17:55:09.470Z] 17:55:09     INFO -  1610474109464	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: Z:\task_1610473700\build\tmpcibe1s.mozrunner\datareporting\archived\2021-01\1610474109461.1c846c1a-c497-42b7-88a9-e3bbfc662ae8.new-profile.jsonlz4
[task 2021-01-12T17:55:09.473Z] 17:55:09     INFO -  1610474109469	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: Z:\task_1610473700\build\tmpcibe1s.mozrunner\saved-telemetry-pings\1c846c1a-c497-42b7-88a9-e3bbfc662ae8
[task 2021-01-12T17:55:09.480Z] 17:55:09     INFO -  1610474109475	Toolkit.Telemetry	TRACE	TelemetryStorage::savePendingPing - saved ping with id 1c846c1a-c497-42b7-88a9-e3bbfc662ae8
[task 2021-01-12T17:55:09.480Z] 17:55:09     INFO -  1610474109475	Toolkit.Telemetry	TRACE	TelemetrySend::_sendWithPingSender - sending 1c846c1a-c497-42b7-88a9-e3bbfc662ae8 to http://localhost:8000/pings/submit/telemetry/1c846c1a-c497-42b7-88a9-e3bbfc662ae8/new-profile/Firefox/86.0a1/default/20210112170249?v=4
[task 2021-01-12T17:55:09.480Z] 17:55:09     INFO -  1610474109475	Toolkit.Telemetry	TRACE	TelemetrySend::_sendWithPingSender - too late to send. Batching.
[task 2021-01-12T17:55:09.480Z] 17:55:09     INFO -  1610474109475	Toolkit.Telemetry	TRACE	TelemetrySession::markNewProfilePingSent
[task 2021-01-12T17:55:09.480Z] 17:55:09     INFO -  1610474109475	Toolkit.Telemetry	TRACE	TelemetryStorage::_popAndPerformQueuedOperation - Performing queued operation.
[task 2021-01-12T17:55:09.487Z] 17:55:09     INFO -  1610474109483	Toolkit.Telemetry	TRACE	TelemetryEventPing::::Shutting down.
[task 2021-01-12T17:55:09.487Z] 17:55:09     INFO -  1610474109483	Toolkit.Telemetry	TRACE	TelemetryEventPing::::_submitPing
[task 2021-01-12T17:55:09.487Z] 17:55:09     INFO -  1610474109484	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - type: event, aOptions: {"addClientId":true,"addEnvironment":true,"usePingSender":true}
[task 2021-01-12T17:55:09.487Z] 17:55:09     INFO -  1610474109484	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type event, aOptions {"addClientId":true,"addEnvironment":true,"usePingSender":true}
[task 2021-01-12T17:55:09.487Z] 17:55:09     INFO -  1610474109484	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - ping assembled, id: 9d7ee7cc-d9cb-42b9-a0ce-61f51b1da732
[task 2021-01-12T17:55:09.487Z] 17:55:09     INFO -  1610474109485	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - ping id: 9d7ee7cc-d9cb-42b9-a0ce-61f51b1da732, options: {"usePingSender":true}
[task 2021-01-12T17:55:09.487Z] 17:55:09     INFO -  1610474109485	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet.
[task 2021-01-12T17:55:09.487Z] 17:55:09     INFO -  1610474109485	Toolkit.Telemetry	TRACE	TelemetryPrioPing::Shutting down.
[task 2021-01-12T17:55:09.488Z] 17:55:09     INFO -  1610474109485	Toolkit.Telemetry	TRACE	TelemetryPrioPing::_submitPing
[task 2021-01-12T17:55:09.488Z] 17:55:09     INFO -  1610474109485	Toolkit.Telemetry	TRACE	TelemetryPrioPing::nothing to send
[task 2021-01-12T17:55:09.488Z] 17:55:09     INFO -  1610474109485	Toolkit.Telemetry	TRACE	TelemetryReportingPolicy::shutdown
[task 2021-01-12T17:55:09.488Z] 17:55:09     INFO -  1610474109486	Toolkit.Telemetry	TRACE	TelemetryEnvironment::shutdown
[task 2021-01-12T17:55:09.488Z] 17:55:09     INFO -  1610474109486	Toolkit.Telemetry	TRACE	TelemetrySend::Scheduler::shutdown
[task 2021-01-12T17:55:09.488Z] 17:55:09     INFO -  1610474109486	Toolkit.Telemetry	TRACE	TelemetrySend::promisePendingPingActivity - Waiting for ping task
[task 2021-01-12T17:55:09.491Z] 17:55:09     INFO -  1610474109487	Toolkit.Telemetry	TRACE	TelemetryHealthPing::::shutdown()
[task 2021-01-12T17:55:09.491Z] 17:55:09     INFO -  1610474109487	Toolkit.Telemetry	TRACE	TelemetrySession::shutdownChromeProcess
[task 2021-01-12T17:55:09.491Z] 17:55:09     INFO -  1610474109487	Toolkit.Telemetry	TRACE	TelemetryEnvironment::unregisterChangeListener for TelemetrySession::onEnvironmentChange
[task 2021-01-12T17:55:09.491Z] 17:55:09     INFO -  1610474109487	Toolkit.Telemetry	WARN	TelemetryEnvironment::registerChangeListener - already shutdown
[task 2021-01-12T17:55:09.491Z] 17:55:09     INFO -  1610474109488	Toolkit.Telemetry	TRACE	TelemetryScheduler::shutdown
[task 2021-01-12T17:55:09.491Z] 17:55:09     INFO -  1610474109488	Toolkit.Telemetry	TRACE	TelemetrySession::saveShutdownPings
[task 2021-01-12T17:55:09.491Z] 17:55:09     INFO -  1610474109488	Toolkit.Telemetry	TRACE	TelemetrySession::getSessionPayload - reason: shutdown, clearSubsession: false
[task 2021-01-12T17:55:09.491Z] 17:55:09     INFO -  1610474109488	Toolkit.Telemetry	TRACE	TelemetrySession::assemblePayloadWithMeasurements - reason: shutdown, submitting subsession data: true
[task 2021-01-12T17:55:09.498Z] 17:55:09     INFO -  1610474109493	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - type: main, aOptions: {"addClientId":true,"addEnvironment":true,"usePingSender":false}
[task 2021-01-12T17:55:09.498Z] 17:55:09     INFO -  1610474109493	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type main, aOptions {"addClientId":true,"addEnvironment":true,"usePingSender":false}
[task 2021-01-12T17:55:09.499Z] 17:55:09     INFO -  1610474109497	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - ping assembled, id: ff8f844a-828c-48e6-a3b2-9854cf1cf028
[task 2021-01-12T17:55:09.499Z] 17:55:09     INFO -  1610474109497	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - ping id: ff8f844a-828c-48e6-a3b2-9854cf1cf028, options: {"usePingSender":false}
[task 2021-01-12T17:55:09.499Z] 17:55:09     INFO -  1610474109497	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet.
[task 2021-01-12T17:55:09.500Z] 17:55:09     INFO -  1610474109497	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet.
[task 2021-01-12T17:55:09.500Z] 17:55:09     INFO -  1610474109497	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - can't send ping now, persisting to disk - canSendNow: false
[task 2021-01-12T17:55:09.500Z] 17:55:09     INFO -  1610474109497	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - type: first-shutdown, aOptions: {"addClientId":true,"addEnvironment":true,"usePingSender":true}
[task 2021-01-12T17:55:09.500Z] 17:55:09     INFO -  1610474109497	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type first-shutdown, aOptions {"addClientId":true,"addEnvironment":true,"usePingSender":true}
[task 2021-01-12T17:55:09.507Z] 17:55:09     INFO -  1610474109502	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - ping assembled, id: 4f178cc0-26c9-4b4e-a2d5-d4067c345ce3
[task 2021-01-12T17:55:09.507Z] 17:55:09     INFO -  1610474109502	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - ping id: 4f178cc0-26c9-4b4e-a2d5-d4067c345ce3, options: {"usePingSender":true}
[task 2021-01-12T17:55:09.507Z] 17:55:09     INFO -  1610474109502	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet.
[task 2021-01-12T17:55:09.507Z] 17:55:09     INFO -  1610474109502	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: Z:\task_1610473700\build\tmpcibe1s.mozrunner\datareporting\archived\2021-01\1610474109484.9d7ee7cc-d9cb-42b9-a0ce-61f51b1da732.event.jsonlz4
[task 2021-01-12T17:55:09.507Z] 17:55:09     INFO -  1610474109504	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: Z:\task_1610473700\build\tmpcibe1s.mozrunner\saved-telemetry-pings\9d7ee7cc-d9cb-42b9-a0ce-61f51b1da732
[task 2021-01-12T17:55:09.508Z] 17:55:09     INFO -  1610474109505	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: Z:\task_1610473700\build\tmpcibe1s.mozrunner\datareporting\archived\2021-01\1610474109496.ff8f844a-828c-48e6-a3b2-9854cf1cf028.main.jsonlz4
[task 2021-01-12T17:55:09.511Z] 17:55:09     INFO -  1610474109507	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: Z:\task_1610473700\build\tmpcibe1s.mozrunner\saved-telemetry-pings\ff8f844a-828c-48e6-a3b2-9854cf1cf028
[task 2021-01-12T17:55:09.511Z] 17:55:09     INFO -  1610474109509	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: Z:\task_1610473700\build\tmpcibe1s.mozrunner\datareporting\archived\2021-01\1610474109501.4f178cc0-26c9-4b4e-a2d5-d4067c345ce3.first-shutdown.jsonlz4
[task 2021-01-12T17:55:09.514Z] 17:55:09     INFO -  1610474109511	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: Z:\task_1610473700\build\tmpcibe1s.mozrunner\saved-telemetry-pings\4f178cc0-26c9-4b4e-a2d5-d4067c345ce3
[task 2021-01-12T17:55:09.529Z] 17:55:09     INFO -  1610474109523	Toolkit.Telemetry	TRACE	TelemetryStorage::savePendingPing - saved ping with id 9d7ee7cc-d9cb-42b9-a0ce-61f51b1da732
[task 2021-01-12T17:55:09.529Z] 17:55:09     INFO -  1610474109523	Toolkit.Telemetry	TRACE	TelemetrySend::_sendWithPingSender - sending 9d7ee7cc-d9cb-42b9-a0ce-61f51b1da732 to http://localhost:8000/pings/submit/telemetry/9d7ee7cc-d9cb-42b9-a0ce-61f51b1da732/event/Firefox/86.0a1/default/20210112170249?v=4
[task 2021-01-12T17:55:09.529Z] 17:55:09     INFO -  1610474109524	Toolkit.Telemetry	TRACE	TelemetrySend::_sendWithPingSender - too late to send. Batching.
[task 2021-01-12T17:55:09.544Z] 17:55:09     INFO -  1610474109536	Toolkit.Telemetry	TRACE	TelemetryStorage::savePendingPing - saved ping with id ff8f844a-828c-48e6-a3b2-9854cf1cf028
[task 2021-01-12T17:55:09.551Z] 17:55:09     INFO -  1610474109548	Toolkit.Telemetry	TRACE	TelemetryStorage::savePendingPing - saved ping with id 4f178cc0-26c9-4b4e-a2d5-d4067c345ce3
[task 2021-01-12T17:55:09.551Z] 17:55:09     INFO -  1610474109548	Toolkit.Telemetry	TRACE	TelemetrySend::_sendWithPingSender - sending 4f178cc0-26c9-4b4e-a2d5-d4067c345ce3 to http://localhost:8000/pings/submit/telemetry/4f178cc0-26c9-4b4e-a2d5-d4067c345ce3/first-shutdown/Firefox/86.0a1/default/20210112170249?v=4
[task 2021-01-12T17:55:09.551Z] 17:55:09     INFO -  1610474109548	Toolkit.Telemetry	TRACE	TelemetrySend::_sendWithPingSender - too late to send. Batching.
[task 2021-01-12T17:55:09.551Z] 17:55:09     INFO -  1610474109548	Toolkit.Telemetry	TRACE	TelemetryStorage::_popAndPerformQueuedOperation - Performing queued operation.
[task 2021-01-12T17:55:09.554Z] 17:55:09     INFO -  1610474109550	Toolkit.Telemetry	TRACE	TelemetryStorage::removeAbortedSessionPing - success
[task 2021-01-12T17:55:09.554Z] 17:55:09     INFO -  1610474109551	Toolkit.Telemetry	TRACE	TelemetrySend::flushPingSenderBatch - Sending 3 pings.
[task 2021-01-12T17:55:09.554Z] 17:55:09     INFO -  1610474109552	Toolkit.Telemetry	TRACE	TelemetryStorage::_popAndPerformQueuedOperation - Performing queued operation.
[task 2021-01-12T17:55:09.557Z] 17:55:09     INFO -  1610474109554	Marionette	TRACE	Received observer notification xpcom-will-shutdown
[task 2021-01-12T17:55:09.557Z] 17:55:09     INFO -  1610474109554	Marionette	DEBUG	Marionette stopped listening
[task 2021-01-12T17:55:09.618Z] 17:55:09     INFO - pingserver pings_handler received 'new-profile' ping
[task 2021-01-12T17:55:09.625Z] 17:55:09     INFO - pingserver pings_handler received 'event' ping
[task 2021-01-12T17:55:09.640Z] 17:55:09     INFO - pingserver pings_handler received 'first-shutdown' ping
[task 2021-01-12T17:55:11.115Z] 17:55:11     INFO - pingserver pings_handler received 'main' ping with reason 'shutdown'
[task 2021-01-12T17:55:11.194Z] 17:55:11     INFO - wait_for_pings running action 'install_addon'.
[task 2021-01-12T17:55:11.317Z] 17:55:11     INFO - pingserver pings_handler received 'main' ping with reason 'environment-change'
[task 2021-01-12T17:55:13.552Z] 17:55:13     INFO - wait_for_pings running action 'restart_browser'.
[task 2021-01-12T17:58:23.916Z] 17:58:23     INFO - mozcrash Copy/paste: Z:/task_1610473700/fetches\minidump_stackwalk\minidump_stackwalk.exe Z:\task_1610473700\build\tmpcibe1s.mozrunner\minidumps\10097778-1528-40e8-bdd3-b65d8d88e77d.dmp c:\users\task_1610473700\appdata\local\temp\tmpy5of_4
[task 2021-01-12T17:58:34.157Z] 17:58:34     INFO - mozcrash Saved minidump as Z:\task_1610473700\build\blobber_upload_dir\10097778-1528-40e8-bdd3-b65d8d88e77d.dmp
[task 2021-01-12T17:58:34.158Z] 17:58:34     INFO - mozcrash Saved app info as Z:\task_1610473700\build\blobber_upload_dir\10097778-1528-40e8-bdd3-b65d8d88e77d.extra
[task 2021-01-12T17:58:34.276Z] 17:58:34     INFO - PROCESS-CRASH | telemetry/marionette/tests/client/test_search_counts_across_sessions.py TestSearchCounts.test_search_counts | application crashed [@ RtlComputePrivatizedDllName_U + 0x110]
[task 2021-01-12T17:58:34.277Z] 17:58:34     INFO - Crash dump filename: Z:\task_1610473700\build\tmpcibe1s.mozrunner\minidumps\10097778-1528-40e8-bdd3-b65d8d88e77d.dmp
[task 2021-01-12T17:58:34.277Z] 17:58:34     INFO - Operating system: Windows NT
[task 2021-01-12T17:58:34.277Z] 17:58:34     INFO -                   6.1.7601 Service Pack 1
[task 2021-01-12T17:58:34.277Z] 17:58:34     INFO - CPU: x86
[task 2021-01-12T17:58:34.277Z] 17:58:34     INFO -      GenuineIntel family 6 model 63 stepping 2
[task 2021-01-12T17:58:34.277Z] 17:58:34     INFO -      8 CPUs
[task 2021-01-12T17:58:34.277Z] 17:58:34     INFO - 
[task 2021-01-12T17:58:34.277Z] 17:58:34     INFO - GPU: UNKNOWN
[task 2021-01-12T17:58:34.277Z] 17:58:34     INFO - 
[task 2021-01-12T17:58:34.277Z] 17:58:34     INFO - Crash reason:  0xc000000d / 0x00000000
[task 2021-01-12T17:58:34.277Z] 17:58:34     INFO - Crash address: 0x0
[task 2021-01-12T17:58:34.277Z] 17:58:34     INFO - Assertion: Invalid parameter passed to library function (null) in function (null), in file (null)
[task 2021-01-12T17:58:34.277Z] 17:58:34     INFO - Process uptime: 4 seconds
[task 2021-01-12T17:58:34.277Z] 17:58:34     INFO - 
[task 2021-01-12T17:58:34.277Z] 17:58:34     INFO - Thread 31 (crashed)
[task 2021-01-12T17:58:34.277Z] 17:58:34     INFO -  0  ucrtbase.dll!RtlComputePrivatizedDllName_U + 0x110
[task 2021-01-12T17:58:34.277Z] 17:58:34     INFO -     eip = 0x6c0d0d6b   esp = 0x0d20f66c   ebp = 0x0d20f694   ebx = 0x0d20f078
[task 2021-01-12T17:58:34.277Z] 17:58:34     INFO -     esi = 0x00960900   edi = 0x0d20f380   eax = 0x0d20f020   ecx = 0x00000000
[task 2021-01-12T17:58:34.277Z] 17:58:34     INFO -     edx = 0x0d20f380   efl = 0x00000212
[task 2021-01-12T17:58:34.277Z] 17:58:34     INFO -     Found by: given as instruction pointer in context
[task 2021-01-12T17:58:34.278Z] 17:58:34     INFO -  1  ucrtbase.dll!RtlComputePrivatizedDllName_U + 0x140
[task 2021-01-12T17:58:34.278Z] 17:58:34     INFO -     eip = 0x6c0d0d9b   esp = 0x0d20f69c   ebp = 0x0d20f6f8   ebx = 0x00000000
[task 2021-01-12T17:58:34.278Z] 17:58:34     INFO -     Found by: call frame info
[task 2021-01-12T17:58:34.278Z] 17:58:34     INFO -  2  xul.dll + 0x5c359
[task 2021-01-12T17:58:34.278Z] 17:58:34     INFO -     eip = 0x57f8c359   esp = 0x0d20f700   ebp = 0x0d20f71c   ebx = 0x13b88880
[task 2021-01-12T17:58:34.278Z] 17:58:34     INFO -     Found by: call frame info
[task 2021-01-12T17:58:34.278Z] 17:58:34     INFO -  3  xul.dll + 0x5c3d1
[task 2021-01-12T17:58:34.278Z] 17:58:34     INFO -     eip = 0x57f8c3d1   esp = 0x0d20f724   ebp = 0x0d20f734
[task 2021-01-12T17:58:34.278Z] 17:58:34     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:58:34.278Z] 17:58:34     INFO -  4  xul.dll + 0x5d7370
[task 2021-01-12T17:58:34.278Z] 17:58:34     INFO -     eip = 0x58507370   esp = 0x0d20f73c   ebp = 0x0d20f744
[task 2021-01-12T17:58:34.278Z] 17:58:34     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:58:34.278Z] 17:58:34     INFO -  5  xul.dll + 0x718b27
[task 2021-01-12T17:58:34.278Z] 17:58:34     INFO -     eip = 0x58648b27   esp = 0x0d20f74c   ebp = 0x0d20f8d4
[task 2021-01-12T17:58:34.278Z] 17:58:34     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:58:34.278Z] 17:58:34     INFO -  6  xul.dll + 0x65e1b6
[task 2021-01-12T17:58:34.278Z] 17:58:34     INFO -     eip = 0x5858e1b6   esp = 0x0d20f8dc   ebp = 0x0d20f968
[task 2021-01-12T17:58:34.278Z] 17:58:34     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:58:34.279Z] 17:58:34     INFO -  7  xul.dll + 0x5d4065
[task 2021-01-12T17:58:34.279Z] 17:58:34     INFO -     eip = 0x58504065   esp = 0x0d20f970   ebp = 0x0d20f98c
[task 2021-01-12T17:58:34.279Z] 17:58:34     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:58:34.279Z] 17:58:34     INFO -  8  xul.dll + 0x5d330b
[task 2021-01-12T17:58:34.279Z] 17:58:34     INFO -     eip = 0x5850330b   esp = 0x0d20f994   ebp = 0x0d20fa04
[task 2021-01-12T17:58:34.279Z] 17:58:34     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:58:34.279Z] 17:58:34     INFO -  9  xul.dll + 0x5d3953
[task 2021-01-12T17:58:34.279Z] 17:58:34     INFO -     eip = 0x58503953   esp = 0x0d20fa0c   ebp = 0x0d20fa30
[task 2021-01-12T17:58:34.279Z] 17:58:34     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:58:34.279Z] 17:58:34     INFO - 10  xul.dll + 0x5d3a85
[task 2021-01-12T17:58:34.279Z] 17:58:34     INFO -     eip = 0x58503a85   esp = 0x0d20fa38   ebp = 0x0d20fa44
[task 2021-01-12T17:58:34.279Z] 17:58:34     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:58:34.279Z] 17:58:34     INFO - 11  xul.dll + 0xe5f90
[task 2021-01-12T17:58:34.279Z] 17:58:34     INFO -     eip = 0x58015f90   esp = 0x0d20fa4c   ebp = 0x0d20fb10
[task 2021-01-12T17:58:34.279Z] 17:58:34     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:58:34.279Z] 17:58:34     INFO - 12  xul.dll + 0xe9c0f
[task 2021-01-12T17:58:34.279Z] 17:58:34     INFO -     eip = 0x58019c0f   esp = 0x0d20fb18   ebp = 0x0d20fb34
[task 2021-01-12T17:58:34.279Z] 17:58:34     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:58:34.280Z] 17:58:34     INFO - 13  xul.dll + 0x5d61c1
[task 2021-01-12T17:58:34.280Z] 17:58:34     INFO -     eip = 0x585061c1   esp = 0x0d20fb3c   ebp = 0x0d20fb64
[task 2021-01-12T17:58:34.280Z] 17:58:34     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:58:34.280Z] 17:58:34     INFO - 14  xul.dll + 0x5a63f9
[task 2021-01-12T17:58:34.280Z] 17:58:34     INFO -     eip = 0x584d63f9   esp = 0x0d20fb6c   ebp = 0x0d20fb9c
[task 2021-01-12T17:58:34.280Z] 17:58:34     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:58:34.280Z] 17:58:34     INFO - 15  xul.dll + 0x5a6356
[task 2021-01-12T17:58:34.280Z] 17:58:34     INFO -     eip = 0x584d6356   esp = 0x0d20fba4   ebp = 0x0d20fbbc
[task 2021-01-12T17:58:34.280Z] 17:58:34     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:58:34.280Z] 17:58:34     INFO - 16  xul.dll + 0xe3ab5
[task 2021-01-12T17:58:34.280Z] 17:58:34     INFO -     eip = 0x58013ab5   esp = 0x0d20fbc4   ebp = 0x0d20fca0
[task 2021-01-12T17:58:34.280Z] 17:58:34     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:58:34.280Z] 17:58:34     INFO - 17  nss3.dll + 0x104fa4
[task 2021-01-12T17:58:34.280Z] 17:58:34     INFO -     eip = 0x6bba4fa4   esp = 0x0d20fca8   ebp = 0x0d20fcc8
[task 2021-01-12T17:58:34.280Z] 17:58:34     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:58:34.280Z] 17:58:34     INFO - 18  nss3.dll + 0xf8896
[task 2021-01-12T17:58:34.280Z] 17:58:34     INFO -     eip = 0x6bb98896   esp = 0x0d20fcd0   ebp = 0x0d20fcd8
[task 2021-01-12T17:58:34.280Z] 17:58:34     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:58:34.281Z] 17:58:34     INFO - 19  ucrtbase.dll!__RtlConvertUlongToLargeInteger + 0x8489
[task 2021-01-12T17:58:34.281Z] 17:58:34     INFO -     eip = 0x6c06e16f   esp = 0x0d20fce0   ebp = 0x0d20fd14
[task 2021-01-12T17:58:34.281Z] 17:58:34     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:58:34.281Z] 17:58:34     INFO - 20  kernel32.dll! ?? ?? ::FNODOBFM::`string' + 0x46
[task 2021-01-12T17:58:34.281Z] 17:58:34     INFO -     eip = 0x77a5ef3c   esp = 0x0d20fd1c   ebp = 0x0d20fd20
[task 2021-01-12T17:58:34.281Z] 17:58:34     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:58:34.281Z] 17:58:34     INFO - 21  ntdll.dll!__RtlUserThreadStart + 0x27
[task 2021-01-12T17:58:34.281Z] 17:58:34     INFO -     eip = 0x77d53618   esp = 0x0d20fd28   ebp = 0x0d20fd60
[task 2021-01-12T17:58:34.281Z] 17:58:34     INFO -     Found by: previous frame's frame pointer
[task 2021-01-12T17:58:34.281Z] 17:58:34     INFO - 22  ntdll.dll!_RtlUserThreadStart + 0x1b
[task 2021-01-12T17:58:34.281Z] 17:58:34     INFO -     eip = 0x77d535eb   esp = 0x0d20fd68   ebp = 0x0d20fd78
[task 2021-01-12T17:58:34.281Z] 17:58:34     INFO -     Found by: call frame info```
Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.