Should we make content console messages print to stdout when browser.dom.window.dump.enabled is true?

[Brian Grinstead]

In Bug 1439686 we started printing chrome console messages to stdout. At that time we restricted it to chrome callers to avoid extra noise in stdout during local builds - especially since filtering out content messages is a much-requested feature for the Browser Console (Bug 1260877).

Interestingly, a page can already get text out to stdout if browser.dom.window.dump.enabled is true using `window.dump`. But the output isn't great when dealing with objects, and it requires the page to change its code.

We got a request to enable this for console.log in Bug 1480544 - I'm curious if people have opinions on if/how this should be exposed. Should the output be controlled based on the browser.dom.window.dump.enabled pref? Should we have a second pref controlling itf? Something else?

Thanks,
Brian

[Mike Hommey]

On Fri, Aug 03, 2018 at 12:15:50PM +1000, Mark Hammond wrote:

> This is tricky. I use dump() more than I'd care to admit - it works well in
> content code because you almost never see dump() used in real sites (does
> Chrome even support it?), so there's not a huge amount of "spam" in the
> terminal. Having dump() output from *both* chrome and content can be very
> helpful.
>
> If we also wrote console.log() from content to the terminal, I fear we would
> then end up in a situation where content spams the terminal, with the only
> mitigation being to flip browser.dom.window.dump.enabled to false - but that
> means we also lose dump() output, throwing the baby out with the bathwater.
>
> So my vote would be:
>
> * Leave dump alone - it's basically a firefox-specific easter-egg and no one
> seems to mind that content *could* spam the terminal because it almost never
> does. (I know this wasn't proposed, but it's worth clarifying imo)
>
> * A new pref that would allow content console.* output to be written to this
> terminal. I'd be fine with this defaulting to true wherever
> browser.dom.window.dump.enabled does.
>
> Having "dump" in the name of this pref wouldn't be a good option, because
> IMO, it should *not* affect the behaviour of dump()

There's javascript.options.showInConsole, too, but I'm not sure it does
anything these days, despite being defined in all.js, firefox.js and
other places, it seems it was made a no-op by the error console removal
in bug 1278368.

Mike

[Brian Grinstead]

That makes sense to me - having a secondary pref would let us avoid spamming stdout in local builds and in automation (assuming it defaulted to false in both cases).

> On Aug 2, 2018, at 7:15 PM, Mark Hammond <skippy....@gmail.com> wrote:
>
>> On 3/08/2018 5:16 am, Brian Grinstead wrote:
>> In Bug 1439686 we started printing chrome console messages to stdout. At that time we restricted it to chrome callers to avoid extra noise in stdout during local builds - especially since filtering out content messages is a much-requested feature for the Browser Console (Bug 1260877).
>> Interestingly, a page can already get text out to stdout if browser.dom.window.dump.enabled is true using `window.dump`. But the output isn't great when dealing with objects, and it requires the page to change its code.
>> We got a request to enable this for console.log in Bug 1480544 - I'm curious if people have opinions on if/how this should be exposed. Should the output be controlled based on the browser.dom.window.dump.enabled pref? Should we have a second pref controlling itf? Something else?
>
> This is tricky. I use dump() more than I'd care to admit - it works well in content code because you almost never see dump() used in real sites (does Chrome even support it?), so there's not a huge amount of "spam" in the terminal. Having dump() output from *both* chrome and content can be very helpful.
>
> If we also wrote console.log() from content to the terminal, I fear we would then end up in a situation where content spams the terminal, with the only mitigation being to flip browser.dom.window.dump.enabled to false - but that means we also lose dump() output, throwing the baby out with the bathwater.
>
> So my vote would be:
>
> * Leave dump alone - it's basically a firefox-specific easter-egg and no one seems to mind that content *could* spam the terminal because it almost never does. (I know this wasn't proposed, but it's worth clarifying imo)
>
> * A new pref that would allow content console.* output to be written to this terminal. I'd be fine with this defaulting to true wherever browser.dom.window.dump.enabled does.
>
> Having "dump" in the name of this pref wouldn't be a good option, because IMO, it should *not* affect the behaviour of dump()
>

> My-$0.02-ly,
>
> Mark
> _______________________________________________
> firefox-dev mailing list
> firef...@mozilla.org
> https://mail.mozilla.org/listinfo/firefox-dev

[Brian Grinstead]

Huh - must have missed that during error console removal. I don’t think the pref name fits close enough with this proposed behavior to reuse it, so I’ll file a bug to remove it.

Brian

> On Aug 2, 2018, at 7:25 PM, Mike Hommey <m...@glandium.org> wrote:

>
>> On Fri, Aug 03, 2018 at 12:15:50PM +1000, Mark Hammond wrote:
>>> On 3/08/2018 5:16 am, Brian Grinstead wrote:
>>> In Bug 1439686 we started printing chrome console messages to stdout. At that time we restricted it to chrome callers to avoid extra noise in stdout during local builds - especially since filtering out content messages is a much-requested feature for the Browser Console (Bug 1260877).
>>>
>>> Interestingly, a page can already get text out to stdout if browser.dom.window.dump.enabled is true using `window.dump`. But the output isn't great when dealing with objects, and it requires the page to change its code.
>>>
>>> We got a request to enable this for console.log in Bug 1480544 - I'm curious if people have opinions on if/how this should be exposed. Should the output be controlled based on the browser.dom.window.dump.enabled pref? Should we have a second pref controlling itf? Something else?
>>
>> This is tricky. I use dump() more than I'd care to admit - it works well in
>> content code because you almost never see dump() used in real sites (does
>> Chrome even support it?), so there's not a huge amount of "spam" in the
>> terminal. Having dump() output from *both* chrome and content can be very
>> helpful.
>>
>> If we also wrote console.log() from content to the terminal, I fear we would
>> then end up in a situation where content spams the terminal, with the only
>> mitigation being to flip browser.dom.window.dump.enabled to false - but that
>> means we also lose dump() output, throwing the baby out with the bathwater.
>>
>> So my vote would be:
>>
>> * Leave dump alone - it's basically a firefox-specific easter-egg and no one
>> seems to mind that content *could* spam the terminal because it almost never
>> does. (I know this wasn't proposed, but it's worth clarifying imo)
>>
>> * A new pref that would allow content console.* output to be written to this
>> terminal. I'd be fine with this defaulting to true wherever
>> browser.dom.window.dump.enabled does.
>>
>> Having "dump" in the name of this pref wouldn't be a good option, because
>> IMO, it should *not* affect the behaviour of dump()
>

> There's javascript.options.showInConsole, too, but I'm not sure it does
> anything these days, despite being defined in all.js, firefox.js and
> other places, it seems it was made a no-op by the error console removal
> in bug 1278368.
>
> Mike

[Eric Rahm]

Note the console message service also has 'consoleservice.logcat' [1] for
android that dumps to logcat at the appropriate log levels when enabled (I
believe it's enabled by default for nightly), we had a similar
implementation for b2g as well [2] that covered the mapping of console
functions to log levels. Our gecko logging code prefixes log levels [3] and
supports logging only certain levels [4] to keep verbosity down, this might
be something worth reusing.

In general, please keep this pref opt-in and disabled by default in
automation to avoid excessive log spam.

-e

[1]
https://searchfox.org/mozilla-central/rev/3fdc491e118c5cdfbaf6e2d52f3466d2b27ad1de/xpcom/base/nsConsoleService.cpp#153-161
[2] https://bugzilla.mozilla.org/show_bug.cgi?format=default&id=1060171
[3]
https://searchfox.org/mozilla-central/rev/3fdc491e118c5cdfbaf6e2d52f3466d2b27ad1de/xpcom/base/Logging.cpp#88-105
[4]
https://developer.mozilla.org/en-US/docs/Mozilla/Developer_guide/Gecko_Logging#Logging_interface

On Fri, Aug 3, 2018 at 7:40 AM, Brian Grinstead <bgrin...@mozilla.com>
wrote:

[Brian Grinstead]

Filed a bug to remove the pref at https://bugzilla.mozilla.org/show_bug.cgi?id=1481898 <https://bugzilla.mozilla.org/show_bug.cgi?id=1481898>.

[Brian Grinstead]

Based on the discussion here and on the bug, I do think there’s value in being able to separately control chrome and content logs going to stdout. I’m leaning towards either:

1) Keep the current behavior for chrome callers and then add a second pref (false by default everywhere) to allow content logs to go out to stdout.
2) Stop overloading `browser.dom.window.dump.enabled`, and instead add two new prefs like `devtools.console.stdout.chrome` and `devtools.console.stdout.content`. The chrome variation would be true by default in local builds and automation, I guess, and the content variation would be false by default everywhere.

Brian

> On Aug 6, 2018, at 11:21 AM, Eric Rahm <er...@mozilla.com> wrote:
>
> Note the console message service also has 'consoleservice.logcat' [1] for android that dumps to logcat at the appropriate log levels when enabled (I believe it's enabled by default for nightly), we had a similar implementation for b2g as well [2] that covered the mapping of console functions to log levels. Our gecko logging code prefixes log levels [3] and supports logging only certain levels [4] to keep verbosity down, this might be something worth reusing.
>
> In general, please keep this pref opt-in and disabled by default in automation to avoid excessive log spam.
>
> -e
>
> [1] https://searchfox.org/mozilla-central/rev/3fdc491e118c5cdfbaf6e2d52f3466d2b27ad1de/xpcom/base/nsConsoleService.cpp#153-161
> [2] https://bugzilla.mozilla.org/show_bug.cgi?format=default&id=1060171
> [3] https://searchfox.org/mozilla-central/rev/3fdc491e118c5cdfbaf6e2d52f3466d2b27ad1de/xpcom/base/Logging.cpp#88-105
> [4] https://developer.mozilla.org/en-US/docs/Mozilla/Developer_guide/Gecko_Logging#Logging_interface
>

[Andreas Tolfsen]

Hi, sorry for chiming in late.

dump() is used extensively for logging through Log.jsm, and that
again is used in a lot of our test automation.

Also sprach Brian Grinstead:

> Based on the discussion here and on the bug, I do think there’s
> value in being able to separately control chrome and content logs
> going to stdout. I’m leaning towards either:
>
> 1) Keep the current behavior for chrome callers and then add a
> second pref (false by default everywhere) to allow content logs to
> go out to stdout.

Sorry, maybe this is a stupid question, but what exactly is a “chrome
caller” and how is it differentiated from a JSM using dump()?

> 2) Stop overloading `browser.dom.window.dump.enabled`, and instead
> add two new prefs like `devtools.console.stdout.chrome` and
> `devtools.console.stdout.content`. The chrome variation would be
> true by default in local builds and automation, I guess, and the
> content variation would be false by default everywhere.

Being able to differentiate between web content uses of window.dump()
and those originating from privileged JS seems reasonable, but why
devtools.console.*? Is dump() specific to devtools?

[Brian Grinstead]

> On Aug 13, 2018, at 8:36 AM, Andreas Tolfsen <a...@sny.no> wrote:
>
> Hi, sorry for chiming in late.
>
> dump() is used extensively for logging through Log.jsm, and that
> again is used in a lot of our test automation.

`dump` behavior won’t change regardless of any changes here.

> Also sprach Brian Grinstead:
>
>> Based on the discussion here and on the bug, I do think there’s
>> value in being able to separately control chrome and content logs
>> going to stdout. I’m leaning towards either:
>>
>> 1) Keep the current behavior for chrome callers and then add a
>> second pref (false by default everywhere) to allow content logs to
>> go out to stdout.
>
> Sorry, maybe this is a stupid question, but what exactly is a “chrome
> caller” and how is it differentiated from a JSM using dump()?

This is referring to chrome callers (i.e. JSMs or any other chrome-priv JS code) of `console.log` (distinct from callers to `dump`). FWIW for most cases, I’d recommend to use console.log() in chrome code instead of dump() - it shows up in the Browser Console, does a better job of formatting objects, and supports multiple arguments.

>> 2) Stop overloading `browser.dom.window.dump.enabled`, and instead
>> add two new prefs like `devtools.console.stdout.chrome` and
>> `devtools.console.stdout.content`. The chrome variation would be
>> true by default in local builds and automation, I guess, and the
>> content variation would be false by default everywhere.
>
> Being able to differentiate between web content uses of window.dump()
> and those originating from privileged JS seems reasonable, but why
> devtools.console.*? Is dump() specific to devtools?

This would only affect callers of `console.log`. It’s all a bit confusing though, since we are currently overloading the dump pref (browser.dom.window.dump.enabled) to also print chrome `console.log` messages to stdout. The idea of creating `devtools.console` prefs is to (a) stop that overloading, and to (b) give more fine-grained control over what goes out to stdout. I don’t feel too strongly about (a) - if we wanted to continue overloading the dump pref for that it'd be fine with me. But I think (b) is necessary to prevent spamming stdout with content console.log messages when the dump pref is set.

Brian

[Brian Grinstead]

To follow up on this, https://bugzilla.mozilla.org/show_bug.cgi?id=1480544
has now landed, which has decoupled Console printing from the dump pref. To
sum up:

* browser.dom.window.dump.enabled continues to enable the dump() function
in windows, workers and worklets, and the default values have remained
unchanged.

2 new prefs were added to control printing of Console API calls:

* devtools.console.stdout.chrome enables the stdout logging in console API
when used in chrome contexts. It is defaulted to the same value as
`browser.dom.window.dump.enabled`, so chrome console.log will continue to
go to stdout in local builds, automation, etc.
* devtools.console.stdout.content enables the stdout logging in console API
when used in content contexts. It is false by default everywhere, so this
feature will only be enabled with a manual override.

Brian

On Mon, Aug 13, 2018 at 10:01 AM Brian Grinstead <bgrin...@mozilla.com>
wrote: