Big blobs of stuff dumped to stdout or stderr on startup

RESOLVED FIXED in Firefox 52

Status

()

defect
P1
normal
RESOLVED FIXED
3 years ago
2 years ago

People

(Reporter: bzbarsky, Assigned: keeler)

Tracking

Trunk
mozilla55
Points:
---
Dependency tree / graph
Bug Flags:
qe-verify -

Firefox Tracking Flags

(firefox52 fixed, firefox53 fixed, firefox54 fixed, firefox55 fixed)

Details

(Whiteboard: [psm-assigned])

Attachments

(1 attachment)

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.
Flags: needinfo?(dkeeler)
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.
Assignee: nobody → dkeeler
Flags: needinfo?(dkeeler)
Priority: -- → P1
Whiteboard: [psm-assigned]
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.
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.
> 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 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
Attachment #8847187 - Flags: review?(felipc) → review+
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/deployment-checker@mozilla.org" 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.  :(
Or I guess the Console.jsm console.  I don't know why it feels the need to dump everything to stdout.  :(
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 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.
Pushed by dkeeler@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/b28b0312ed4e
lessen debug spew in deployment-checker r=Felipe
I have been seeing this output too. Thank you for the fix.
https://hg.mozilla.org/mozilla-central/rev/b28b0312ed4e
Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla55
Duplicate of this bug: 1347364
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
Attachment #8847187 - Flags: approval-mozilla-release?
Attachment #8847187 - Flags: approval-mozilla-beta?
Attachment #8847187 - Flags: approval-mozilla-aurora?
Comment on attachment 8847187 [details]
bug 1347217 - lessen debug spew in deployment-checker

Remove unnecessary debug logs in the console. Aurora54+ & Beta53+.
Attachment #8847187 - Flags: approval-mozilla-beta?
Attachment #8847187 - Flags: approval-mozilla-beta+
Attachment #8847187 - Flags: approval-mozilla-aurora?
Attachment #8847187 - Flags: approval-mozilla-aurora+
Setting qe-verify- based on David's assessment on manual testing needs (see Comment 17).
Flags: qe-verify-
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?
Attachment #8847187 - Flags: approval-mozilla-release? → approval-mozilla-release+
Yes, the xpi already has this change.
Blocks: 1353364
You need to log in before you can comment on or make changes to this bug.