1923985 - Unify Console and MOZ_LOG levels

Status: RESOLVED FIXED

(DevTools :: Console, enhancement, P3)

Description

[Alexandre Poirot [:ochameau]]

Bug 1828100 is wiring the console API to MOZ_LOG.
But this is brittle around log level as MOZ_LOG level is used to control actual logs of console api calls to MOZ_LOG,
but console.shouldLog(...) ignores the MOZ_LOG level.
Instead it relies on ConsoleInstance maxLogLevel optional argument.
This could create some confusion and prevents using console.shouldLog to avoid costly logging operation when you are considering using only the MOZ_LOG output of console API calls.

This bug is a followup based on this review discussion:
https://phabricator.services.mozilla.com/D224104?id=927367#inline-1250562

Comment 1

[Mark Banner (:standard8)]

With the change in bug 1828100, we are better integrating console logging with MOZ_LOG. After the change we'll be in the state where:

1. console.log etc will log to the browser console regardless.
2. Logging via a console.createInstance will log according to the passed maxLogLevel or maxLogLevelPref.
3. Enabling MOZ_LOG=console:5 or one of the prefixes for console.createInstance will log to the defined MOZ_LOG location (i.e. stdout, profiler, or a file). We also have the option to use preferences for enabling these.

In the case of 1 and 2, we also have devtools.console.stdout.chrome and devtools.console.stdout.content that determine if console messages are logged to stdout or not. For developer builds devtools.console.stdout.chrome defaults to true.

Hence for JavaScript, we'll now have two ways for logging to stdout, with different level options. My thoughts were could we drop maxLogLevel etc and only use the MOZ_LOG env/preferences to control the logging levels for console.createInstance?

Looking at it preference wise, it could simplify the random logging preferences that we have e.g. browser.search.log which is a boolean, browser.download.loglevel which is a string and other inconsistencies. The MOZ_LOG preferences are all logging.<prefix> which is much simpler, although you do need to know the prefix (though maybe we can add those as default prefs?). The slightly confusing thing would be that the C++ prefixes wouldn't log to the browser console, whereas the JavaScript ones would.

The potential downside though is that for console.createInstance prefixes we would loose the output of errors/warnings to the browser console, unless we also logged those to stdout by default. This might affect end users slightly. Generally there shouldn't be lots of those occurring, though it could make broken situations worse wrt performance.

We would probably have to do something special for general console.* logging so that it would always log to the browser console, or we would have to output that to stdout all the time.

Overall, there does seem to be some overlap in the situation after bug 1828100 which is why I was thinking about potentially unifying these, but it does appear there are various issues that we'll need to work through to get there.

Comment 2

[Alexandre Poirot [:ochameau]]

Attachment: Bug 1923985 - Control console message logging via MOZ_LOG only via MOZ_LOG level. r=standard8

That, instead of being only driven by console default level (hardcoded or via a specific pref).
The console messages won't be logged to MOZ_LOG if the they aren't enabled in MOZ_LOG.
This may lead to duplicated messages if console still logs to stdout.

Comment 3

[Alexandre Poirot [:ochameau]]

Attachment: Bug 1923985 - Prevent logging stacks from console messages logged via MOZ_LOG. r=standard8

These logs can be very noisy if you are logging raw data to stdout.

Comment 4

[Alexandre Poirot [:ochameau]]

I just submitted patch that drastically help using MOZ_LOG, at least to me.
The new logic makes a stronger split between MOZ_LOG and legacy console behavior.

Two new principles are applied:

• The logs will only be logged via MOZ_LOG if the log module is enabled in MOZ_LOG ecosystem.
• MOZ_LOG will ignore console.cpp internal level, so that you can get higher/lower level for MOZ_LOG compared to default console behavior.
  Which could be summary to: console logs to MOZ_LOG are controlled 100% by MOZ_LOG.

I'm also piling up another patch to disable the loggic of stack traces to stdout, they are actually hurting the readability of logs when logging data to stdout.

This doesn't really help move forward on getting rid of the two distinct logging mechanisms, but it makes MOZ_LOG logging of console messages more usable.

Comment 5

[Mark Banner (:standard8)]

(In reply to Alexandre Poirot [:ochameau] from comment #4)

I'm also piling up another patch to disable the loggic of stack traces to stdout, they are actually hurting the readability of logs when logging data to stdout.

I'm not sure which instances of stdout we're talking about here, but we do need to be careful for tests - we'll still need the stack traces for those.

Comment 6

[Alexandre Poirot [:ochameau]]

(In reply to Mark Banner (:standard8) from comment #5)

(In reply to Alexandre Poirot [:ochameau] from comment #4)

I'm also piling up another patch to disable the loggic of stack traces to stdout, they are actually hurting the readability of logs when logging data to stdout.

I'm not sure which instances of stdout we're talking about here, but we do need to be careful for tests - we'll still need the stack traces for those.

I'm being extra conservative. https://phabricator.services.mozilla.com/D280069 is the one patch disabling stacks logging to stdout by default,
and it only does that for logging Console API calls via MOZ_LOG.

MOZ_LOG="console:5" ./firefox would no longer log stacks for console api calls.
You would now have to do:
MOZ_LOG="console:5,jsstacks" ./firefox
to see the call stacks.

This doesn't change the default behavior of console api logging to stdout via devtools.console.stdout.content and devtools.console.stdout.chrome. Stacks are always logged to stdout and can't be turned off.

Comment 7

[Pulsebot]

Pushed by [e-mail]:
https://github.com/mozilla-firefox/firefox/commit/bbd0c2d60007
https://hg.mozilla.org/integration/autoland/rev/f70c74e0d24c
Control console message logging via MOZ_LOG only via MOZ_LOG level. r=Standard8
https://github.com/mozilla-firefox/firefox/commit/e4c7ba4b1b23
https://hg.mozilla.org/integration/autoland/rev/88650852cacc
Prevent logging stacks from console messages logged via MOZ_LOG. r=Standard8

Comment 8

[Cristian Tuns]

https://hg.mozilla.org/mozilla-central/rev/f70c74e0d24c
https://hg.mozilla.org/mozilla-central/rev/88650852cacc