1822913 - Intermittent toolkit/components/telemetry/tests/unit/test_PingSender.js | single tracking bug

Status: RESOLVED INCOMPLETE

(Toolkit :: Telemetry, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2023-03-16T20:22:25.606Z] 20:22:25     INFO -  TEST-START | toolkit/components/telemetry/tests/unit/test_PingSender.js
[task 2023-03-16T20:22:27.069Z] 20:22:27  WARNING -  TEST-UNEXPECTED-FAIL | toolkit/components/telemetry/tests/unit/test_PingSender.js | xpcshell return code: 0
[task 2023-03-16T20:22:27.070Z] 20:22:27     INFO -  TEST-INFO took 1463ms
[task 2023-03-16T20:22:27.070Z] 20:22:27     INFO -  >>>>>>>
[task 2023-03-16T20:22:27.071Z] 20:22:27     INFO -  PID 7832 | DLL blocklist was unable to intercept AppInit DLLs.
[task 2023-03-16T20:22:27.071Z] 20:22:27     INFO -  PID 7832 | [Parent 7832, Main Thread] WARNING: Failed to get directory to cache.: file /builds/worker/checkouts/gecko/security/sandbox/win/src/sandboxbroker/sandboxBroker.cpp:131
[task 2023-03-16T20:22:27.072Z] 20:22:27     INFO -  PID 7832 | [Parent 7832, Main Thread] WARNING: Failed to get directory to cache.: file /builds/worker/checkouts/gecko/security/sandbox/win/src/sandboxbroker/sandboxBroker.cpp:131
[task 2023-03-16T20:22:27.072Z] 20:22:27     INFO -  PID 7832 | [Parent 7832, Main Thread] WARNING: Couldn't get the user appdata directory. Crash events may not be produced.: file /builds/worker/checkouts/gecko/toolkit/crashreporter/nsExceptionHandler.cpp:2908
[task 2023-03-16T20:22:27.072Z] 20:22:27     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2023-03-16T20:22:27.072Z] 20:22:27     INFO -  (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2023-03-16T20:22:27.072Z] 20:22:27     INFO -  (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2023-03-16T20:22:27.073Z] 20:22:27     INFO -  running event loop
[task 2023-03-16T20:22:27.073Z] 20:22:27     INFO -  toolkit/components/telemetry/tests/unit/test_PingSender.js | Starting setup
[task 2023-03-16T20:22:27.073Z] 20:22:27     INFO -  (xpcshell/head.js) | test setup pending (2)
[task 2023-03-16T20:22:27.073Z] 20:22:27     INFO -  (xpcshell/head.js) | test run_next_test 0 finished (2)
[task 2023-03-16T20:22:27.074Z] 20:22:27     INFO -  (xpcshell/head.js) | test run_next_test 1 pending (2)
[task 2023-03-16T20:22:27.074Z] 20:22:27     INFO -  (xpcshell/head.js) | test setup finished (2)
[task 2023-03-16T20:22:27.074Z] 20:22:27     INFO -  toolkit/components/telemetry/tests/unit/test_PingSender.js | Starting test_pingsender1
[task 2023-03-16T20:22:27.074Z] 20:22:27     INFO -  (xpcshell/head.js) | test test_pingsender1 pending (2)
[task 2023-03-16T20:22:27.075Z] 20:22:27     INFO -  (xpcshell/head.js) | test run_next_test 1 finished (2)
[task 2023-03-16T20:22:27.075Z] 20:22:27     INFO -  "CONSOLE_MESSAGE: (info) 1678998145879	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: C:\\Users\\task_167899092841212\\AppData\\Local\\Temp\\xpc-profile-x3n2wtpa\\saved-telemetry-pings\\b57b366b-a867-4752-af92-6a670ae77fb2"
[task 2023-03-16T20:22:27.075Z] 20:22:27     INFO -  "CONSOLE_MESSAGE: (info) 1678998145907	Toolkit.Telemetry	INFO	TelemetrySend::Invoking 'pingsender.exe ...'"
[task 2023-03-16T20:22:27.075Z] 20:22:27     INFO -  "CONSOLE_MESSAGE: (info) 1678998145911	Toolkit.Telemetry	INFO	TelemetrySend::Invoking 'pingsender.exe ...'"
[task 2023-03-16T20:22:27.076Z] 20:22:27     INFO -  PID 7832 | ERROR: Error submitting the HTTP request: code 404
[task 2023-03-16T20:22:27.076Z] 20:22:27     INFO -  PID 7832 | ERROR: Error submitting the HTTP request: code 404
[task 2023-03-16T20:22:27.076Z] 20:22:27     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_PingSender.js | test_pingsender1 - [test_pingsender1 : 123] The pending ping must not be deleted if we fail to send using the PingSender - true == true
[task 2023-03-16T20:22:27.077Z] 20:22:27     INFO -  "CONSOLE_MESSAGE: (info) 1678998145959	Toolkit.Telemetry	INFO	TelemetrySend::Invoking 'pingsender.exe ...'"
[task 2023-03-16T20:22:27.077Z] 20:22:27     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_PingSender.js | test_pingsender1 - [test_pingsender1 : 134] Should have received the correct user agent string. - "pingsender/1.0" == "pingsender/1.0"
[task 2023-03-16T20:22:27.078Z] 20:22:27     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_PingSender.js | test_pingsender1 - [test_pingsender1 : 139] Should have received the correct PingSender version string. - "1.0" == "1.0"
[task 2023-03-16T20:22:27.078Z] 20:22:27     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_PingSender.js | test_pingsender1 - [test_pingsender1 : 144] Should have a gzip encoded ping. - "gzip" == "gzip"
[task 2023-03-16T20:22:27.078Z] 20:22:27     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_PingSender.js | test_pingsender1 - [test_pingsender1 : 149] Should have received a Date header. - "Thu, 16 Mar 2023 20:22:25 GMT" == true
[task 2023-03-16T20:22:27.079Z] 20:22:27     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_PingSender.js | test_pingsender1 - [test_pingsender1 : 150] Should have received the correct ping id. - "b57b366b-a867-4752-af92-6a670ae77fb2" == "b57b366b-a867-4752-af92-6a670ae77fb2"
[task 2023-03-16T20:22:27.079Z] 20:22:27     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_PingSender.js | test_pingsender1 - [test_pingsender1 : 151] Should have received the correct ping type. - "test-pingsender-type" == "test-pingsender-type"
[task 2023-03-16T20:22:27.080Z] 20:22:27     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_PingSender.js | test_pingsender1 - [test_pingsender1 : 156] Should have received the correct payload. - {"dummy":"stuff"} deepEqual {"dummy":"stuff"}
[task 2023-03-16T20:22:27.080Z] 20:22:27     INFO -  "CONSOLE_MESSAGE: (info) 1678998145996	Toolkit.Telemetry	TRACE	PingServer::defaultPingHandler() - POST http://localhost:58578/submit/telemetry/"
[task 2023-03-16T20:22:27.080Z] 20:22:27     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_PingSender.js | test_pingsender1 - [test_pingsender1 : 49] Pingsender should be able to post to localhost - true == true
[task 2023-03-16T20:22:27.080Z] 20:22:27     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_PingSender.js | test_pingsender1 - [test_pingsender1 : 68] b57b366b-a867-4752-af92-6a670ae77fb2 was deleted - true == true
[task 2023-03-16T20:22:27.081Z] 20:22:27     INFO -  (xpcshell/head.js) | test run_next_test 2 pending (2)
[task 2023-03-16T20:22:27.081Z] 20:22:27     INFO -  (xpcshell/head.js) | test test_pingsender1 finished (2)
[task 2023-03-16T20:22:27.081Z] 20:22:27     INFO -  toolkit/components/telemetry/tests/unit/test_PingSender.js | Starting test_pingsender2
[task 2023-03-16T20:22:27.081Z] 20:22:27     INFO -  (xpcshell/head.js) | test test_pingsender2 pending (2)
[task 2023-03-16T20:22:27.082Z] 20:22:27     INFO -  (xpcshell/head.js) | test run_next_test 2 finished (2)
[task 2023-03-16T20:22:27.082Z] 20:22:27     INFO -  "CONSOLE_MESSAGE: (info) 1678998146262	Toolkit.Telemetry	TRACE	TelemetryStorage::savePingToFile - path: C:\\Users\\task_167899092841212\\AppData\\Local\\Temp\\xpc-profile-x3n2wtpa\\saved-telemetry-pings\\0d59f517-7f2d-4592-b5a0-e64746323e9a"
[task 2023-03-16T20:22:27.082Z] 20:22:27     INFO -  "CONSOLE_MESSAGE: (info) 1678998146271	Toolkit.Telemetry	INFO	TelemetrySend::Invoking 'firefox.exe --backgroundtask pingsender ...'"
[task 2023-03-16T20:22:27.083Z] 20:22:27     INFO -  "CONSOLE_MESSAGE: (info) 1678998146274	Toolkit.Telemetry	INFO	TelemetrySend::Invoking 'firefox.exe --backgroundtask pingsender ...'"
[task 2023-03-16T20:22:27.083Z] 20:22:27     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_PingSender.js | test_pingsender2 - [test_pingsender2 : 123] The pending ping must not be deleted if we fail to send using the PingSender - true == true
[task 2023-03-16T20:22:27.083Z] 20:22:27     INFO -  "CONSOLE_MESSAGE: (info) 1678998146495	Toolkit.Telemetry	INFO	TelemetrySend::Invoking 'firefox.exe --backgroundtask pingsender ...'"
[task 2023-03-16T20:22:27.083Z] 20:22:27     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_PingSender.js | test_pingsender2 - [test_pingsender2 : 134] Should have received the correct user agent string. - "pingsender/2.0" == "pingsender/2.0"
[task 2023-03-16T20:22:27.084Z] 20:22:27     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_PingSender.js | test_pingsender2 - [test_pingsender2 : 139] Should have received the correct PingSender version string. - "2.0" == "2.0"
[task 2023-03-16T20:22:27.084Z] 20:22:27     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_PingSender.js | test_pingsender2 - [test_pingsender2 : 144] Should have a gzip encoded ping. - "gzip" == "gzip"
[task 2023-03-16T20:22:27.085Z] 20:22:27     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_PingSender.js | test_pingsender2 - [test_pingsender2 : 149] Should have received a Date header. - "Thu, 16 Mar 2023 20:22:26 GMT" == true
[task 2023-03-16T20:22:27.085Z] 20:22:27     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_PingSender.js | test_pingsender2 - [test_pingsender2 : 150] Should have received the correct ping id. - "0d59f517-7f2d-4592-b5a0-e64746323e9a" == "0d59f517-7f2d-4592-b5a0-e64746323e9a"
[task 2023-03-16T20:22:27.086Z] 20:22:27     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_PingSender.js | test_pingsender2 - [test_pingsender2 : 151] Should have received the correct ping type. - "test-pingsender-type" == "test-pingsender-type"
[task 2023-03-16T20:22:27.086Z] 20:22:27     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_PingSender.js | test_pingsender2 - [test_pingsender2 : 156] Should have received the correct payload. - {"dummy":"stuff"} deepEqual {"dummy":"stuff"}
[task 2023-03-16T20:22:27.086Z] 20:22:27     INFO -  "CONSOLE_MESSAGE: (info) 1678998146714	Toolkit.Telemetry	TRACE	PingServer::defaultPingHandler() - POST http://localhost:58578/submit/telemetry/"
[task 2023-03-16T20:22:27.087Z] 20:22:27  WARNING -  TEST-UNEXPECTED-FAIL | toolkit/components/telemetry/tests/unit/test_PingSender.js | test_pingsender2 - [test_pingsender2 : 52] Pingsender should be able to post to localhost - false == true
[task 2023-03-16T20:22:27.087Z] 20:22:27     INFO -  Z:/task_167899092841212/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_PingSender.js:testSendingPings/<:52
[task 2023-03-16T20:22:27.087Z] 20:22:27     INFO -  Z:\task_167899092841212\build\tests\xpcshell\head.js:_do_main:238
[task 2023-03-16T20:22:27.088Z] 20:22:27     INFO -  Z:\task_167899092841212\build\tests\xpcshell\head.js:_execute_test:585
[task 2023-03-16T20:22:27.088Z] 20:22:27     INFO -  -e:null:1
[task 2023-03-16T20:22:27.088Z] 20:22:27     INFO -  exiting test
[task 2023-03-16T20:22:27.088Z] 20:22:27     INFO -  PID 7832 | JavaScript error: Z:\\task_167899092841212\\build\\tests\\xpcshell\\head.js, line 863: NS_ERROR_ABORT:
[task 2023-03-16T20:22:27.088Z] 20:22:27     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "NS_ERROR_ABORT: " {file: "Z:\\task_167899092841212\\build\\tests\\xpcshell\\head.js" line: 863}]
[task 2023-03-16T20:22:27.088Z] 20:22:27     INFO -  _abort_failed_test@Z:\\task_167899092841212\\build\\tests\\xpcshell\\head.js:863:20
[task 2023-03-16T20:22:27.089Z] 20:22:27     INFO -  do_report_result@Z:\\task_167899092841212\\build\\tests\\xpcshell\\head.js:964:5
[task 2023-03-16T20:22:27.089Z] 20:22:27     INFO -  Assert<@Z:\\task_167899092841212\\build\\tests\\xpcshell\\head.js:71:21
[task 2023-03-16T20:22:27.089Z] 20:22:27     INFO -  Assert.prototype.report@resource://testing-common/Assert.sys.mjs:240:10
[task 2023-03-16T20:22:27.089Z] 20:22:27     INFO -  Assert.prototype.ok@resource://testing-common/Assert.sys.mjs:266:10
[task 2023-03-16T20:22:27.090Z] 20:22:27     INFO -  testSendingPings/<@Z:/task_167899092841212/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_PingSender.js:52:16
[task 2023-03-16T20:22:27.090Z] 20:22:27     INFO -  _do_main@Z:\\task_167899092841212\\build\\tests\\xpcshell\\head.js:238:6
[task 2023-03-16T20:22:27.090Z] 20:22:27     INFO -  _execute_test@Z:\\task_167899092841212\\build\\tests\\xpcshell\\head.js:585:5
[task 2023-03-16T20:22:27.090Z] 20:22:27     INFO -  @-e:1:1
[task 2023-03-16T20:22:27.090Z] 20:22:27     INFO -  "
[task 2023-03-16T20:22:27.091Z] 20:22:27     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "1678998146970	Toolkit.Telemetry	ERROR	TelemetrySend::shutdown - failed to remove observer for idle-daily: [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.sys.mjs :: shutdown :: line 895"  data: no] Stack trace: shutdown()@resource://gre/modules/TelemetrySend.sys.mjs:895
[task 2023-03-16T20:22:27.091Z] 20:22:27     INFO -  shutdown()@resource://gre/modules/TelemetrySend.sys.mjs:251
[task 2023-03-16T20:22:27.092Z] 20:22:27     INFO -  Z:/task_167899092841212/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/head.js:561
[task 2023-03-16T20:22:27.092Z] 20:22:27     INFO -  _execute_test/<()@Z:\\task_167899092841212\\build\\tests\\xpcshell\\head.js:649
[task 2023-03-16T20:22:27.092Z] 20:22:27     INFO -  _execute_test()@Z:\\task_167899092841212\\build\\tests\\xpcshell\\head.js:658
[task 2023-03-16T20:22:27.093Z] 20:22:27     INFO -  -e:1" {file: "resource://gre/modules/Log.sys.mjs" line: 722}]
[task 2023-03-16T20:22:27.093Z] 20:22:27     INFO -  append@resource://gre/modules/Log.sys.mjs:722:12
[task 2023-03-16T20:22:27.093Z] 20:22:27     INFO -  log@resource://gre/modules/Log.sys.mjs:376:16
[task 2023-03-16T20:22:27.093Z] 20:22:27     INFO -  getLoggerWithMessagePrefix/proxy.log@resource://gre/modules/Log.sys.mjs:505:18
[task 2023-03-16T20:22:27.093Z] 20:22:27     INFO -  error@resource://gre/modules/Log.sys.mjs:384:10
[task 2023-03-16T20:22:27.094Z] 20:22:27     INFO -  shutdown@resource://gre/modules/TelemetrySend.sys.mjs:897:19
[task 2023-03-16T20:22:27.094Z] 20:22:27     INFO -  shutdown@resource://gre/modules/TelemetrySend.sys.mjs:251:30
[task 2023-03-16T20:22:27.094Z] 20:22:27     INFO -  @Z:/task_167899092841212/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/head.js:561:47
[task 2023-03-16T20:22:27.094Z] 20:22:27     INFO -  _execute_test/<@Z:\\task_167899092841212\\build\\tests\\xpcshell\\head.js:649:28
[task 2023-03-16T20:22:27.094Z] 20:22:27     INFO -  _execute_test@Z:\\task_167899092841212\\build\\tests\\xpcshell\\head.js:658:5
[task 2023-03-16T20:22:27.095Z] 20:22:27     INFO -  @-e:1:1
[task 2023-03-16T20:22:27.095Z] 20:22:27     INFO -  "
[task 2023-03-16T20:22:27.095Z] 20:22:27     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "1678998146972	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.sys.mjs :: shutdown :: line 895"  data: no] Stack trace: shutdown()@resource://gre/modules/TelemetrySend.sys.mjs:895
[task 2023-03-16T20:22:27.095Z] 20:22:27     INFO -  shutdown()@resource://gre/modules/TelemetrySend.sys.mjs:251
[task 2023-03-16T20:22:27.096Z] 20:22:27     INFO -  Z:/task_167899092841212/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/head.js:561
[task 2023-03-16T20:22:27.096Z] 20:22:27     INFO -  _execute_test/<()@Z:\\task_167899092841212\\build\\tests\\xpcshell\\head.js:649
[task 2023-03-16T20:22:27.096Z] 20:22:27     INFO -  _execute_test()@Z:\\task_167899092841212\\build\\tests\\xpcshell\\head.js:658
[task 2023-03-16T20:22:27.096Z] 20:22:27     INFO -  -e:1" {file: "resource://gre/modules/Log.sys.mjs" line: 722}]
[task 2023-03-16T20:22:27.097Z] 20:22:27     INFO -  append@resource://gre/modules/Log.sys.mjs:722:12
[task 2023-03-16T20:22:27.097Z] 20:22:27     INFO -  log@resource://gre/modules/Log.sys.mjs:376:16
[task 2023-03-16T20:22:27.097Z] 20:22:27     INFO -  getLoggerWithMessagePrefix/proxy.log@resource://gre/modules/Log.sys.mjs:505:18
[task 2023-03-16T20:22:27.097Z] 20:22:27     INFO -  error@resource://gre/modules/Log.sys.mjs:384:10
[task 2023-03-16T20:22:27.098Z] 20:22:27     INFO -  shutdown@resource://gre/modules/TelemetrySend.sys.mjs:897:19
[task 2023-03-16T20:22:27.098Z] 20:22:27     INFO -  shutdown@resource://gre/modules/TelemetrySend.sys.mjs:251:30
[task 2023-03-16T20:22:27.098Z] 20:22:27     INFO -  @Z:/task_167899092841212/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/head.js:561:47
[task 2023-03-16T20:22:27.098Z] 20:22:27     INFO -  _execute_test/<@Z:\\task_167899092841212\\build\\tests\\xpcshell\\head.js:649:28
[task 2023-03-16T20:22:27.098Z] 20:22:27     INFO -  _execute_test@Z:\\task_167899092841212\\build\\tests\\xpcshell\\head.js:658:5
[task 2023-03-16T20:22:27.099Z] 20:22:27     INFO -  @-e:1:1
[task 2023-03-16T20:22:27.099Z] 20:22:27     INFO -  "
[task 2023-03-16T20:22:27.100Z] 20:22:27     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "1678998146972	Toolkit.Telemetry	ERROR	TelemetrySend::shutdown - failed to remove observer for quit-application-forced: [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.sys.mjs :: shutdown :: line 895"  data: no] Stack trace: shutdown()@resource://gre/modules/TelemetrySend.sys.mjs:895
[task 2023-03-16T20:22:27.100Z] 20:22:27     INFO -  shutdown()@resource://gre/modules/TelemetrySend.sys.mjs:251
[task 2023-03-16T20:22:27.100Z] 20:22:27     INFO -  Z:/task_167899092841212/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/head.js:561
[task 2023-03-16T20:22:27.100Z] 20:22:27     INFO -  _execute_test/<()@Z:\\task_167899092841212\\build\\tests\\xpcshell\\head.js:649
[task 2023-03-16T20:22:27.101Z] 20:22:27     INFO -  _execute_test()@Z:\\task_167899092841212\\build\\tests\\xpcshell\\head.js:658
[task 2023-03-16T20:22:27.101Z] 20:22:27     INFO -  -e:1" {file: "resource://gre/modules/Log.sys.mjs" line: 722}]
[task 2023-03-16T20:22:27.101Z] 20:22:27     INFO -  append@resource://gre/modules/Log.sys.mjs:722:12
[task 2023-03-16T20:22:27.101Z] 20:22:27     INFO -  log@resource://gre/modules/Log.sys.mjs:376:16
[task 2023-03-16T20:22:27.101Z] 20:22:27     INFO -  getLoggerWithMessagePrefix/proxy.log@resource://gre/modules/Log.sys.mjs:505:18
[task 2023-03-16T20:22:27.101Z] 20:22:27     INFO -  error@resource://gre/modules/Log.sys.mjs:384:10
[task 2023-03-16T20:22:27.102Z] 20:22:27     INFO -  shutdown@resource://gre/modules/TelemetrySend.sys.mjs:897:19
[task 2023-03-16T20:22:27.102Z] 20:22:27     INFO -  shutdown@resource://gre/modules/TelemetrySend.sys.mjs:251:30
[task 2023-03-16T20:22:27.102Z] 20:22:27     INFO -  @Z:/task_167899092841212/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/head.js:561:47
[task 2023-03-16T20:22:27.103Z] 20:22:27     INFO -  _execute_test/<@Z:\\task_167899092841212\\build\\tests\\xpcshell\\head.js:649:28
[task 2023-03-16T20:22:27.103Z] 20:22:27     INFO -  _execute_test@Z:\\task_167899092841212\\build\\tests\\xpcshell\\head.js:658:5
[task 2023-03-16T20:22:27.103Z] 20:22:27     INFO -  @-e:1:1
[task 2023-03-16T20:22:27.103Z] 20:22:27     INFO -  "
[task 2023-03-16T20:22:27.103Z] 20:22:27     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "1678998146973	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.sys.mjs :: shutdown :: line 895"  data: no] Stack trace: shutdown()@resource://gre/modules/TelemetrySend.sys.mjs:895
[task 2023-03-16T20:22:27.104Z] 20:22:27     INFO -  shutdown()@resource://gre/modules/TelemetrySend.sys.mjs:251
[task 2023-03-16T20:22:27.104Z] 20:22:27     INFO -  Z:/task_167899092841212/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/head.js:561
[task 2023-03-16T20:22:27.104Z] 20:22:27     INFO -  _execute_test/<()@Z:\\task_167899092841212\\build\\tests\\xpcshell\\head.js:649
[task 2023-03-16T20:22:27.104Z] 20:22:27     INFO -  _execute_test()@Z:\\task_167899092841212\\build\\tests\\xpcshell\\head.js:658
[task 2023-03-16T20:22:27.105Z] 20:22:27     INFO -  -e:1" {file: "resource://gre/modules/Log.sys.mjs" line: 722}]
[task 2023-03-16T20:22:27.105Z] 20:22:27     INFO -  append@resource://gre/modules/Log.sys.mjs:722:12
[task 2023-03-16T20:22:27.105Z] 20:22:27     INFO -  log@resource://gre/modules/Log.sys.mjs:376:16
[task 2023-03-16T20:22:27.105Z] 20:22:27     INFO -  getLoggerWithMessagePrefix/proxy.log@resource://gre/modules/Log.sys.mjs:505:18
[task 2023-03-16T20:22:27.106Z] 20:22:27     INFO -  error@resource://gre/modules/Log.sys.mjs:384:10
[task 2023-03-16T20:22:27.106Z] 20:22:27     INFO -  shutdown@resource://gre/modules/TelemetrySend.sys.mjs:897:19
[task 2023-03-16T20:22:27.106Z] 20:22:27     INFO -  shutdown@resource://gre/modules/TelemetrySend.sys.mjs:251:30
[task 2023-03-16T20:22:27.106Z] 20:22:27     INFO -  @Z:/task_167899092841212/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/head.js:561:47
[task 2023-03-16T20:22:27.106Z] 20:22:27     INFO -  _execute_test/<@Z:\\task_167899092841212\\build\\tests\\xpcshell\\head.js:649:28
[task 2023-03-16T20:22:27.107Z] 20:22:27     INFO -  _execute_test@Z:\\task_167899092841212\\build\\tests\\xpcshell\\head.js:658:5
[task 2023-03-16T20:22:27.107Z] 20:22:27     INFO -  @-e:1:1
[task 2023-03-16T20:22:27.107Z] 20:22:27     INFO -  "
[task 2023-03-16T20:22:27.107Z] 20:22:27     INFO -  "CONSOLE_MESSAGE: (info) 1678998146974	Toolkit.Telemetry	TRACE	TelemetrySend::Scheduler::shutdown"
[task 2023-03-16T20:22:27.108Z] 20:22:27     INFO -  "CONSOLE_MESSAGE: (info) 1678998146974	Toolkit.Telemetry	TRACE	TelemetrySend::promisePendingPingActivity - Waiting for ping task"
[task 2023-03-16T20:22:27.108Z] 20:22:27     INFO -  PID 7832 | !!! error running onStopped callback: TypeError: callback is not a function
[task 2023-03-16T20:22:27.108Z] 20:22:27     INFO -  TEST-PASS | toolkit/components/telemetry/tests/unit/test_PingSender.js | test_pingsender2 - [test_pingsender2 : 68] 0d59f517-7f2d-4592-b5a0-e64746323e9a was deleted - true == true

Comment 1

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-beta: 1

Platform and build breakdown:

• windows11-64-2009-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1822913&startday=2023-03-13&endday=2023-03-19&tree=all

Comment 2

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• windows11-64-2009-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1822913&startday=2023-03-27&endday=2023-04-02&tree=all

Comment 3

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

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