1526244 - Intermittent toolkit/components/telemetry/tests/unit/test_TelemetrySession.js | test_schedulerEnvironmentReschedules - [test_schedulerEnvironmentReschedules : 1713] No ping should be received in this test (got cfa98259-0290-448b-8bc0-f3d7224e1a5a).

Status: RESOLVED INCOMPLETE

(Toolkit :: Telemetry, defect, P5)

Description

[Treeherder Bug Filer]

#[markdown(off)]
Filed by: nerli [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=227123638&repo=autoland

https://queue.taskcluster.net/v1/task/WE5SVQ__REGE5tnX-tfzkA/runs/0/artifacts/public/logs/live_backing.log

[task 2019-02-08T09:11:09.912Z] 09:11:09 INFO - TEST-PASS | toolkit/components/telemetry/tests/unit/test_TelemetrySession.js | test_schedulerEnvironmentReschedules - [test_schedulerEnvironmentReschedules : 1717] true == true
[task 2019-02-08T09:11:09.912Z] 09:11:09 INFO - TEST-PASS | toolkit/components/telemetry/tests/unit/test_TelemetrySession.js | test_schedulerEnvironmentReschedules - [test_schedulerEnvironmentReschedules : 1712] Known clientId should never appear in a ping on the server - "c0ffeec0-ffee-c0ff-eec0-ffeec0ffeec0" != "89a90132-3c5f-4d4c-b4fd-eee5c379d7b7"
[task 2019-02-08T09:11:09.912Z] 09:11:09 WARNING - TEST-UNEXPECTED-FAIL | toolkit/components/telemetry/tests/unit/test_TelemetrySession.js | test_schedulerEnvironmentReschedules - [test_schedulerEnvironmentReschedules : 1713] No ping should be received in this test (got cfa98259-0290-448b-8bc0-f3d7224e1a5a). - false == true
[task 2019-02-08T09:11:09.912Z] 09:11:09 INFO - /builds/worker/workspace/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_TelemetrySession.js:test_schedulerEnvironmentReschedules/<:1713
[task 2019-02-08T09:11:09.912Z] 09:11:09 INFO - /builds/worker/workspace/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/head.js:wrapper:179
[task 2019-02-08T09:11:09.915Z] 09:11:09 INFO - resource://testing-common/httpd.js:handleResponse:2183
[task 2019-02-08T09:11:09.915Z] 09:11:09 INFO - resource://testing-common/httpd.js:process:1147
[task 2019-02-08T09:11:09.916Z] 09:11:09 INFO - resource://testing-common/httpd.js:_handleResponse:1555
[task 2019-02-08T09:11:09.916Z] 09:11:09 INFO - resource://testing-common/httpd.js:_processBody:1418
[task 2019-02-08T09:11:09.916Z] 09:11:09 INFO - resource://testing-common/httpd.js:onInputStreamReady:1306
[task 2019-02-08T09:11:09.917Z] 09:11:09 INFO - /builds/worker/workspace/build/tests/xpcshell/head.js:_do_main:224
[task 2019-02-08T09:11:09.918Z] 09:11:09 INFO - /builds/worker/workspace/build/tests/xpcshell/head.js:_execute_test:527
[task 2019-02-08T09:11:09.919Z] 09:11:09 INFO - -e:null:1
[task 2019-02-08T09:11:09.920Z] 09:11:09 INFO - exiting test
[task 2019-02-08T09:11:09.920Z] 09:11:09 INFO - PID 15571 | Caught exception:
[task 2019-02-08T09:11:09.920Z] 09:11:09 INFO - PID 15571 | _abort_failed_test@/builds/worker/workspace/build/tests/xpcshell/head.js:740:9
[task 2019-02-08T09:11:09.921Z] 09:11:09 INFO - PID 15571 | do_report_result@/builds/worker/workspace/build/tests/xpcshell/head.js:847:5
[task 2019-02-08T09:11:09.921Z] 09:11:09 INFO - PID 15571 | Assert<@/builds/worker/workspace/build/tests/xpcshell/head.js:54:5
[task 2019-02-08T09:11:09.922Z] 09:11:09 INFO - PID 15571 | proto.report@resource://testing-common/Assert.jsm:213:5
[task 2019-02-08T09:11:09.923Z] 09:11:09 INFO - PID 15571 | proto.ok@resource://testing-common/Assert.jsm:233:5
[task 2019-02-08T09:11:09.923Z] 09:11:09 INFO - PID 15571 | test_schedulerEnvironmentReschedules/<@/builds/worker/workspace/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_TelemetrySession.js:1713:5
[task 2019-02-08T09:11:09.923Z] 09:11:09 INFO - PID 15571 | wrapper@/builds/worker/workspace/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/head.js:179:7
[task 2019-02-08T09:11:09.924Z] 09:11:09 INFO - PID 15571 | handleResponse@resource://testing-common/httpd.js:2183:50
[task 2019-02-08T09:11:09.924Z] 09:11:09 INFO - PID 15571 | process@resource://testing-common/httpd.js:1147:5
[task 2019-02-08T09:11:09.924Z] 09:11:09 INFO - PID 15571 | _handleResponse@resource://testing-common/httpd.js:1555:5
[task 2019-02-08T09:11:09.925Z] 09:11:09 INFO - PID 15571 | _processBody@resource://testing-common/httpd.js:1418:9
[task 2019-02-08T09:11:09.925Z] 09:11:09 INFO - PID 15571 | onInputStreamReady@resource://testing-common/httpd.js:1306:9
[task 2019-02-08T09:11:09.925Z] 09:11:09 INFO - PID 15571 | _do_main@/builds/worker/workspace/build/tests/xpcshell/head.js:224:3
[task 2019-02-08T09:11:09.925Z] 09:11:09 INFO - PID 15571 | _execute_test@/builds/worker/workspace/build/tests/xpcshell/head.js:527:5
[task 2019-02-08T09:11:09.926Z] 09:11:09 INFO - PID 15571 | @-e:1:1
[task 2019-02-08T09:11:09.926Z] 09:11:09 INFO - (xpcshell/head.js) | test finished (1)
[task 2019-02-08T09:11:09.927Z] 09:11:09 INFO - exiting test
[task 2019-02-08T09:11:09.927Z] 09:11:09 INFO - "CONSOLE_MESSAGE: (info) 1549617065592 Toolkit.Telemetry TRACE TelemetryScheduler::_onSchedulerTick - dispatchOnIdle: false"
[task 2019-02-08T09:11:09.927Z] 09:11:09 INFO - "CONSOLE_MESSAGE: (info) 1549617065592 Toolkit.Telemetry TRACE TelemetryScheduler::_schedulerTickLogic"
[task 2019-02-08T09:11:09.928Z] 09:11:09 INFO - "CONSOLE_MESSAGE: (info) 1549617065592 Toolkit.Telemetry TRACE TelemetryScheduler::_schedulerTickLogic - First scheduler tick after sleep."
[task 2019-02-08T09:11:09.928Z] 09:11:09 INFO - "CONSOLE_MESSAGE: (info) 1549617065592 Toolkit.Telemetry TRACE TelemetryScheduler::_isDailyPingDue - already sent one today"
[task 2019-02-08T09:11:09.928Z] 09:11:09 INFO - "CONSOLE_MESSAGE: (info) 1549617065592 Toolkit.Telemetry TRACE TelemetryScheduler::_schedulerTickLogic - No ping due."
[task 2019-02-08T09:11:09.929Z] 09:11:09 INFO - "CONSOLE_MESSAGE: (info) 1549617065592 Toolkit.Telemetry TRACE TelemetryScheduler::_rescheduleTimeout - isUserIdle: false"
[task 2019-02-08T09:11:09.929Z] 09:11:09 INFO - "CONSOLE_MESSAGE: (info) 1549617065592 Toolkit.Telemetry TRACE TelemetryScheduler::_rescheduleTimeout - scheduling next tick for Fri Nov 19 2060 00:05:00 GMT+0000 (Coordinated Universal Time)"
[task 2019-02-08T09:11:09.929Z] 09:11:09 INFO - "CONSOLE_MESSAGE: (info) 1549617065592 Toolkit.Telemetry TRACE TelemetryController::shutdown"
[task 2019-02-08T09:11:09.930Z] 09:11:09 INFO - "CONSOLE_MESSAGE: (info) 1549617065593 Toolkit.Telemetry TRACE TelemetryEventPing::::Shutting down."
[task 2019-02-08T09:11:09.930Z] 09:11:09 INFO - "CONSOLE_MESSAGE: (info) 1549617065593 Toolkit.Telemetry TRACE TelemetryEventPing::::_submitPing"
[task 2019-02-08T09:11:09.930Z] 09:11:09 INFO - "CONSOLE_MESSAGE: (info) 1549617065593 Toolkit.Telemetry TRACE TelemetryEventPing::::not sending event ping due to lack of events"
[task 2019-02-08T09:11:09.931Z] 09:11:09 INFO - "CONSOLE_MESSAGE: (info) 1549617065593 Toolkit.Telemetry TRACE TelemetryReportingPolicy::shutdown"
[task 2019-02-08T09:11:09.931Z] 09:11:09 INFO - "CONSOLE_MESSAGE: (info) 1549617065593 Toolkit.Telemetry TRACE TelemetryEnvironment::shutdown"
[task 2019-02-08T09:11:09.931Z] 09:11:09 INFO - "CONSOLE_MESSAGE: (info) 1549617065593 Toolkit.Telemetry TRACE TelemetrySend::_cancelOutgoingRequests - aborting ping request for id cfa98259-0290-448b-8bc0-f3d7224e1a5a"
[task 2019-02-08T09:11:09.932Z] 09:11:09 INFO - "CONSOLE_MESSAGE: (info) 1549617065593 Toolkit.Telemetry TRACE TelemetryHealthPing::::_addToFailure() - with type and subtype: sendFailure : abort"
[task 2019-02-08T09:11:09.934Z] 09:11:09 INFO - "CONSOLE_MESSAGE: (error) [JavaScript Error: "1549617065594 Toolkit.Telemetry ERROR TelemetrySend::_doPing - error making request to http://localhost:43183/submit/telemetry/cfa98259-0290-448b-8bc0-f3d7224e1a5a/main/XPCShell/1/default/20160315?v=4: abort" {file: "resource://gre/modules/Log.jsm" line: 679}]
[task 2019-02-08T09:11:09.934Z] 09:11:09 INFO - append@resource://gre/modules/Log.jsm:679:9
[task 2019-02-08T09:11:09.935Z] 09:11:09 INFO - log@resource://gre/modules/Log.jsm:360:7
[task 2019-02-08T09:11:09.935Z] 09:11:09 INFO - getLoggerWithMessagePrefix/proxy.log@resource://gre/modules/Log.jsm:484:14
[task 2019-02-08T09:11:09.935Z] 09:11:09 INFO - error@resource://gre/modules/Log.jsm:368:5
[task 2019-02-08T09:11:09.936Z] 09:11:09 INFO - errorhandler@resource://gre/modules/TelemetrySend.jsm:1165:7
[task 2019-02-08T09:11:09.936Z] 09:11:09 INFO - _cancelOutgoingRequests@resource://gre/modules/TelemetrySend.jsm:940:9
[task 2019-02-08T09:11:09.936Z] 09:11:09 INFO - shutdown@resource://gre/modules/TelemetrySend.jsm:754:11
[task 2019-02-08T09:11:09.936Z] 09:11:09 INFO - async*shutdown@resource://gre/modules/TelemetrySend.jsm:200:12
[task 2019-02-08T09:11:09.937Z] 09:11:09 INFO - _cleanupOnShutdown@resource://gre/modules/TelemetryController.jsm:795:13
[task 2019-02-08T09:11:09.938Z] 09:11:09 INFO - async*shutdown@resource://gre/modules/TelemetryController.jsm:840:14
[task 2019-02-08T09:11:09.938Z] 09:11:09 INFO - testShutdown@resource://gre/modules/TelemetryController.jsm:140:12
[task 2019-02-08T09:11:09.941Z] 09:11:09 INFO - test_schedulerEnvironmentReschedules@/builds/worker/workspace/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_TelemetrySession.js:1719:9
[task 2019-02-08T09:11:09.941Z] 09:11:09 INFO - async*run_next_test/_run_next_test/<@/builds/worker/workspace/build/tests/xpcshell/head.js:1435:22
[task 2019-02-08T09:11:09.941Z] 09:11:09 INFO - async*_run_next_test@/builds/worker/workspace/build/tests/xpcshell/head.js:1435:10
[task 2019-02-08T09:11:09.942Z] 09:11:09 INFO - run@/builds/worker/workspace/build/tests/xpcshell/head.js:686:9
[task 2019-02-08T09:11:09.942Z] 09:11:09 INFO - _do_main@/builds/worker/workspace/build/tests/xpcshell/head.js:224:3
[task 2019-02-08T09:11:09.942Z] 09:11:09 INFO - _execute_test@/builds/worker/workspace/build/tests/xpcshell/head.js:527:5
[task 2019-02-08T09:11:09.942Z] 09:11:09 INFO - @-e:1:1

Comment 1

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform breakdown:

• linux32: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1526244&startday=2019-02-04&endday=2019-02-10&tree=all

Comment 2

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-inbound: 1

Platform breakdown:

• linux32: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1526244&startday=2019-02-25&endday=2019-03-03&tree=all

Comment 3

[Firefox Bug Husbandry Bot]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup