1347217 - Big blobs of stuff dumped to stdout or stderr on startup

Status: RESOLVED FIXED

Description

[Boris Zbarsky [PTO through Aug 25, :bzbarsky, bz on IRC]]

The console.log calls in browser/extensions/deployment-checker/bootstrap.js are dumping huge blobs of stuff out to stdout or stderr (I didn't check which).  This is quite annoying, since it completely destroys terminal scrollback.

It's not clear to me why we're doing this, especially in non-debug builds.

Comment 1

[Dana Keeler (she/her) (use needinfo) (:keeler for reviews)]

Some debugging information will be helpful for QA to verify that this is working as intended when we deploy this as a go-faster add-on, but the deluge of output is definitely not helpful. I'll trim it down.

Comment 2

[Dana Keeler (she/her) (use needinfo) (:keeler for reviews)]

Attachment: bug 1347217 - lessen debug spew in deployment-checker

Review commit: https://reviewboard.mozilla.org/r/120188/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/120188/

Comment 3

[Boris Zbarsky [PTO through Aug 25, :bzbarsky, bz on IRC]]

We shouldn't be creating any stdout/stderr output at all in opt builds, generally.  Logging stuff to the browser console maybe makes sense.  Dumping it all out (maybe because the dump.enabled pref is set in my case?) really doesn't.

Comment 4

[Benjamin Smedberg]

console.log should be going to the browser console by default, no? I don't know why that would be going to stdout/stderr by default.

Comment 5

[Boris Zbarsky [PTO through Aug 25, :bzbarsky, bz on IRC]]

> I don't know why that would be going to stdout/stderr by default.

It generally doesn't.  But in this case it is, and the question is why.

Comment 6

[:Felipe Gomes (needinfo for replies!)]

Comment on attachment 8847187 [details]
bug 1347217 - lessen debug spew in deployment-checker

https://reviewboard.mozilla.org/r/120188/#review122118

::: browser/extensions/deployment-checker/bootstrap.js:234
(Diff revision 1)
>    console.log("deployment-checker payload:");
>    console.log(payload);

no need to keep the payload being logged either, if it's for QA folks.. The payload can be acessed in about:telemetry

Comment 7

[Boris Zbarsky [PTO through Aug 25, :bzbarsky, bz on IRC]]

The reason why is that this is using toolkit/modules/Console.jsm which has:

  log: createDumper("log"),

where createDumper is defined at http://searchfox.org/mozilla-central/rev/a5c2b278897272497e14a8481513fee34bbc7e2c/toolkit/modules/Console.jsm#472

This calls sendConsoleAPIMessage which presumably sends stuff to an actual console, and also unconditionally calls dumpMessage which calls console.dump().  This is defined as:

  this.dump = aConsoleOptions.dump || dump;

so everything gets dumped out to the terminal by default unless you passed in different console options.  And in this case your consoleID is "addon/[e-mail]" so presumably your console came from either addon-sdk/source/lib/toolkit/loader.js or addon-sdk/source/lib/sdk/console/plain-text.js.  The former passes no "dump" option.  The latter passes "dump: print", which will use whatever the "print" function was that was passed to the PlainTextConsole.  If you came via addon-sdk/source/lib/sdk/content/sandbox.js then the "print" function is null...

Anyway, the upshot is that if I'm reading this stuff correctly and this is the addon SDK console, we probably should never use its log() in opt builds.  :(

Comment 8

[Boris Zbarsky [PTO through Aug 25, :bzbarsky, bz on IRC]]

Or I guess the Console.jsm console.  I don't know why it feels the need to dump everything to stdout.  :(

Comment 9

[Boris Zbarsky [PTO through Aug 25, :bzbarsky, bz on IRC]]

And to the Android log.

And I would bet that this dump is unconditional even in opt builds, because we're a sandbox, so it ignores the window-specific dump.enabled pref.

Comment 10

[Dana Keeler (she/her) (use needinfo) (:keeler for reviews)]

Comment on attachment 8847187 [details]
bug 1347217 - lessen debug spew in deployment-checker

https://reviewboard.mozilla.org/r/120188/#review122118

Thanks! I also switched `console.log` to `Services.console.logStringMessage` which doesn't appear to output to stdout/stderr.

> no need to keep the payload being logged either, if it's for QA folks.. The payload can be acessed in about:telemetry

Good call.

Comment 11

[Dana Keeler (she/her) (use needinfo) (:keeler for reviews)]

Comment on attachment 8847187 [details]
bug 1347217 - lessen debug spew in deployment-checker

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/120188/diff/1-2/

Comment 12

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/b28b0312ed4e
lessen debug spew in deployment-checker r=Felipe

Comment 13

[Boris Zbarsky [PTO through Aug 25, :bzbarsky, bz on IRC]]

Thank you!

Comment 14

[Nicholas Nethercote [:njn]]

I have been seeing this output too. Thank you for the fix.

Comment 15

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/b28b0312ed4e

Comment 17

[Dana Keeler (she/her) (use needinfo) (:keeler for reviews)]

Comment on attachment 8847187 [details]
bug 1347217 - lessen debug spew in deployment-checker

Approval Request Comment
[Feature/Bug causing the regression]: bug 1346017
[User impact if declined]: unnecessary debug spew in the console
[Is this code covered by automated tests?]: no
[Has the fix been verified in Nightly?]: yes
[Needs manual test from QE? If yes, steps to reproduce]: no
[List of other uplifts needed for the feature/fix]: none
[Is the change risky?]: no
[Why is the change risky/not risky?]: this lessens some debug output and changes which "console" the logging uses
[String changes made/needed]: none

Comment 18

[Gerry Chang [:gchang]]

Comment on attachment 8847187 [details]
bug 1347217 - lessen debug spew in deployment-checker

Remove unnecessary debug logs in the console. Aurora54+ & Beta53+.

Comment 19

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/daf87d4151aa

Comment 20

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/releases/mozilla-beta/rev/da4e2f5a75dd

Comment 21

[Andrei Vaida [:avaida]]

Setting qe-verify- based on David's assessment on manual testing needs (see Comment 17).

Comment 22

[Julien Cristau [:jcristau]]

Comment on attachment 8847187 [details]
bug 1347217 - lessen debug spew in deployment-checker

release52+

Will this change also be made on the xpi we're going to ship through gofaster?

Comment 23

[Dana Keeler (she/her) (use needinfo) (:keeler for reviews)]

Yes, the xpi already has this change.

Comment 24

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-release/rev/0f3b930b3ef7