1113779 - UserCustomizations.jsm spams desktop mochitest test logs

Status: RESOLVED FIXED

(Firefox OS Graveyard :: General, defect)

Description

[:Gijs (he/him)]

Random example:

http://ftp.mozilla.org/pub/mozilla.org/firefox/tinderbox-builds/fx-team-linux/1419013123/fx-team_ubuntu32_vm_test-mochitest-browser-chrome-1-bm03-tests1-linux32-build253.txt.gz

10:45:44     INFO -  -*-*- UserCustomizations (parent): document created: http://tracking.example.org/browser/browser/base/content/test/general/benignPage.html

times many thousands.

Can we please disable this logging by default, and enable it only in relevant tests?

I'm not even entirely sure why this module is shipped on desktop at all, but that is its own issue.

Comment 1

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

Fabrice, can you suggest a fix here? This generates a huge amount of spam, to the point that it's hard to do printf debugging while running tests.

It looks like this code is getting tested on desktop because there's some problem that makes it impossible to run the tests on b2g. Is that right? Could we perhaps only enable the customizations while running the marketplace tests? It looks like the code doesn't allow that right now, but maybe it wouldn't be too hard.

Comment 2

[[:fabrice] Fabrice Desré]

Attachment: debug-customizations.patch

Bill, I didn't test locally, but it's simple enough and will show debug messages only when running the UserCustomizations.jsm tests.

Comment 3

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

Comment on attachment 8545707 [details] [diff] [review]
debug-customizations.patch

Review of attachment 8545707 [details] [diff] [review]:
-----------------------------------------------------------------

::: dom/apps/UserCustomizations.jsm
@@ +36,5 @@
>    *  }
>    * ]
>    */
>  
> +let debug = Services.prefs.getBoolPref("dom.mozApps.customizations.debug")

I don't think this will work. |debug| is assigned once when the module is loaded. The pref will presumably be false then. After that, even if the pref is enabled, debug will continue to refer to the disabled version of the function.

I think you have to check the pref every time the function is called or else use a pref observer to modify the value of |debug|.

Comment 4

[Nathan Froyd [:froydnj]]

Attachment: eliminate test logging spam from UserCustomizations.jsm

I got tired of seeing this in my local mochitest runs, so I updated the patch
according to Bill's suggestion.  It would be nice if other modules could do the
same thing (Webapps.jsm comes to mind), but that can be a separate bug.

Instead of determining the debugging helper for UserCustomizations.jsm
at module import time, register a preference observer so that we can
change the debugging helper on the fly.

Comment 5

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

I don't think this is quite right. We need to update the value of |debug| in the pref observer. I think we also need to remove the pref observer at shutdown.

Fabrice, is it okay to just disable this logging in tests? It doesn't seem worth all the time we're putting into it.

Comment 6

[Andrew McCreight [:mccr8]]

About one third of the entire Mochitest 5 log is a single "document created" UserCustomizations line, from a large data URI.  If we don't enable it, we should at least truncate what gets printed out a little.

Comment 7

[Andrew McCreight [:mccr8]]

(In reply to Andrew McCreight [:mccr8] from comment #6)
> If we don't enable it
This should read _disable it_ of course.

Comment 8

[[:fabrice] Fabrice Desré]

Attachment: usercustom-logs.patch

Untested yet, but this patch disables logging in this file by default, and let test opt-in through SpecialPowers.

Comment 9

[Andrew McCreight [:mccr8]]

Comment on attachment 8550513 [details] [diff] [review]
usercustom-logs.patch

I tested this locally and it fixes the spam.  There's still some of the
-*-*- Langpacks: getAdditionalLanguages http://example.org/manifest.webapp
-*-*- Langpacks: Languages found: ({langs:{}})
stuff but maybe that's unrelated.  In any event, that doesn't seem to be per-test.

Comment 10

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

Thanks Fabrice. It looks like the Langpacks stuff comes from Langpacks.jsm. Can we give that one the same treatment?

Comment 11

[Andrew McCreight [:mccr8]]

Comment on attachment 8550513 [details] [diff] [review]
usercustom-logs.patch

Review of attachment 8550513 [details] [diff] [review]:
-----------------------------------------------------------------

Looks reasonable to me.  It seems a bit brittle but I guess it is better than what we have now. ;)

Comment 12

[[:fabrice] Fabrice Desré]

https://hg.mozilla.org/integration/b2g-inbound/rev/e5a20f32cbef

Comment 14

[Phil Ringnalda (:philor)]

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