1458125 - Docs / behaviour don't match for toolkit.telemetry.log.level

Status: RESOLVED FIXED

(Toolkit :: Telemetry, enhancement, P3)

Description

[Paul Bone [:pbone]]

The documentation here: https://firefox-source-docs.mozilla.org/toolkit/components/telemetry/telemetry/internals/preferences.html says that the pref toolkit.telemetry.log.level can be a number (it mentions 0) but this doesn't work as documented, I didn't notice any extra logging.  Setting the pref to "Trace" worked as described.

Is the implementation buggy or are the docs out-of-date?  Also the docs should list each of the levels this pref understands.

(I'm not sure if this is the right place to file a docs bug, I couldn't find anything more appropriate, sorry.)

Comment 1

[Chris H-C :chutten]

This is the perfect place to file a Telemetry docs bug. Thank you for filing it.

I think the problem is that toolkit.telemetry.log.level is a string pref. So if it is set to 0 Preferences.cpp will instead use our default log level of "Warn", but if you set it to "0"... well, then it gets interesting.

Our log code just tries to index the log level object with the string[1]. There is no log level "0", so instead it does what JS objects do when you deref them on a key that doesn't exist and gives us a log level of undefined.

Our log level of undefined always fails this early-return[2] which means it prints all the messages all the time. Same thing should happen if you specify a log level of "banana", but I haven't yet tested this. (UPDATE: I have tested this and it works. Also, it is mildly hilarious)

What I don't understand is why we bother doing the pref management ourselves. Log.jsm can be configured with a pref name so that -it- has to take care of listening for it and asking how it's doing and all that jazz. We might have to add a parent log to carry the default log level for when the logging pref isn't present (or we could put the pref in the build with our default value in it so it's easier to find)... Probably historical reasons for this. Or maybe we do it because we need to configure the stdout log appender if someone changes the .dump pref too.

So, in short: "0" will work but 0 will not. "banana" will also work. Thank you for this rabbit hole, I've learned some things.  We can be more clear about that in the docs by specifying it has to be a string pref.

[1]: https://searchfox.org/mozilla-central/rev/8837610b6c999451435695e800f38d4acbc0a644/toolkit/components/telemetry/TelemetryController.jsm#87
[2]: https://searchfox.org/mozilla-central/rev/8837610b6c999451435695e800f38d4acbc0a644/toolkit/modules/Log.jsm#452

Comment 2

[Chris H-C :chutten]

To help Mozilla out with this bug, here's the steps:

0) Comment here on the bug that you want to volunteer to help. I (or someone else) will assign it to you.
1) Download and build the Firefox source code: https://developer.mozilla.org/en-US/docs/Mozilla/Developer_guide/Build_Instructions/Simple_Firefox_build
- If you have any problems, please ask on IRC (https://wiki.mozilla.org/Irc) in the #introduction channel. They're there to help you get started.
- You can also read the Developer Guide, which has answers to most development questions: https://developer.mozilla.org/en-US/docs/Mozilla/Developer_guide/Introduction
2) Start working on this bug. You'll be editing the file toolkit/componenets/telemetry/docs/internals/preferences.rst to note that toolkit.telemetry.log.level is a string preference.
- If you have any problems with this bug, please comment on this bug and set the needinfo flag for me. Also, you can find me and my teammates on the #telemetry channel on IRC (https://wiki.mozilla.org/Irc) most hours of most days.
3) Build and test your change with `mach doc`. Also check your changes for adherence to our style guidelines by using `mach lint`
4) Submit the patch for review. Mark me as a reviewer so I'll get an email to come look at your code.
- Here's the guide: https://developer.mozilla.org/en-US/docs/Mozilla/Developer_guide/How_to_Submit_a_Patch
5) After a series of reviews and changes to your patch, I'll mark it for checkin or push it to autoland. Your code will soon be shipping to Firefox users worldwide!
6) ...now you get to think about what kind of bug you'd like to work on next. Let me know what you're interested in and I can help you find your next contribution.

Comment 3

[Paul Bone [:pbone]]

Nice, thanks chutten,

Yeah, I tried 0 but not "0".  I didn't try any other digits, but the implication is that 1 might be info, 2 might be warnings etc, which from what you've said it is not.

So to confirm, and provide any info for a potential contributor, we want to change the code to only accept strings (which also simplifies it) and update the docs to remove the mention of numbers and to either provide the list of valid strings or link to that documentation (for Log.jsm) elsewhere.

Cheers.

Comment 4

[Thi Huynh]

Hi, I want to work on this.

Comment 5

[Chris H-C :chutten]

Great! I have assigned the bug to you. Please let me know if you have any questions.

Comment 6

[Thi Huynh]

Hi Chris, it would take a bit slow for this bug because I want to understand the code more clearly before submitting the patch (even though this bug is about editting the docs).

Comment 7

[Chris H-C :chutten]

Of course, take your time. I tend to leave mentored bugs a week or so before concluding they're no longer being worked on. Will that be enough?

Comment 8

[Thi Huynh]

That's is more than enough, thank you.

Comment 9

[Thi Huynh]

When we use an invalid string (like "0"), |Log.Level[Services.prefs.getStringPref(TelemetryUtils.Preferences.LogLevel, "Warn")]| [1] returns |undefined| which in turn is assigned sets |_level| of class Logger [2].

However, |Logger._level| has a getter with this interesting line [3] so instead of return |undefined|, it will return |Log.Level.All| [4].

Therefore, for this bug, I think we only need to adjust the documents to specify the available log levels. No changes for the code is needed.

[1] https://searchfox.org/mozilla-central/rev/8837610b6c999451435695e800f38d4acbc0a644/toolkit/components/telemetry/TelemetryController.jsm#87
[2] https://searchfox.org/mozilla-central/rev/8837610b6c999451435695e800f38d4acbc0a644/toolkit/modules/Log.jsm#311
[3] https://searchfox.org/mozilla-central/source/toolkit/modules/Log.jsm#232
[4] https://searchfox.org/mozilla-central/source/toolkit/modules/Log.jsm#237

Comment 10

[Thi Huynh]

Attachment: Bug 1458125 - Document the valid log levels for toolkit.telemetry.log.level r?chutten

MozReview-Commit-ID: GpScw6r7heY

Comment 11

[Chris H-C :chutten]

Comment on attachment 8999426 [details]
Bug 1458125 - Document the valid log levels for toolkit.telemetry.log.level r?chutten

Chris H-C :chutten has approved the revision.

Comment 12

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/6590b3c23f48
Document the valid log levels for toolkit.telemetry.log.level r=chutten

Comment 13

[Chris H-C :chutten]

Well done on the patch! I have sent it to autoland where it will be built and tested and then included in the next Nightly build of the firefox source docs: http://firefox-source-docs.mozilla.org/

Logger's logic is even more complicated for log levels than you learned, if you're interested. For instance, there's this structure[1] that permits the use of numerical log levels (which is why we referenced 0 in the docs) but our preference code depends on the type of the pref being set correctly (to String). It's better practice just to specify strings anyway :)

Do you have an idea of what you'd like to work on next, or would you like help finding something new? If you'd like help, let me know what kinds of things you might want to work on and I'll see if I can find something related.

[1]: https://searchfox.org/mozilla-central/rev/2466b82b729765fb0a3ab62f812c1a96a7362478/toolkit/modules/Log.jsm#45

Comment 14

[Arthur Iakab [arthur_iakab]]

https://hg.mozilla.org/mozilla-central/rev/6590b3c23f48

Comment 15

[Thi Huynh]

(In reply to Chris H-C :chutten from comment #13)
> Do you have an idea of what you'd like to work on next, or would you like
> help finding something new? If you'd like help, let me know what kinds of
> things you might want to work on and I'll see if I can find something
> related.

Greate, I'd like to work on the Javascript Engine or Telemetry. Do you know any bug that requires more investigations into the architecture of those components?

BTW, my preferred language is C++ :) .

Comment 16

[Chris H-C :chutten]

If you find it interesting, you could take over bug 1374631 which is C++ and close to complete. It's been sitting idle a while so it would benefit from a fresh pair of eyes.

Something larger would be a wishlist for improving an API in bug 1289094. It will involve adding parameters to a JS API and improving its capabilities.

Or maybe something more clearly scoped would be adding a C++ API for Telemetry Events in bug 1313327.

Comment 17

[Thi Huynh]

(In reply to Chris H-C :chutten from comment #16)
> If you find it interesting, you could take over bug 1374631 which is C++ and
> close to complete. It's been sitting idle a while so it would benefit from a
> fresh pair of eyes.
> 
> Something larger would be a wishlist for improving an API in bug 1289094. It
> will involve adding parameters to a JS API and improving its capabilities.
> 
> Or maybe something more clearly scoped would be adding a C++ API for
> Telemetry Events in bug 1313327.

Excellent, thank you very much!