1454208 - Intermittent toolkit/components/telemetry/tests/unit/test_TelemetrySend.js | testCookies - [testCookies : 547] We're testing the right ping's request, right? - "c01b998f-24a8-4eaf-8d9a-f021a72456ce" == "a008e869-fe5b-4509-9402-20ba0d018ddc"

Status: RESOLVED FIXED

(Toolkit :: Telemetry, defect, P1)

Description

[Treeherder Bug Filer]

Filed by: ccoroiu [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=173737166&repo=mozilla-central

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

1:41:21     INFO -  TEST-START | toolkit/components/telemetry/tests/unit/test_TelemetrySend.js
01:42:16  WARNING -  TEST-UNEXPECTED-FAIL | toolkit/components/telemetry/tests/unit/test_TelemetrySend.js | xpcshell return code: 0
01:42:16     INFO -  TEST-INFO took 54805ms
01:42:16     INFO -  >>>>>>>
01:42:16     INFO -  PID 4204 | [4204, Main Thread] WARNING: Couldn't get the user appdata directory. Crash events may not be produced.: file z:/build/build/src/toolkit/crashreporter/nsExceptionHandler.cpp, line 2678
01:42:16     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
01:42:16     INFO -  (xpcshell/head.js) | test run_next_test 0 pending (2)
01:42:16     INFO -  (xpcshell/head.js) | test MAIN run_test finished (2)
01:42:16     INFO -  running event loop
01:42:16     INFO -  toolkit/components/telemetry/tests/unit/test_TelemetrySend.js | Starting test_setup
01:42:16     INFO -  (xpcshell/head.js) | test test_setup pending (2)
01:42:16     INFO -  PID 4204 | Unable to read VR Path Registry from Z:\\task_1523755074\\AppData\\Local\\openvr\\openvrpaths.vrpath
01:42:16     INFO -  PID 4204 | JavaScript strict warning: resource://gre/modules/TelemetryEnvironment.jsm, line 1447: ReferenceError: reference to undefined property "@mozilla.org/sandbox/sandbox-settings;1"
01:42:16     INFO -  (xpcshell/head.js) | test run_next_test 0 finished (2)
01:42:16     INFO -  (xpcshell/head.js) | test run_next_test 1 pending (2)
01:42:16     INFO -  (xpcshell/head.js) | test test_setup finished (2)
01:42:16     INFO -  "CONSOLE_MESSAGE: (info) 1523756482362	Toolkit.Telemetry	TRACE	TelemetryEnvironment::constructor"
01:42:16     INFO -  "CONSOLE_MESSAGE: (info) 1523756482403	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_getGFXData - Only one display adapter detected."
01:42:16     INFO -  "CONSOLE_MESSAGE: (warn) [JavaScript Warning: "ReferenceError: reference to undefined property "@mozilla.org/sandbox/sandbox-settings;1"" {file: "resource://gre/modules/TelemetryEnvironment.jsm" line: 1447}]"
01:42:16     INFO -  "CONSOLE_MESSAGE: (info) 1523756482430	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_updateSearchEngine - ignoring early call"
01:42:16     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "1523756482459	Toolkit.Telemetry	ERROR	TelemetryEnvironment::EnvironmentCache - error while initializing: TypeError: gShutdownBarrier is null (resource://gre/modules/AddonManager.jsm:3642:5) JS Stack trace: get [e-mail]:3642:5
01:42:16     INFO -  [e-mail]:508:7
01:42:16     INFO -  [e-mail]:898:9
01:42:16     INFO -  [e-mail]:63:26
01:42:16     INFO -  [e-mail]:74:12
01:42:16     INFO -  [e-mail]:318:10
01:42:16     INFO -  test_setup@test_TelemetrySend.js:88:9
01:42:16     INFO -  async*run_next_test/_run_next_test/<@Z:\\task_1523755074\\build\\tests\\xpcshell\\head.js:1418:22
01:42:16     INFO -  async*_run_next_test@Z:\\task_1523755074\\build\\tests\\xpcshell\\head.js:1418:10
01:42:16     INFO -  run@Z:\\task_1523755074\\build\\tests\\xpcshell\\head.js:669:9
01:42:16     INFO -  _do_main@Z:\\task_1523755074\\build\\tests\\xpcshell\\head.js:211:3
01:42:16     INFO -  _execute_test@Z:\\task_1523755074\\build\\tests\\xpcshell\\head.js:517:5
01:42:16     INFO -  @-e:1:1" {file: "resource://gre/modules/Log.jsm" line: 797}]
01:42:16     INFO -  App_append@resource://gre/modules/Log.jsm:797:9
01:42:16     INFO -  log@resource://gre/modules/Log.jsm:435:7
01:42:16     INFO -  getLoggerWithMessagePrefix/proxy.log@resource://gre/modules/Log.jsm:550:44
01:42:16     INFO -  error@resource://gre/modules/Log.jsm:443:5
01:42:16     INFO -  EnvironmentCache/this._initTask<@resource://gre/modules/TelemetryEnvironment.jsm:924:9
01:42:16     INFO -  _do_main@Z:\\task_1523755074\\build\\tests\\xpcshell\\head.js:211:3
01:42:16     INFO -  _execute_test@Z:\\task_1523755074\\build\\tests\\xpcshell\\head.js:517:5
01:42:16     INFO -  @-e:1:1
01:42:16     INFO -  "
01:42:16     INFO -  "CONSOLE_MESSAGE: (info) 1523756482464	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_startWatchingPrefs - [object Map]"
01:42:16     INFO -  "CONSOLE_MESSAGE: (info) 1523756482494	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_stopWatchingPrefs"
01:42:16     INFO -  "CONSOLE_MESSAGE: (info) 1523756482511	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_updateSearchEngine - ignoring early call"
01:42:16     INFO -  "CONSOLE_MESSAGE: (info) 1523756482512	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_startWatchingPrefs - [object Map]"
01:42:16     INFO -  toolkit/components/telemetry/tests/unit/test_TelemetrySend.js | Starting test_sendPendingPings
01:42:16     INFO -  (xpcshell/head.js) | test test_sendPendingPings pending (2)
01:42:16     INFO -  (xpcshell/head.js) | test run_next_test 1 finished (2)
01:42:16     INFO -  PID 4204 | [4204, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004002: file z:/build/build/src/toolkit/components/resistfingerprinting/nsRFPService.cpp, line 680

Comment 1

[Intermittent Failures Robot]

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

Repository breakdown:
* mozilla-central: 1

Platform breakdown:
* windows10-64-ccov: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1454208&startday=2018-04-09&endday=2018-04-15&tree=trunk

Comment 2

[Alessio Placitelli [:Dexter]]

Hey Chris, this looks related to bug 1452139. Any clue?

Comment 3

[Chris H-C :chutten]

Eurgh, this means that some other ping is being returned by the PingServer during the test instead of the one we're looking for. I'll have to rewrite the test to be more resilient to this.

Thank goodness I put in this defensive assert so we know what's going wrong.

Comment 4

[Intermittent Failures Robot]

4 failures in 782 pushes (0.005 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* mozilla-central: 4

Platform breakdown:
* windows10-64-ccov: 4

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1454208&startday=2018-04-16&endday=2018-04-22&tree=trunk

Comment 5

[Chris H-C :chutten]

Maybe add a capability to PingServer to wait for a -particular- ping?

Comment 6

[Intermittent Failures Robot]

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

Repository breakdown:
* autoland: 1

Platform breakdown:
* windows10-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1454208&startday=2018-04-23&endday=2018-04-29&tree=trunk

Comment 8

[Chris H-C :chutten]

(In reply to Chris H-C :chutten from comment #5)
> Maybe add a capability to PingServer to wait for a -particular- ping?

Unfortunately it doesn't make sense here as we need the whole response for its headers, not just the ping. Maybe next time.

Comment 9

[Chris H-C :chutten]

Attachment: 0001-bug-1454208-Wait-for-the-correct-ping-in-the-test-r-.patch

Comment 10

[Alessio Placitelli [:Dexter]]

Comment on attachment 8972143 [details] [diff] [review]
0001-bug-1454208-Wait-for-the-correct-ping-in-the-test-r-.patch

Review of attachment 8972143 [details] [diff] [review]:
-----------------------------------------------------------------

Great to have that feature, I wish waiting for a ping was in the PingServer :-)

Comment 11

[Intermittent Failures Robot]

2 failures in 551 pushes (0.004 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* mozilla-central: 2

Platform breakdown:
* windows10-64-ccov: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1454208&startday=2018-04-30&endday=2018-05-06&tree=trunk

Comment 12

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/2e48ec2ac122
Wait for the correct ping in the test. r=Dexter

Comment 13

[Raul Gurzau (:RaulG)]

https://hg.mozilla.org/mozilla-central/rev/2e48ec2ac122

Comment 14

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-beta/rev/e545d0271d08