Closed Bug 1525417 Opened 6 years ago Closed 6 years ago

windows/aarch64 - failures in toolkit/components/telemetry/tests/unit/

Categories

(Toolkit :: Telemetry, defect, P5)

defect

Tracking

()

RESOLVED FIXED
mozilla67
Tracking Status
firefox67 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: froydnj)

References

Details

Attachments

(1 file)

TEST-UNEXPECTED-FAIL | toolkit/components/telemetry/tests/unit/test_ModulesPing.js | xpcshell return code: 0

18:11:48  WARNING -  TEST-UNEXPECTED-FAIL | toolkit/components/telemetry/tests/unit/test_ModulesPing.js | xpcshell return code: 0
18:11:48     INFO -  TEST-INFO took 317ms
18:11:48     INFO -  >>>>>>>
18:11:48     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
18:11:48     INFO -  (xpcshell/head.js) | test run_next_test 0 pending (2)
18:11:48     INFO -  (xpcshell/head.js) | test MAIN run_test finished (2)
18:11:48     INFO -  running event loop
18:11:48     INFO -  toolkit/components/telemetry/tests/unit/test_ModulesPing.js | Starting setup
18:11:48     INFO -  (xpcshell/head.js) | test setup pending (2)
18:11:48     INFO -  (xpcshell/head.js) | test run_next_test 0 finished (2)
18:11:48     INFO -  Unexpected exception Error: couldn't open library C:\\tasks\\task_1549389559\\build\\tests\\xpcshell\\tests\\toolkit\\components\\telemetry\\tests\\unit\\testUnicodePDB64.dll: error 193 at C:/tasks/task_1549389559/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_ModulesPing.js:114
18:11:48     INFO -  setup@C:/tasks/task_1549389559/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_ModulesPing.js:114:29
18:11:48     INFO -  async*run_next_test/_run_next_test/<@C:\tasks\task_1549389559\build\tests\xpcshell\head.js:1435:22
18:11:48     INFO -  async*_run_next_test@C:\tasks\task_1549389559\build\tests\xpcshell\head.js:1435:10
18:11:48     INFO -  run@C:\tasks\task_1549389559\build\tests\xpcshell\head.js:686:9
18:11:48     INFO -  _do_main@C:\tasks\task_1549389559\build\tests\xpcshell\head.js:224:3
18:11:48     INFO -  _execute_test@C:\tasks\task_1549389559\build\tests\xpcshell\head.js:527:5
18:11:48     INFO -  @-e:1:1
18:11:48     INFO -  exiting test
18:11:48     INFO -  TypeError: this._httpServer is null at C:/tasks/task_1549389559/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/head.js:89
18:11:48     INFO -  stop/<@C:/tasks/task_1549389559/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/head.js:89:7
18:11:48     INFO -  stop@C:/tasks/task_1549389559/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/head.js:88:12
18:11:48     INFO -  @C:/tasks/task_1549389559/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_ModulesPing.js:148:15
18:11:48     INFO -  _execute_test@C:\tasks\task_1549389559\build\tests\xpcshell\head.js:601:3
18:11:48     INFO -  @-e:1:1
18:11:48     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "1549390308068	Toolkit.Telemetry	ERROR	TelemetrySend::shutdown - failed to remove observer for idle-daily: [Exception... "Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver]"  nsresult: "0x80004005 (NS_ERROR_FAILURE)"  location: "JS frame :: resource://gre/modules/TelemetrySend.jsm :: shutdown :: line 744"  data: no] Stack trace: shutdown()@resource://gre/modules/TelemetrySend.jsm:744" {file: "resource://gre/modules/Log.jsm" line: 679}]
18:11:48     INFO -  append@resource://gre/modules/Log.jsm:679:9
18:11:48     INFO -  log@resource://gre/modules/Log.jsm:360:7
18:11:48     INFO -  getLoggerWithMessagePrefix/proxy.log@resource://gre/modules/Log.jsm:484:14
18:11:48     INFO -  error@resource://gre/modules/Log.jsm:368:5
18:11:48     INFO -  shutdown@resource://gre/modules/TelemetrySend.jsm:746:9
18:11:48     INFO -  async*shutdown@resource://gre/modules/TelemetrySend.jsm:200:12
18:11:48     INFO -  @C:/tasks/task_1549389559/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/head.js:393:33
18:11:48     INFO -  _execute_test/<@C:\\tasks\\task_1549389559\\build\\tests\\xpcshell\\head.js:591:28
18:11:48     INFO -  async*_execute_test@C:\\tasks\\task_1549389559\\build\\tests\\xpcshell\\head.js:588:4
18:11:48     INFO -  @-e:1:1
18:11:48     INFO -  "
18:11:48     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "1549390308069	Toolkit.Telemetry	ERROR	TelemetrySend::shutdown - failed to remove observer for quit-application-granted: [Exception... "Component returned failure code: 0x80070057 (NS_ERROR_ILLEGAL_VALUE) [nsIObserverService.removeObserver]"  nsresult: "0x80070057 (NS_ERROR_ILLEGAL_VALUE)"  location: "JS frame :: resource://gre/modules/TelemetrySend.jsm :: shutdown :: line 744"  data: no] Stack trace: shutdown()@resource://gre/modules/TelemetrySend.jsm:744" {file: "resource://gre/modules/Log.jsm" line: 679}]
18:11:48     INFO -  append@resource://gre/modules/Log.jsm:679:9
18:11:48     INFO -  log@resource://gre/modules/Log.jsm:360:7
18:11:48     INFO -  getLoggerWithMessagePrefix/proxy.log@resource://gre/modules/Log.jsm:484:14
18:11:48     INFO -  error@resource://gre/modules/Log.jsm:368:5
18:11:48     INFO -  shutdown@resource://gre/modules/TelemetrySend.jsm:746:9
18:11:48     INFO -  async*shutdown@resource://gre/modules/TelemetrySend.jsm:200:12
18:11:48     INFO -  @C:/tasks/task_1549389559/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/head.js:393:33
18:11:48     INFO -  _execute_test/<@C:\\tasks\\task_1549389559\\build\\tests\\xpcshell\\head.js:591:28
18:11:48     INFO -  async*_execute_test@C:\\tasks\\task_1549389559\\build\\tests\\xpcshell\\head.js:588:4
18:11:48     INFO -  @-e:1:1
18:11:48     INFO -  "
18:11:48     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "1549390308069	Toolkit.Telemetry	ERROR	TelemetrySend::shutdown - failed to remove observer for quit-application-forced: [Exception... "Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver]"  nsresult: "0x80004005 (NS_ERROR_FAILURE)"  location: "JS frame :: resource://gre/modules/TelemetrySend.jsm :: shutdown :: line 744"  data: no] Stack trace: shutdown()@resource://gre/modules/TelemetrySend.jsm:744" {file: "resource://gre/modules/Log.jsm" line: 679}]
18:11:48     INFO -  append@resource://gre/modules/Log.jsm:679:9
18:11:48     INFO -  log@resource://gre/modules/Log.jsm:360:7
18:11:48     INFO -  getLoggerWithMessagePrefix/proxy.log@resource://gre/modules/Log.jsm:484:14
18:11:48     INFO -  error@resource://gre/modules/Log.jsm:368:5
18:11:48     INFO -  shutdown@resource://gre/modules/TelemetrySend.jsm:746:9
18:11:48     INFO -  async*shutdown@resource://gre/modules/TelemetrySend.jsm:200:12
18:11:48     INFO -  @C:/tasks/task_1549389559/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/head.js:393:33
18:11:48     INFO -  _execute_test/<@C:\\tasks\\task_1549389559\\build\\tests\\xpcshell\\head.js:591:28
18:11:48     INFO -  async*_execute_test@C:\\tasks\\task_1549389559\\build\\tests\\xpcshell\\head.js:588:4
18:11:48     INFO -  @-e:1:1
18:11:48     INFO -  "
18:11:48     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "1549390308070	Toolkit.Telemetry	ERROR	TelemetrySend::shutdown - failed to remove observer for profile-change-net-teardown: [Exception... "Component returned failure code: 0x80070057 (NS_ERROR_ILLEGAL_VALUE) [nsIObserverService.removeObserver]"  nsresult: "0x80070057 (NS_ERROR_ILLEGAL_VALUE)"  location: "JS frame :: resource://gre/modules/TelemetrySend.jsm :: shutdown :: line 744"  data: no] Stack trace: shutdown()@resource://gre/modules/TelemetrySend.jsm:744" {file: "resource://gre/modules/Log.jsm" line: 679}]
18:11:48     INFO -  append@resource://gre/modules/Log.jsm:679:9
18:11:48     INFO -  log@resource://gre/modules/Log.jsm:360:7
18:11:48     INFO -  getLoggerWithMessagePrefix/proxy.log@resource://gre/modules/Log.jsm:484:14
18:11:48     INFO -  error@resource://gre/modules/Log.jsm:368:5
18:11:48     INFO -  shutdown@resource://gre/modules/TelemetrySend.jsm:746:9
18:11:48     INFO -  async*shutdown@resource://gre/modules/TelemetrySend.jsm:200:12
18:11:48     INFO -  @C:/tasks/task_1549389559/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/head.js:393:33
18:11:48     INFO -  _execute_test/<@C:\\tasks\\task_1549389559\\build\\tests\\xpcshell\\head.js:591:28
18:11:48     INFO -  async*_execute_test@C:\\tasks\\task_1549389559\\build\\tests\\xpcshell\\head.js:588:4
18:11:48     INFO -  @-e:1:1
18:11:48     INFO -  "
18:11:48     INFO -  "CONSOLE_MESSAGE: (info) 1549390308071	Toolkit.Telemetry	TRACE	TelemetrySend::Scheduler::shutdown"
18:11:48     INFO -  "CONSOLE_MESSAGE: (info) 1549390308071	Toolkit.Telemetry	TRACE	TelemetrySend::promisePendingPingActivity - Waiting for ping task"
18:11:48     INFO -  <<<<<<<
Summary: Intermittent toolkit/components/telemetry/tests/unit/test_ModulesPing.js | xpcshell return code: 0 → Intermittent failures in toolkit/components/telemetry/tests/unit/

TEST-UNEXPECTED-FAIL | toolkit/components/telemetry/tests/unit/test_UntrustedModulesPing.js | xpcshell return code: 0

18:11:48  WARNING -  TEST-UNEXPECTED-FAIL | toolkit/components/telemetry/tests/unit/test_UntrustedModulesPing.js | xpcshell return code: 0
18:11:48     INFO -  TEST-INFO took 738ms
18:11:48     INFO -  >>>>>>>
18:11:48     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
18:11:48     INFO -  (xpcshell/head.js) | test run_next_test 0 pending (2)
18:11:48     INFO -  (xpcshell/head.js) | test MAIN run_test finished (2)
18:11:48     INFO -  running event loop
18:11:48     INFO -  toolkit/components/telemetry/tests/unit/test_UntrustedModulesPing.js | Starting setup
18:11:48     INFO -  (xpcshell/head.js) | test setup pending (2)
18:11:48     INFO -  (xpcshell/head.js) | test run_next_test 0 finished (2)
18:11:48     INFO -  "CONSOLE_MESSAGE: (info) 1549390308398	Toolkit.Telemetry	TRACE	TelemetryController::setupTelemetry"
18:11:48     INFO -  "CONSOLE_MESSAGE: (info) 1549390308398	Toolkit.Telemetry	TRACE	TelemetryController::registerJsProbes - registering builtin JS probes"
18:11:48     INFO -  "CONSOLE_MESSAGE: (info) 1549390308398	Toolkit.Telemetry	TRACE	TelemetryController::registerScalarProbes - registering scalar builtin JS probes"
18:11:48     INFO -  "CONSOLE_MESSAGE: (info) 1549390308398	Toolkit.Telemetry	TRACE	TelemetryController::loadProbeDefinitions - no builtin JS probe file ScalarArtifactDefinitions.json"
18:11:48     INFO -  "CONSOLE_MESSAGE: (info) 1549390308400	Toolkit.Telemetry	TRACE	TelemetryReportingPolicy::setup"
18:11:48     INFO -  "CONSOLE_MESSAGE: (info) 1549390308401	Toolkit.Telemetry	CONFIG	TelemetryController::enableTelemetryRecording - canRecordBase:true, canRecordExtended: true"
18:11:48     INFO -  "CONSOLE_MESSAGE: (info) 1549390308401	Toolkit.Telemetry	TRACE	TelemetrySession::earlyInit"
18:11:48     INFO -  "CONSOLE_MESSAGE: (info) 1549390308401	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
18:11:48     INFO -  "CONSOLE_MESSAGE: (info) 1549390308402	Toolkit.Telemetry	TRACE	UpdatePing::init - enabled: true"
18:11:48     INFO -  "CONSOLE_MESSAGE: (info) 1549390308403	Toolkit.Telemetry	TRACE	TelemetryController::registerEventProbes - registering builtin JS Event probes"
18:11:48     INFO -  "CONSOLE_MESSAGE: (info) 1549390308404	Toolkit.Telemetry	TRACE	TelemetryController::loadProbeDefinitions - no builtin JS probe file EventArtifactDefinitions.json"
18:11:48     INFO -  "CONSOLE_MESSAGE: (info) 1549390308427	Toolkit.Telemetry	TRACE	TelemetryEnvironment::constructor"
18:11:48     INFO -  "CONSOLE_MESSAGE: (info) 1549390308457	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_getGFXData - Two display adapters detected."
18:11:48     INFO -  "CONSOLE_MESSAGE: (info) 1549390308482	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_updateSearchEngine - ignoring early call"
18:11:48     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "1549390308488	Toolkit.Telemetry	ERROR	TelemetryEnvironment::EnvironmentCache - error while initializing: TypeError: gShutdownBarrier is null(resource://gre/modules/AddonManager.jsm:3491:5) JS Stack trace: get shutdown@AddonManager.jsm:3491:5
18:11:48     INFO -  init@TelemetryEnvironment.jsm:565:7
18:11:48     INFO -  EnvironmentCache@TelemetryEnvironment.jsm:958:10
18:11:48     INFO -  getGlobal@TelemetryEnvironment.jsm:76:26
18:11:48     INFO -  delayedInit@TelemetryEnvironment.jsm:91:12
18:11:48     INFO -  setupTelemetry/this._delayedInitTask<@TelemetryController.jsm:667:9
18:11:49     INFO -  async*_runTask@DeferredTask.jsm:306:15
18:11:49     INFO -  async*_timerCallback/<@DeferredTask.jsm:276:13
18:11:49     INFO -  async*_timerCallback@DeferredTask.jsm:274:30
18:11:49     INFO -  _do_main@C:\\tasks\\task_1549389559\\build\\tests\\xpcshell\\head.js:224:3
18:11:49     INFO -  _execute_test@C:\\tasks\\task_1549389559\\build\\tests\\xpcshell\\head.js:527:5
18:11:49     INFO -  @-e:1:1" {file: "resource://gre/modules/Log.jsm" line: 679}]
18:11:49     INFO -  append@resource://gre/modules/Log.jsm:679:9
18:11:49     INFO -  log@resource://gre/modules/Log.jsm:360:7
18:11:49     INFO -  getLoggerWithMessagePrefix/proxy.log@resource://gre/modules/Log.jsm:484:14
18:11:49     INFO -  error@resource://gre/modules/Log.jsm:368:5
18:11:49     INFO -  EnvironmentCache/this._initTask<@resource://gre/modules/TelemetryEnvironment.jsm:986:9
18:11:49     INFO -  _do_main@C:\\tasks\\task_1549389559\\build\\tests\\xpcshell\\head.js:224:3
18:11:49     INFO -  _execute_test@C:\\tasks\\task_1549389559\\build\\tests\\xpcshell\\head.js:527:5
18:11:49     INFO -  @-e:1:1
18:11:49     INFO -  "
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308489	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_startWatchingPrefs - [object Map]"
18:11:49     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "UpdateUtils.getAppUpdateAutoEnabled - Unable to read app update configuration file. Exception: [Exception... "Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIProperties.get]"  nsresult: "0x80004005 (NS_ERROR_FAILURE)"  location: "JS frame :: resource://gre/modules/FileUtils.jsm :: FileUtils_getDir :: line 60"  data: no]" {file: "resource://gre/modules/UpdateUtils.jsm" line: 180}]
18:11:49     INFO -  getAppUpdateAutoEnabled/readPromise<@resource://gre/modules/UpdateUtils.jsm:180:9
18:11:49     INFO -  async*_do_main@C:\\tasks\\task_1549389559\\build\\tests\\xpcshell\\head.js:224:3
18:11:49     INFO -  _execute_test@C:\\tasks\\task_1549389559\\build\\tests\\xpcshell\\head.js:527:5
18:11:49     INFO -  @-e:1:1
18:11:49     INFO -  "
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308490	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: app.update.auto.migrated"
18:11:49     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "UpdateUtils.getAppUpdateAutoEnabled - Migration failed. Exception: [Exception... "Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIProperties.get]"  nsresult: "0x80004005 (NS_ERROR_FAILURE)"  location: "JS frame :: resource://gre/modules/FileUtils.jsm :: FileUtils_getDir :: line 60"  data: no]" {file: "resource://gre/modules/UpdateUtils.jsm" line: 194}]
18:11:49     INFO -  getAppUpdateAutoEnabled/readPromise<@resource://gre/modules/UpdateUtils.jsm:194:13
18:11:49     INFO -  async*_do_main@C:\\tasks\\task_1549389559\\build\\tests\\xpcshell\\head.js:224:3
18:11:49     INFO -  _execute_test@C:\\tasks\\task_1549389559\\build\\tests\\xpcshell\\head.js:527:5
18:11:49     INFO -  @-e:1:1
18:11:49     INFO -  "
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308496	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: toolkit.telemetry.cachedClientID"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308553	Toolkit.Telemetry	TRACE	TelemetrySend::setup"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308554	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308559	Toolkit.Telemetry	TRACE	TelemetryStorage::_scanPendingPings"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308559	Toolkit.Telemetry	TRACE	TelemetryStorage::_migrateAppDataPings"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308559	Toolkit.Telemetry	TRACE	TelemetryStorage::_iterateAppDataPings"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308559	Toolkit.Telemetry	TRACE	TelemetryStorage::_iterateAppDataPings - userApplicationDataDir is not defined. Is this a test?"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308569	Toolkit.Telemetry	INFO	TelemetrySend::_checkPendingPings - pending ping count: 0"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308569	Toolkit.Telemetry	TRACE	TelemetrySend::_checkPendingPings - no pending pings"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308569	Toolkit.Telemetry	TRACE	TelemetryStorage::_enforcePendingPingsQuota"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308570	Toolkit.Telemetry	TRACE	TelemetrySend::Scheduler::triggerSendingPings - active send task: false, immediately: true"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308570	Toolkit.Telemetry	TRACE	TelemetrySend::Scheduler::_doSendTask iteration"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308570	Toolkit.Telemetry	TRACE	TelemetrySend::Scheduler::_doSendTask - pending: 0, current: 0"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308570	Toolkit.Telemetry	TRACE	TelemetrySend::Scheduler::_doSendTask - can send - pending: 0, current: 0"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308570	Toolkit.Telemetry	TRACE	TelemetrySend::Scheduler::_doSendTask - no pending pings, bailing out"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308570	Toolkit.Telemetry	TRACE	TelemetrySession::delayedInit"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308570	Toolkit.Telemetry	TRACE	TelemetryStorage::_popAndPerformQueuedOperation - Performing queued operation."
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308573	Toolkit.Telemetry	INFO	TelemetryStorage::_loadSessionData - can not load session data file: {"operation":"open","path":"c:\\\\users\\\\testdr~1\\\\appdata\\\\local\\\\temp\\\\xpc-profile-xrmlr4\\\\datareporting\\\\session-state.json","winLastError":2}"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308573	Toolkit.Telemetry	TRACE	TelemetryStorage::_popAndPerformQueuedOperation - Performing queued operation."
18:11:49     INFO -  (xpcshell/head.js) | test run_next_test 1 pending (2)
18:11:49     INFO -  (xpcshell/head.js) | test setup finished (2)
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308590	Toolkit.Telemetry	TRACE	TelemetryStorage::loadPingfile - unreadable ping c:\\users\\testdr~1\\appdata\\local\\temp\\xpc-profile-xrmlr4\\datareporting\\aborted-session-ping: {"operation":"open","path":"c:\\\\users\\\\testdr~1\\\\appdata\\\\local\\\\temp\\\\xpc-profile-xrmlr4\\\\datareporting\\\\aborted-session-ping","winLastError":2}"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308591	Toolkit.Telemetry	TRACE	TelemetryStorage::loadAbortedSessionPing - no such file"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308591	Toolkit.Telemetry	TRACE	TelemetryController::checkAbortedSessionPing - found aborted-session ping: false"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308591	Toolkit.Telemetry	TRACE	TelemetryEnvironment::registerChangeListener for TelemetrySession::onEnvironmentChange"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308591	Toolkit.Telemetry	TRACE	TelemetryScheduler::init"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308591	Toolkit.Telemetry	TRACE	TelemetryScheduler::_rescheduleTimeout - isUserIdle: false"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308591	Toolkit.Telemetry	TRACE	TelemetryScheduler::_rescheduleTimeout - scheduling next tick for Tue Feb 05 2019 18:16:48 GMT+0000 (Greenwich Mean Time)"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308594	Toolkit.Telemetry	TRACE	TelemetryStorage::cleanArchiveTask"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308595	Toolkit.Telemetry	TRACE	TelemetryStorage::removeFHRDatabase"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308596	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: app.update.lastUpdateTime.telemetry_modules_ping"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308598	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: app.update.lastUpdateTime.telemetry_untrustedmodules_ping"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308599	Toolkit.Telemetry	TRACE	TelemetryEventPing::::Starting up."
18:11:49     INFO -  toolkit/components/telemetry/tests/unit/test_UntrustedModulesPing.js | Starting test_send_ping
18:11:49     INFO -  (xpcshell/head.js) | test test_send_ping pending (2)
18:11:49     INFO -  (xpcshell/head.js) | test run_next_test 1 finished (2)
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308602	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: app.update.lastUpdateTime.services-settings-poll-changes"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308602	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: app.update.lastUpdateTime.addon-background-update-timer"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308603	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: app.update.lastUpdateTime.blocklist-background-update-timer"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308603	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: app.update.lastUpdateTime.search-engine-update-timer"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308603	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: app.update.lastUpdateTime.background-update-timer"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308603	Toolkit.Telemetry	TRACE	TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: app.update.lastUpdateTime.telemetry_untrustedmodules_ping"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308730	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - type: untrustedModules, aOptions: {"addClientId":true,"addEnvironment":true,"usePingSender":false}"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308730	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type untrustedModules, aOptions {"addClientId":true,"addEnvironment":true,"usePingSender":false}"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308731	Toolkit.Telemetry	TRACE	TelemetryController::submitExternalPing - ping assembled, id: d78bae5a-54c0-4cdc-b080-4237c8154d46"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308732	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - ping id: d78bae5a-54c0-4cdc-b080-4237c8154d46, options: {"usePingSender":false}"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308732	Toolkit.Telemetry	INFO	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet."
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308732	Toolkit.Telemetry	TRACE	TelemetrySend::submitPing - can send pings, trying to send now"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308732	Toolkit.Telemetry	TRACE	TelemetrySend::Scheduler::triggerSendingPings - active send task: false, immediately: true"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308732	Toolkit.Telemetry	TRACE	TelemetrySend::Scheduler::_doSendTask iteration"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308732	Toolkit.Telemetry	TRACE	TelemetrySend::Scheduler::_doSendTask - pending: 0, current: 1"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308732	Toolkit.Telemetry	TRACE	TelemetrySend::Scheduler::_doSendTask - can send - pending: 0, current: 1"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308733	Toolkit.Telemetry	TRACE	TelemetrySend::Scheduler::_doSendTask - triggering sending of 0 pings now, 0 pings waiting"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308733	Toolkit.Telemetry	TRACE	TelemetrySend::_doPing - server: http://localhost:51002, persisted: false, id: d78bae5a-54c0-4cdc-b080-4237c8154d46"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308804	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: c:\\users\\testdr~1\\appdata\\local\\temp\\xpc-profile-xrmlr4\\datareporting\\archived\\2019-02\\1549390308730.d78bae5a-54c0-4cdc-b080-4237c8154d46.untrustedModules.jsonlz4"
18:11:49     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_UntrustedModulesPing.js | test_send_ping - [test_send_ping : 1] Known clientId should never appear in a ping on the server - "c0ffeec0-ffee-c0ff-eec0-ffeec0ffeec0" != "031ab76b-2541-42b1-95c1-79fce9212047"
18:11:49     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_UntrustedModulesPing.js | test_send_ping - [test_send_ping : 73] Untrusted modules ping submitted - {"type":"untrustedModules","id":"d78bae5a-54c0-4cdc-b080-4237c8154d46","creationDate":"2019-02-05T18:11:48.730Z","version":4,"application":{"architecture":"aarch64","displayVersion":"67.0a1","xpcomAbi":"aarch64-msvc","channel":"default"},"payload":{"errorModules":0,"structVersion":1,"events":[{"threadID":366,"isStartup":true,"processUptimeMS":0,"threadName":"","modules":[{"baseAddress":"0x7ffb4dec0000","fileVersion":"67.0.0.6975","loaderName":"untrusted-startup-test-dll.dll","moduleName":"untrusted-startup-test-dll.dll","moduleTrustFlags":0}]},{"threadID":366,"isStartup":true,"processUptimeMS":0,"threadName":"","modules":[{"baseAddress":"0x7ffb49b80000","fileVersion":"67.0.0.6975","loaderName":"modules-test.dll","moduleName":"modules-test.dll","moduleTrustFlags":0}]}],"combinedStacks":{"memoryMap":[],"stacks":[[],[]]}},"clientId":"031ab76b-2541-42b1-95c1-79fce9212047","environment":{"build":{"applicationId":null,"applicationName":null,"architecture":"aarch64","buildId":null,"version":null,"vendor":null,"displayVersion":"67.0a1","platformVersion":null,"xpcomAbi":"aarch64-msvc","updaterAvailable":true},"partner":{"distributionId":null,"distributionVersion":null,"partnerId":null,"distributor":null,"distributorChannel":null,"partnerNames":[]},"system":{"memoryMB":7822,"virtualMaxMB":134217728,"cpu":{"count":8,"cores":8,"vendor":"Qualcomm Technologies Inc","family":2051,"model":7,"stepping":12,"l2cacheKB":256,"l3cacheKB":2048,"speedMHz":1613,"extensions":["hasNEON"]},"os":{"name":"Windows_NT","version":"10.0","locale":"en-US","servicePackMajor":0,"servicePackMinor":0,"windowsBuildNumber":17134,"windowsUBR":523,"installYear":2018},"hdd":{"profile":{"model":"SKhynixH28S8Q302CMR","revision":"A102"},"binary":{"model":"SKhynixH28S8Q302CMR","revision":"A102"},"system":{"model":"SKhynixH28S8Q302CMR","revision":"A102"}},"gfx":{"D2DEnabled":false,"DWriteEnabled":true,"ContentBackend":"Skia","LowEndMachine":false,"adapters":[{"description":"Qualcomm(R) Adreno(TM) 630 GPU","vendorID":"0x5143","deviceID":"0x027e","subsysID":"0000000c","RAM":0,"driver":"qcdx11arm64um850 qcdx11arm64um850 qcdx11arm64um850 qcdx12arm64um850","driverVersion":"23.18.9310.0","driverDate":"10-16-2018","GPUActive":true},{"description":"Qualcomm(R) Adreno(TM) 630 GPU","vendorID":"0x00ac","deviceID":"0x00ac","subsysID":"000000ac","RAM":0,"driver":"qcdx11arm64um850 qcdx11arm64um850 qcdx11arm64um850 qcdx12arm64um850","driverVersion":"23.18.9310.0","driverDate":"10-16-2018","GPUActive":false}],"monitors":[{"screenWidth":1920,"screenHeight":1080,"refreshRate":60,"pseudoDisplay":false}],"features":{"compositor":"none","gpuProcess":{"status":"available"},"wrQualified":{"status":"blocked"},"webrender":{"status":"opt-in"},"advancedLayers":{"status":"available"},"d3d11":{"status":"available","version":0,"warp":false,"textureSharing":false,"blacklisted":false},"d2d":{"status":"available","version":"1.1"}}},"appleModelId":null,"isWow64":false,"sec":{"antivirus":["Windows Defender Antivirus"],"antispyware":["Windows Defender Antivirus"],"firewall":null}},"settings":{"blocklistEnabled":true,"e10sEnabled":true,"e10sMultiProcesses":8,"telemetryEnabled":false,"locale":"en-US","intl":{},"update":{"channel":"default","enabled":true,"autoDownload":true},"userPrefs":{"app.update.url":"http://localhost","browser.search.widget.inNavBar":false,"toolkit.telemetry.testing.overridePreRelease":true},"sandbox":{"effectiveContentProcessLevel":0},"launcherProcessState":0,"addonCompatibilityCheckEnabled":true,"isDefaultBrowser":null},"profile":{"creationDate":17932,"firstUseDate":17932}}} == true
18:11:49     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_UntrustedModulesPing.js | test_send_ping - [test_send_ping : 74] Ping has an environment - {"build":{"applicationId":null,"applicationName":null,"architecture":"aarch64","buildId":null,"version":null,"vendor":null,"displayVersion":"67.0a1","platformVersion":null,"xpcomAbi":"aarch64-msvc","updaterAvailable":true},"partner":{"distributionId":null,"distributionVersion":null,"partnerId":null,"distributor":null,"distributorChannel":null,"partnerNames":[]},"system":{"memoryMB":7822,"virtualMaxMB":134217728,"cpu":{"count":8,"cores":8,"vendor":"Qualcomm Technologies Inc","family":2051,"model":7,"stepping":12,"l2cacheKB":256,"l3cacheKB":2048,"speedMHz":1613,"extensions":["hasNEON"]},"os":{"name":"Windows_NT","version":"10.0","locale":"en-US","servicePackMajor":0,"servicePackMinor":0,"windowsBuildNumber":17134,"windowsUBR":523,"installYear":2018},"hdd":{"profile":{"model":"SKhynixH28S8Q302CMR","revision":"A102"},"binary":{"model":"SKhynixH28S8Q302CMR","revision":"A102"},"system":{"model":"SKhynixH28S8Q302CMR","revision":"A102"}},"gfx":{"D2DEnabled":false,"DWriteEnabled":true,"ContentBackend":"Skia","LowEndMachine":false,"adapters":[{"description":"Qualcomm(R) Adreno(TM) 630 GPU","vendorID":"0x5143","deviceID":"0x027e","subsysID":"0000000c","RAM":0,"driver":"qcdx11arm64um850 qcdx11arm64um850 qcdx11arm64um850 qcdx12arm64um850","driverVersion":"23.18.9310.0","driverDate":"10-16-2018","GPUActive":true},{"description":"Qualcomm(R) Adreno(TM) 630 GPU","vendorID":"0x00ac","deviceID":"0x00ac","subsysID":"000000ac","RAM":0,"driver":"qcdx11arm64um850 qcdx11arm64um850 qcdx11arm64um850 qcdx12arm64um850","driverVersion":"23.18.9310.0","driverDate":"10-16-2018","GPUActive":false}],"monitors":[{"screenWidth":1920,"screenHeight":1080,"refreshRate":60,"pseudoDisplay":false}],"features":{"compositor":"none","gpuProcess":{"status":"available"},"wrQualified":{"status":"blocked"},"webrender":{"status":"opt-in"},"advancedLayers":{"status":"available"},"d3d11":{"status":"available","version":0,"warp":false,"textureSharing":false,"blacklisted":false},"d2d":{"status":"available","version":"1.1"}}},"appleModelId":null,"isWow64":false,"sec":{"antivirus":["Windows Defender Antivirus"],"antispyware":["Windows Defender Antivirus"],"firewall":null}},"settings":{"blocklistEnabled":true,"e10sEnabled":true,"e10sMultiProcesses":8,"telemetryEnabled":false,"locale":"en-US","intl":{},"update":{"channel":"default","enabled":true,"autoDownload":true},"userPrefs":{"app.update.url":"http://localhost","browser.search.widget.inNavBar":false,"toolkit.telemetry.testing.overridePreRelease":true},"sandbox":{"effectiveContentProcessLevel":0},"launcherProcessState":0,"addonCompatibilityCheckEnabled":true,"isDefaultBrowser":null},"profile":{"creationDate":17932,"firstUseDate":17932}} == true
18:11:49     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_UntrustedModulesPing.js | test_send_ping - [test_send_ping : 75] Ping has a client ID - true == true
18:11:49     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_UntrustedModulesPing.js | test_send_ping - [test_send_ping : 77] Version is correct - 1 == 1
18:11:49     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_UntrustedModulesPing.js | test_send_ping - [test_send_ping : 78] 'combinedStacks' array exists - {"memoryMap":[],"stacks":[[],[]]} == true
18:11:49     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_UntrustedModulesPing.js | test_send_ping - [test_send_ping : 79] 'events' array exists - [{"threadID":366,"isStartup":true,"processUptimeMS":0,"threadName":"","modules":[{"baseAddress":"0x7ffb4dec0000","fileVersion":"67.0.0.6975","loaderName":"untrusted-startup-test-dll.dll","moduleName":"untrusted-startup-test-dll.dll","moduleTrustFlags":0}]},{"threadID":366,"isStartup":true,"processUptimeMS":0,"threadName":"","modules":[{"baseAddress":"0x7ffb49b80000","fileVersion":"67.0.0.6975","loaderName":"modules-test.dll","moduleName":"modules-test.dll","moduleTrustFlags":0}]}] == true
18:11:49     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_UntrustedModulesPing.js | test_send_ping - [test_send_ping : 80] combinedStacks.length == events.length - 2 == 2
18:11:49     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_UntrustedModulesPing.js | test_send_ping - [test_send_ping : 85] 'modules' array exists - [{"baseAddress":"0x7ffb4dec0000","fileVersion":"67.0.0.6975","loaderName":"untrusted-startup-test-dll.dll","moduleName":"untrusted-startup-test-dll.dll","moduleTrustFlags":0}] == true
18:11:49     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_UntrustedModulesPing.js | test_send_ping - [test_send_ping : 87] Module contains moduleName: untrusted-startup-test-dll.dll - true == true
18:11:49     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_UntrustedModulesPing.js | test_send_ping - [test_send_ping : 89] Module contains moduleTrustFlags: 0 - true == true
18:11:49     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_UntrustedModulesPing.js | test_send_ping - [test_send_ping : 91] Module contains baseAddress - true == true
18:11:49     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_UntrustedModulesPing.js | test_send_ping - [test_send_ping : 93] Module contains loaderName - true == true
18:11:49     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_UntrustedModulesPing.js | test_send_ping - [test_send_ping : 98] isStartup == expected for module: untrusted-startup-test-dll.dll - true == true
18:11:49     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_UntrustedModulesPing.js | test_send_ping - [test_send_ping : 85] 'modules' array exists - [{"baseAddress":"0x7ffb49b80000","fileVersion":"67.0.0.6975","loaderName":"modules-test.dll","moduleName":"modules-test.dll","moduleTrustFlags":0}] == true
18:11:49     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_UntrustedModulesPing.js | test_send_ping - [test_send_ping : 87] Module contains moduleName: modules-test.dll - true == true
18:11:49     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_UntrustedModulesPing.js | test_send_ping - [test_send_ping : 89] Module contains moduleTrustFlags: 0 - true == true
18:11:49     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_UntrustedModulesPing.js | test_send_ping - [test_send_ping : 91] Module contains baseAddress - true == true
18:11:49     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_UntrustedModulesPing.js | test_send_ping - [test_send_ping : 93] Module contains loaderName - true == true
18:11:49  WARNING -  TEST-UNEXPECTED-FAIL | toolkit/components/telemetry/tests/unit/test_UntrustedModulesPing.js | test_send_ping - [test_send_ping : 98] isStartup == expected for module: modules-test.dll - false == true
18:11:49     INFO -  C:/tasks/task_1549389559/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_UntrustedModulesPing.js:test_send_ping:98
18:11:49     INFO -  exiting test
18:11:49     INFO -  Unexpected exception NS_ERROR_ABORT:
18:11:49     INFO -  _abort_failed_test@C:\tasks\task_1549389559\build\tests\xpcshell\head.js:740:9
18:11:49     INFO -  do_report_result@C:\tasks\task_1549389559\build\tests\xpcshell\head.js:847:5
18:11:49     INFO -  Assert<@C:\tasks\task_1549389559\build\tests\xpcshell\head.js:54:5
18:11:49     INFO -  proto.report@resource://testing-common/Assert.jsm:213:5
18:11:49     INFO -  equal@resource://testing-common/Assert.jsm:249:3
18:11:49     INFO -  test_send_ping@C:/tasks/task_1549389559/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_UntrustedModulesPing.js:98:11
18:11:49     INFO -  async*run_next_test/_run_next_test/<@C:\tasks\task_1549389559\build\tests\xpcshell\head.js:1435:22
18:11:49     INFO -  async*_run_next_test@C:\tasks\task_1549389559\build\tests\xpcshell\head.js:1435:10
18:11:49     INFO -  run@C:\tasks\task_1549389559\build\tests\xpcshell\head.js:686:9
18:11:49     INFO -  _do_main@C:\tasks\task_1549389559\build\tests\xpcshell\head.js:224:3
18:11:49     INFO -  _execute_test@C:\tasks\task_1549389559\build\tests\xpcshell\head.js:527:5
18:11:49     INFO -  @-e:1:1
18:11:49     INFO -  exiting test
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308812	Toolkit.Telemetry	TRACE	PingServer::defaultPingHandler() - POST http://localhost:51002/submit/telemetry/d78bae5a-54c0-4cdc-b080-4237c8154d46/untrustedModules///default/"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308849	Toolkit.Telemetry	INFO	TelemetrySend::_doPing - successfully loaded, status: 200"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308849	Toolkit.Telemetry	TRACE	TelemetrySend::_onPingRequestFinished - success: true, persisted: false"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308850	Toolkit.Telemetry	TRACE	TelemetrySend::Scheduler::_doSendTask - bailing out after sending, shutdown: false, pendingPingCount: 0"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308855	Toolkit.Telemetry	TRACE	TelemetrySend::Scheduler::shutdown"
18:11:49     INFO -  "CONSOLE_MESSAGE: (info) 1549390308855	Toolkit.Telemetry	TRACE	TelemetrySend::promisePendingPingActivity - Waiting for ping task"
18:11:49     INFO -  PID 12252 | [GPU 3032, Chrome_ChildThread] WAR
18:11:49     INFO -  PID 12252 | ###!!! [Child][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
18:11:49     INFO -  PID 12252 | NING: pipe error: 109: file z:/
18:11:49     INFO -  <<<<<<<
Flags: needinfo?(ccorcoran)

I see:
Unexpected exception Error: couldn't open library C:\tasks\task_1549389559\build\tests\xpcshell\tests\toolkit\components\telemetry\tests\unit\testUnicodePDB64.dll: error 193 at C:/tasks/task_1549389559/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_ModulesPing.js:114
18:11:48 INFO - setup@C:/tasks/task_1549389559/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_ModulesPing.js:114:29
18:11:48 INFO - asyncrun_next_test/_run_next_test/<@C:\tasks\task_1549389559\build\tests\xpcshell\head.js:1435:22
18:11:48 INFO - async
_run_next_test@C:\tasks\task_1549389559\build\tests\xpcshell\head.js:1435:10
18:11:48 INFO - run@C:\tasks\task_1549389559\build\tests\xpcshell\head.js:686:9
18:11:48 INFO - _do_main@C:\tasks\task_1549389559\build\tests\xpcshell\head.js:224:3
18:11:48 INFO - _execute_test@C:\tasks\task_1549389559\build\tests\xpcshell\head.js:527:5

looking at this code, we are trying to load a .dll:
https://searchfox.org/mozilla-central/source/toolkit/components/telemetry/tests/unit/test_ModulesPing.js#18

const libUnicodePDB = Services.appinfo.is64Bit ? "testUnicodePDB64.dll" : "testUnicodePDB32.dll";

given that this is arm64, we have a 64bit OS, but cannot load i686/amd64 binaries.

As for the other related telemetry failures, they seem to use ctypes as well to load specific .dll files.

:dexter, do you have thoughts on this?

Flags: needinfo?(alessio.placitelli)
Summary: Intermittent failures in toolkit/components/telemetry/tests/unit/ → windows/aarch64 - failures in toolkit/components/telemetry/tests/unit/

:dexter, do you have thoughts on this?

Marco, the author of the test, might have! Flagging him :)

Flags: needinfo?(alessio.placitelli) → needinfo?(mcastelluccio)

The relevant failure is:

18:11:48 INFO - Unexpected exception Error: couldn't open library C:\tasks\task_1549389559\build\tests\xpcshell\tests\toolkit\components\telemetry\tests\unit\testUnicodePDB64.dll: error 193 at C:/tasks/task_1549389559/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_ModulesPing.js:114

This is because that DLL, and testNoPDB64.dll, were compiled for x64 and not aarch64.

There are a few options:

  1. compile the DLL for aarch too, add it to the tree alongside the other two DLLs, and use them in the test when we're on aarch64 (instructions at https://searchfox.org/mozilla-central/rev/5e3bffe964110b8d1885b4236b8abd5c94d8f609/toolkit/components/telemetry/tests/modules-test.cpp).
  2. make the test not use those two libraries when on aarch64.
Flags: needinfo?(mcastelluccio)

it seems we should be compiling all source files for aarch64 when testing builds and test packages from aarch64- :froydnj, do you know why we might not be building testNoPDB64.dll in aarch64?

Flags: needinfo?(nfroyd)

(In reply to Joel Maher ( :jmaher ) (UTC-4) from comment #7)

it seems we should be compiling all source files for aarch64 when testing builds and test packages from aarch64- :froydnj, do you know why we might not be building testNoPDB64.dll in aarch64?

AFAICT testNoPDB64.dll is checked into the tree, so there's no build step involved. Likewise for testUnicodePDB64.dll.

I don't know how difficult it would be to generate those files at build time, rather than offline. It looks like they both want to be compiled in very specific ways, and it might be difficult to convince the build system to compile them in that exact way, rather than however the build system wants to compile libraries for Firefox generally.

Flags: needinfo?(nfroyd)

At the time when we introduced the test, it was very painful to compile them at build time (especially the unicode one, because the build system wasn't great at handling files with unicode names), so I was suggested to just compile them on my machine and check them in.

We can just do the same for aarch64, if somebody has a working aarch64 development environment and can quickly build those two DLLs.

from what I can tell on searchfox, there are only 4 test specific dll's which happen to be what we are talking about here:
https://searchfox.org/mozilla-central/search?q=&path=*.dll

Assuming we have aarch64 versions, we will then need to edit the test to look at the environment variable: PROCESSOR_ARCHITEW6432, and load different .dll files if the value == 'ARM64'.

I will attempt to compile aarch64 versions and modify the test. Is it reasonable for somebody else to apply the patches to test, though, since I don't have a test environment set up?

Compiling the files seems to be pretty straightforward, but the resulting .dlls are an order of magnitude larger than the .dlls checked into the tree (the aarch64 nopdb one is ~90k and an x86-64 test is 100k, compared to the in-tree size of ~10k); are you sure the dlls didn't get stripped or something before getting checked in?

Flags: needinfo?(mcastelluccio)

:egao, can you test this when :froydnj gets a patch put together to fix this?

Flags: needinfo?(egao)

(In reply to Nathan Froyd [:froydnj] from comment #12)

Compiling the files seems to be pretty straightforward, but the resulting .dlls are an order of magnitude larger than the .dlls checked into the tree (the aarch64 nopdb one is ~90k and an x86-64 test is 100k, compared to the in-tree size of ~10k); are you sure the dlls didn't get stripped or something before getting checked in?

I don't remember unfortunately, maybe try using "/Os" or other options which might reduce their size. You can really do anything as long as the DLLs keep being loadable and as long as the unicode one has a PDB and the noPDB one doesn't have a PDB.

Flags: needinfo?(mcastelluccio)
This test wasn't accounting for the existence of aarch64 windows, and was trying to load x86-64 DLLs on aarch64, which wouldn't end very well. Compile appropriate DLLs, modify the compilation instructions, and add these new files to the test so everything works out.
Attachment #9045442 - Flags: review?(mcastelluccio)
Attachment #9045442 - Flags: review?(mcastelluccio) → review+

There is also another utility function to get the processor architecture at https://searchfox.org/mozilla-central/rev/4587d146681b16ff9878a6fdcba53b04f76abe1d/toolkit/modules/tests/xpcshell/test_UpdateUtils_url.js#81.

Maybe we should have only one and put it in a common place so it's accessible by all tests. Not needed for fixing this bug, of course.

Pushed by nfroyd@mozilla.com: https://hg.mozilla.org/integration/mozilla-inbound/rev/3f00b31e09d4 add aarch64 files for test_ModulesPing.js; r=marco
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla67
Assignee: nobody → nfroyd

Try run: https://treeherder.mozilla.org/#/jobs?repo=try&revision=c0abb56001522773bc87748f6042efc97dc45797&selectedJob=230585094

Log: https://taskcluster-artifacts.net/IMvnjdRqR9-sTC7FQ1FP1Q/0/public/logs/live_backing.log

Using mozilla-central codebase from 2/25, unknown timestamp, most issues within toolkit/components/telemetry/tests/unit/ have been resolved.

There continues to be one TEST-UNEXPECTED-FAIL in toolkit/components/telemetry/tests/unit/test_ModulesPing.js but that will be in a separate bug related to the parent of this bug, 1524114.

Flags: needinfo?(egao)
Flags: needinfo?(ccorcoran)
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: