Intermittent test_TelemetrySend.js | test_backoffTimeout - [test_backoffTimeout : 245] Should have received the correct amount of type C pings - "undefined" == 1

RESOLVED FIXED in Firefox 49

Status

()

P1
normal
RESOLVED FIXED
3 years ago
2 years ago

People

(Reporter: philor, Assigned: Dexter)

Tracking

({intermittent-failure})

Trunk
mozilla50
intermittent-failure
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(firefox49 fixed, thunderbird_esr45 wontfix, firefox50 fixed)

Details

(Whiteboard: [measurement:client])

Attachments

(1 attachment, 2 obsolete attachments)

(Assignee)

Updated

3 years ago
Priority: -- → P3
Whiteboard: [measurement:client]
(Assignee)

Comment 1

3 years ago
Heh, this is a nice one.

It looks like we're catching a change from a preference on our watchlist during the test and this is triggering a new "main" ping.

> 15:11:05     INFO -  "CONSOLE_MESSAGE: (info) 1464041411704	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_onPrefChanged"
> 15:11:05     INFO -  "CONSOLE_MESSAGE: (info) 1464041411720	Toolkit.Telemetry	TRACE	 TelemetryEnvironment::_updateSearchEngine - isInitialized: false"
> 15:11:05     INFO -  "CONSOLE_MESSAGE: (info) 1464041411720	Toolkit.Telemetry	TRACE	TelemetryEnvironment::_onEnvironmentChange for pref-changed"
> [...]
> 15:11:05     INFO -  "CONSOLE_MESSAGE: (info) 1464041412801	Toolkit.Telemetry	TRACE	TelemetryController::assemblePing - Type main, aOptions {"addClientId":true,"addEnvironment":true}"

This is happening right before [1], where we look and wait for 3 pings. The unexpected "main" ping gets picked up, while the test one is left out, thus making the test fail.

[1] - https://dxr.mozilla.org/mozilla-central/rev/46fe2115d46a5bb40523b8466341d8f9a26e1bdf/toolkit/components/telemetry/tests/unit/test_TelemetrySend.js#242
(Assignee)

Comment 2

3 years ago
Created attachment 8755917 [details] [diff] [review]
bug1275144.patch

This should address the issue, by disabling pref watching during telemetry xpcshell tests.

Unfortunately, we cannot directly use TelemetryEnvironment.testWatchPrefs in head.js as it would cause the AddonManager to load and things would blow up.

Moreover, it looks like |Preferences.observe| feeds the callback function with the changed value, not with the name of the changed pref: I'm not sure if there's a simple way to get the name of the pref that changed from there.
(Assignee)

Updated

3 years ago
Assignee: nobody → alessio.placitelli
Status: NEW → ASSIGNED
Priority: P3 → P1
(Assignee)

Comment 4

3 years ago
Comment on attachment 8755917 [details] [diff] [review]
bug1275144.patch

I've also taken this through a manual test drive and it looks like it's working fine.
Attachment #8755917 - Flags: review?(gfritzsche)
Comment on attachment 8755917 [details] [diff] [review]
bug1275144.patch

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

::: toolkit/components/telemetry/TelemetryEnvironment.jsm
@@ +197,5 @@
> + * This is a policy object used to override behavior for testing.
> + */
> +var Policy = {
> +  now: () => new Date(),
> +  getEnvironmentPrefs: () => DEFAULT_ENVIRONMENT_PREFS,

This is adding an additional way of overriding prefs to the one we already have, lets not do that.
Maybe we should do this just explicitly in the individual tests or figure out a common way to do this with _watchPreferences() or so.
Attachment #8755917 - Flags: review?(gfritzsche)
(Assignee)

Comment 6

3 years ago
Created attachment 8756352 [details] [diff] [review]
bug1275144.patch

(In reply to Georg Fritzsche [:gfritzsche] from comment #5)
> Comment on attachment 8755917 [details] [diff] [review]
> bug1275144.patch
> 
> Review of attachment 8755917 [details] [diff] [review]:
> -----------------------------------------------------------------
> ...
> Maybe we should do this just explicitly in the individual tests or figure
> out a common way to do this with _watchPreferences() or so.

I've changed the patch to explicitly fix the offending test (test_TelemetrySend.js).
Attachment #8755917 - Attachment is obsolete: true
Attachment #8756352 - Flags: review?(gfritzsche)
(Assignee)

Updated

3 years ago
Attachment #8756352 - Flags: review?(gfritzsche)
(Assignee)

Comment 7

3 years ago
Comment on attachment 8756352 [details] [diff] [review]
bug1275144.patch

Sorry, I mistakenly removed the r?.
Attachment #8756352 - Flags: review?(gfritzsche)
(Assignee)

Updated

3 years ago
Attachment #8756352 - Flags: review?(gfritzsche)
(Assignee)

Comment 8

3 years ago
Created attachment 8759981 [details] [diff] [review]
bug1275144.patch

This patch addresses the problem in this bug, Bug 1273973 and Bug 1160816.

This also changes other tests so that we don't have the same issues again.
Attachment #8756352 - Attachment is obsolete: true
Attachment #8759981 - Flags: review?(gfritzsche)
(Assignee)

Updated

3 years ago
OS: Unspecified → All
Hardware: Unspecified → All
Attachment #8759981 - Flags: review?(gfritzsche) → review+
(In reply to Alessio Placitelli [:Dexter] from comment #8)
> This patch addresses the problem in this bug, Bug 1273973 and Bug 1160816.

Let's make this block those bugs then.
(Assignee)

Updated

3 years ago
Blocks: 1273973, 1160816

Comment 11

3 years ago
Pushed by alessio.placitelli@gmail.com:
https://hg.mozilla.org/integration/fx-team/rev/2e85c7f08dd1
Don't watch for preference changes in XPCSHELL tests. r=gfritzsche

Comment 12

3 years ago
bugherder
https://hg.mozilla.org/mozilla-central/rev/2e85c7f08dd1
Status: ASSIGNED → RESOLVED
Last Resolved: 3 years ago
status-firefox50: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla50

Updated

3 years ago
Duplicate of this bug: 1160816

Comment 14

3 years ago
Thanks for the fix, looks like it worked :-)

This should probably be uplifted to aurora.
(Assignee)

Comment 15

3 years ago
@Tomcat, is this (along with Bug 1273973 and Bug 1160816) a big issue on Aurora?
Flags: needinfo?(cbook)
(In reply to Alessio Placitelli [:Dexter] from comment #15)
> @Tomcat, is this (along with Bug 1273973 and Bug 1160816) a big issue on
> Aurora?

i think its no big issue on aurora. Also aurora was closed for 3 days. 

However since this only touching test it can land with a=test-only. Let me know if i shall do this
Flags: needinfo?(cbook)
(Assignee)

Comment 17

3 years ago
(In reply to Carsten Book [:Tomcat] from comment #16)
> (In reply to Alessio Placitelli [:Dexter] from comment #15)
> > @Tomcat, is this (along with Bug 1273973 and Bug 1160816) a big issue on
> > Aurora?
> 
> i think its no big issue on aurora. Also aurora was closed for 3 days. 
> 
> However since this only touching test it can land with a=test-only. Let me
> know if i shall do this

Super, please do! Thank you!

Comment 18

3 years ago
bugherderuplift
https://hg.mozilla.org/releases/mozilla-aurora/rev/1ae7a82e2b1d
status-firefox49: affected → fixed
(Assignee)

Updated

3 years ago
Duplicate of this bug: 1273973
While tempting to land this patch in THUNDERBIRD_45_VERBRANCH, the tests have been redesigned since then, and the patch does not apply cleanly. While I might be able to rewrite to work, not worth the effort to stop the failing tests in the branch.
status-thunderbird_esr45: --- → wontfix
You need to log in before you can comment on or make changes to this bug.