Closed Bug 1454208 Opened 4 years ago Closed 4 years ago

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"

Categories

(Toolkit :: Telemetry, defect, P1)

Other
iOS
defect

Tracking

()

RESOLVED FIXED
mozilla62
Tracking Status
firefox61 --- fixed
firefox62 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: chutten|PTO)

References

Details

(Keywords: intermittent-failure)

Attachments

(1 file)

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 shutdown@AddonManager.jsm:3642:5
01:42:16     INFO -  init@TelemetryEnvironment.jsm:508:7
01:42:16     INFO -  EnvironmentCache@TelemetryEnvironment.jsm:898:9
01:42:16     INFO -  getGlobal@TelemetryEnvironment.jsm:63:26
01:42:16     INFO -  onInitialized@TelemetryEnvironment.jsm:74:12
01:42:16     INFO -  setEmptyPrefWatchlist@head.js: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
Product: Firefox for iOS → Toolkit
Hey Chris, this looks related to bug 1452139. Any clue?
Flags: needinfo?(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.
Assignee: nobody → chutten
Status: NEW → ASSIGNED
Flags: needinfo?(chutten)
Priority: P5 → P1
Maybe add a capability to PingServer to wait for a -particular- ping?
Duplicate of this bug: 1457733
(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 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 :-)
Attachment #8972143 - Flags: review?(alessio.placitelli) → review+
Pushed by ryanvm@gmail.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/2e48ec2ac122
Wait for the correct ping in the test. r=Dexter
Keywords: checkin-needed
https://hg.mozilla.org/mozilla-central/rev/2e48ec2ac122
Status: ASSIGNED → RESOLVED
Closed: 4 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla61
Target Milestone: mozilla61 → mozilla62
You need to log in before you can comment on or make changes to this bug.