Make the TelemetrySend tests call setup()/shutdown() in a consistent way

ASSIGNED
Assigned to

Status

()

Toolkit
Telemetry
P3
normal
ASSIGNED
9 months ago
3 days ago

People

(Reporter: gsvelto, Assigned: agashlin)

Tracking

(Blocks: 1 bug)

Trunk
Points:
---

Firefox Tracking Flags

(firefox55 affected)

Details

(Whiteboard: [measurement:client])

MozReview Requests

()

Submitter Diff Changes Open Issues Last Updated
Loading...
Error loading review requests:

Attachments

(1 attachment)

(Reporter)

Description

9 months ago
We currently have some try/catch blocks in the shutdown procedure of the TelemetrySend object to cope with tests that call shutdown() without calling setup() first or that call shutdown() twice in a row, see:

https://dxr.mozilla.org/mozilla-central/rev/1b9293be51637f841275541d8991314ca56561a5/toolkit/components/telemetry/TelemetrySend.jsm#642

This makes the tests output rather confusing as they produce a number of warnings even when the tests succeed. The tests should be fixed so that they act consistently and we don't need to ignore errors this way.
Priority: -- → P3
Whiteboard: [measurement:client]

Updated

a month ago
Depends on: 1416078

Updated

a month ago
Blocks: 1416078
No longer depends on: 1416078
(Assignee)

Comment 1

20 days ago
I've looked into this but I haven't found any tests that trigger the try/catch you link to. I know it was a while ago, but do you recall which tests were exhibiting this error? It's possible that they got cleaned up independently of this bug, I imagine.
(Reporter)

Comment 2

20 days ago
This is the test that's causing the issue:

https://searchfox.org/mozilla-central/rev/797c93d81fe446f78babf20894f0729f15f71ee6/toolkit/components/telemetry/tests/unit/test_TelemetrySend.js#436

If you run it you'll see error messages that look like this right after the following test starts:

 0:06.57 LOG: Thread-1 INFO "CONSOLE_MESSAGE: (error) [JavaScript Error: "1511336008267	Toolkit.Telemetry	ERROR	TelemetrySend::shutdown - failed to remove observer for idle-daily: [Exception... "Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver]"  nsresult: "0x80004005 (NS_ERROR_FAILURE)"  location: "JS frame :: resource://gre/modules/TelemetrySend.jsm :: shutdown :: line 754"  data: no] Stack trace: shutdown()@resource://gre/modules/TelemetrySend.jsm:754" {file: "resource://gre/modules/Log.jsm" line: 754}]
App_append@resource://gre/modules/Log.jsm:754:9
log@resource://gre/modules/Log.jsm:392:7
getLoggerWithMessagePrefix/proxy.log@resource://gre/modules/Log.jsm:507:44
error@resource://gre/modules/Log.jsm:400:5
shutdown@resource://gre/modules/TelemetrySend.jsm:756:9
async*shutdown@resource://gre/modules/TelemetrySend.jsm:211:12
_cleanupOnShutdown@resource://gre/modules/TelemetryController.jsm:804:13
async*shutdown@resource://gre/modules/TelemetryController.jsm:847:14
testShutdown@resource://gre/modules/TelemetryController.jsm:150:12
test_sendCheckOverride@/home/gsvelto/projects/build/firefox/_tests/xpcshell/toolkit/components/telemetry/tests/unit/test_TelemetrySend.js:465:9
async*asyncFunction@resource://gre/modules/Task.jsm:241:18
Task_spawn@resource://gre/modules/Task.jsm:166:12
_run_next_test@/home/gsvelto/projects/mozilla-central.asan/testing/xpcshell/head.js:1490:9
run@/home/gsvelto/projects/mozilla-central.asan/testing/xpcshell/head.js:703:9
_do_main@/home/gsvelto/projects/mozilla-central.asan/testing/xpcshell/head.js:224:3
_execute_test@/home/gsvelto/projects/mozilla-central.asan/testing/xpcshell/head.js:546:5
@-e:1:1
"

It's caused by this line trying to shutdown again w/o having called setup() first in the following test:

https://searchfox.org/mozilla-central/rev/797c93d81fe446f78babf20894f0729f15f71ee6/toolkit/components/telemetry/tests/unit/test_TelemetrySend.js#465

(this is TelemetryController.shutdown() calling TelemetrySend.shutdown() BTW)
(Assignee)

Comment 3

19 days ago
Oops, I was looking at the output from running ./mach test toolkit/components/telemetry/tests/unit/ and so I was missing the more detailed output. I added --verbose and now I can get the full output for the whole directory. Thanks!
(Assignee)

Comment 4

4 days ago
For my records these are the tests showing these errors:

test_MigratePendingPings
test_PingSender
test_TelemetryControllerShutdown
test_TelemetryEnvironment
test_TelemetryEvents
test_TelemetryFlagClear
test_TelemetryHistograms
test_TelemetryLateWrites
test_TelemetryLockCount
test_TelemetryLog
test_TelemetryScalars
test_TelemetrySend
test_TelemetrySession_activeTicks
test_TelemetryStopwatch
test_TelemetryStorage
test_TelemetryTimestamps
Comment hidden (mozreview-request)
(Assignee)

Comment 6

4 days ago
Changing the function given to do_register_cleanup fixes almost all of those tests. Then I just had to make one more change, to setup before the shutdown in test_sendCheckOverride. This seems to handle all instances of the error and seems to continue to test OK. Try:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=59bd4015597f3aa0fc29ae98feb0c78e727ea64a
(Reporter)

Updated

3 days ago
Assignee: nobody → agashlin
Status: NEW → ASSIGNED
(Reporter)

Comment 7

3 days ago
Comment on attachment 8935567 [details]
Bug 1348890 - Call setup()/shutdown() consistently

Redirecting the review to a telemetry peer. Glad to see this fixed, the logs when running these tests will be a lot cleaner. Also, this try/catch block should probably go too since it was there only to accommodate for the fact that shutdown() was being called multiple times:

https://searchfox.org/mozilla-central/rev/f5f1c3f294f89cfd242c3af9eb2c40d19d5e04e7/toolkit/components/telemetry/TelemetrySend.jsm#753

It should now be possible to just remove the observers without having to worry that the operation might throw.
Attachment #8935567 - Flags: review?(gsvelto) → review?(alessio.placitelli)
You need to log in before you can comment on or make changes to this bug.