Kris Maglione [:kmag] Assignee
	Description • 6 years ago

We currently have several modules that load Console.jsm into every content process for routine logging. I don't really object to loading it in exceptional circumstances, but it shouldn't ever be loaded in content processes by default.

	Matthew N. [:MattN]
	Comment 3 • 6 years ago

Are you aware of bug 1430810 and deps? I think that's a better solution which removes Console.jsm altogether but still allows debug logging from content processes. Thoughts?

	Kris Maglione [:kmag] Assignee
	Comment 4 • 6 years ago

(In reply to Matthew N. [:MattN] (PM if requests are blocking you) from comment #3)
> Are you aware of bug 1430810 and deps? I think that's a better solution
> which removes Console.jsm altogether but still allows debug logging from
> content processes. Thoughts?

I think that's fine, but I'd rather not wait for it. Even the web console API is expensive (both in terms of perf and in terms of memory), so I think we want these changes anyway. The second patch doesn't really change any behavior when debugging is enabled. The first patch does, but I think that many debug log calls in a core JS API like this are a bad idea anyway.

	Matthew N. [:MattN]
	Comment 5 • 6 years ago

(In reply to Kris Maglione [:kmag] from comment #4)
> (In reply to Matthew N. [:MattN] (PM if requests are blocking you) from
> comment #3)
> > Are you aware of bug 1430810 and deps? I think that's a better solution
> > which removes Console.jsm altogether but still allows debug logging from
> > content processes. Thoughts?
> 
> I think that's fine, but I'd rather not wait for it. 

Note that you don't need to wait for that bug if you want to avoid using Console.jsm, the dependencies that added support for `console.createInstance(opts);` already landed.

> Even the web console
> API is expensive (both in terms of perf and in terms of memory), so I think
> we want these changes anyway. The second patch doesn't really change any
> behavior when debugging is enabled. 

Right, unfortunately it adds complexity though.

	Matthew N. [:MattN]
	Comment 6 • 6 years ago
mozreview-review

Comment on attachment 8987717 [details]
Bug 1470333: Part 1 - Optimize debug logging statements in FormAutoFillContent.

https://reviewboard.mozilla.org/r/252964/#review259718

> The first patch does, but I think that
> many debug log calls in a core JS API like this are a bad idea anyway.

The number of callsites isn't what's important though, most of the logging you're removing is really useful for debugging and isn't on hot code paths so I'd rather you only remove the logging that causes a load without user interaction with the page. I think removing ensureRegistered and ensureUnregistered may be enough.

I also think you can switch to using console.createInstance as a drop-in replacement now so fix the memory issue even when the user interacts.

	Kris Maglione [:kmag] Assignee
	Comment 7 • 6 years ago

(In reply to Matthew N. [:MattN] (PM if requests are blocking you) from comment #6)
> Comment on attachment 8987717 [details]
> Bug 1470333: Part 1 - Remove debug logging statements from
> FormAutoFillContent.
> 
> https://reviewboard.mozilla.org/r/252964/#review259718
> 
> > The first patch does, but I think that
> > many debug log calls in a core JS API like this are a bad idea anyway.
> 
> The number of callsites isn't what's important though, most of the logging
> you're removing is really useful for debugging and isn't on hot code paths
> so I'd rather you only remove the logging that causes a load without user
> interaction with the page. I think removing ensureRegistered and
> ensureUnregistered may be enough.
> 
> I also think you can switch to using console.createInstance as a drop-in
> replacement now so fix the memory issue even when the user interacts.

That would probably be an improvement, but creating a console instance (and the requisite prototype objects) would still be quite expensive. So would the logging calls.

And I'm generally opposed to system code emitting any logging during normal operation.

If we really need to keep these calls, I'd rather put them behind a pref, and make the log function a no-op unless it's set.

	Matthew N. [:MattN]
	Comment 10 • 6 years ago
mozreview-review

Comment on attachment 8987717 [details]
Bug 1470333: Part 1 - Optimize debug logging statements in FormAutoFillContent.

https://reviewboard.mozilla.org/r/252964/#review261132

::: browser/extensions/formautofill/FormAutofillUtils.jsm:49
(Diff revision 2)
>  ChromeUtils.import("resource://gre/modules/Services.jsm");
>  ChromeUtils.defineModuleGetter(this, "CreditCard",
>    "resource://gre/modules/CreditCard.jsm");
>  
> +XPCOMUtils.defineLazyPreferenceGetter(this, "logLevel", "extensions.formautofill.loglevel",
> +                                      "error");

This should be "Warn" (upper-case first) to match firefox.js

	Matthew N. [:MattN]
	Comment 11 • 6 years ago
mozreview-review

Comment on attachment 8987718 [details]
Bug 1470333: Part 2 - Avoid creating ConsoleAPI instances when debug logging is not enabled.

https://reviewboard.mozilla.org/r/252966/#review259736

Sorry, for the delay, I somehow missed the new version.

	Matthew N. [:MattN]
	Comment 12 • 6 years ago
mozreview-review

Comment on attachment 8987718 [details]
Bug 1470333: Part 2 - Avoid creating ConsoleAPI instances when debug logging is not enabled.

https://reviewboard.mozilla.org/r/252966/#review261312

::: commit-message-c1016:1
(Diff revision 2)
> +Bug 1470333: Part 2 - Avoid creating ConsoleAPI instances when debug logging is not enabled. r?MattN

Don't forget to remove the line at https://dxr.mozilla.org/mozilla-central/rev/9c02d2ecf22050bfee5d70c04a359d8aaff6eb91/browser/base/content/test/performance/browser_startup_content.js#45 if this is the last use of Console.jsm at content process startup.

	Kris Maglione [:kmag] Assignee
	Comment 13 • 6 years ago

https://hg.mozilla.org/integration/mozilla-inbound/rev/440ee3fab72afc5d483a5bb2b0630f3c2ed3212f
Bug 1470333: Part 1 - Optimize debug logging statements in FormAutoFillContent. r=MattN

https://hg.mozilla.org/integration/mozilla-inbound/rev/dbea1942a32f8bd565f3d500d79fa19db8916fcc
Bug 1470333: Part 2 - Avoid creating ConsoleAPI instances when debug logging is not enabled. r=MattN

	Cristina Coroiu [:ccoroiu]
	Comment 14 • 6 years ago

Backed out 2 changesets (bug 1470333) for xpcshell failures at browser/extensions/formautofill/test/unit/test_getFormInputDetails.js, browser/extensions/formautofill/test/unit/test_markAsAutofillField.js, browser/extensions/formautofill/test/unit/test_onFormSubmitted.js

Backout: https://hg.mozilla.org/integration/mozilla-inbound/rev/90a554d452ebac7d7d7c967de09776abf1993629

Failure push: https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&revision=dbea1942a32f8bd565f3d500d79fa19db8916fcc

Failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=186501087&repo=mozilla-inbound&lineNumber=2071

task 2018-07-04T21:15:45.495Z]     INFO -  TEST-START | browser/extensions/formautofill/test/unit/test_markAsAutofillField.js
[task 2018-07-04T21:15:46.284Z]  WARNING -  TEST-UNEXPECTED-FAIL | browser/extensions/formautofill/test/unit/test_markAsAutofillField.js | xpcshell return code: 0
[task 2018-07-04T21:15:46.285Z]     INFO -  TEST-INFO took 786ms
[task 2018-07-04T21:15:46.286Z]     INFO -  >>>>>>>
[task 2018-07-04T21:15:46.287Z]     INFO -  PID 7970 | JavaScript strict warning: /builds/worker/workspace/build/tests/xpcshell/tests/browser/extensions/formautofill/test/unit/head.js -> resource://testing-common/sinon-2.3.2.js, line 8941: ReferenceError: reference to undefined property "iso-8859-8-i"
[task 2018-07-04T21:15:46.287Z]     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2018-07-04T21:15:46.288Z]     INFO -  (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2018-07-04T21:15:46.288Z]     INFO -  (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2018-07-04T21:15:46.289Z]     INFO -  running event loop
[task 2018-07-04T21:15:46.290Z]     INFO -  "CONSOLE_MESSAGE: (warn) [JavaScript Warning: "ReferenceError: reference to undefined property "iso-8859-8-i"" {file: "/builds/worker/workspace/build/tests/xpcshell/tests/browser/extensions/formautofill/test/unit/head.js -> resource://testing-common/sinon-2.3.2.js" line: 8941}]"
[task 2018-07-04T21:15:46.290Z]     INFO -  "CONSOLE_MESSAGE: (warn) [JavaScript Warning: "Bootstrapped manifest not allowed to use 'resource' directive." {file: "jar:file:///builds/worker/workspace/build/application/firefox/browser/features/formautofill@mozilla.org.xpi!/chrome.manifest" line: 7}]"
[task 2018-07-04T21:15:46.291Z]     INFO -  browser/extensions/formautofill/test/unit/test_markAsAutofillField.js | Starting head_initialize
[task 2018-07-04T21:15:46.292Z]     INFO -  (xpcshell/head.js) | test head_initialize pending (2)
[task 2018-07-04T21:15:46.292Z]     INFO -  (xpcshell/head.js) | test run_next_test 0 finished (2)
[task 2018-07-04T21:15:46.298Z]     INFO -  (xpcshell/head.js) | test run_next_test 1 pending (2)
[task 2018-07-04T21:15:46.298Z]     INFO -  (xpcshell/head.js) | test head_initialize finished (2)
[task 2018-07-04T21:15:46.299Z]     INFO -  browser/extensions/formautofill/test/unit/test_markAsAutofillField.js | Starting
[task 2018-07-04T21:15:46.300Z]     INFO -  (xpcshell/head.js) | test pending (2)
[task 2018-07-04T21:15:46.300Z]     INFO -  "Starting testcase: Form containing 8 fields with autocomplete attribute."
[task 2018-07-04T21:15:46.301Z]     INFO -  (xpcshell/head.js) | test run_next_test 1 finished (2)
[task 2018-07-04T21:15:46.301Z]     INFO -  Unexpected exception TypeError: element.ownerDocument.location is null at resource://formautofill/FormAutofillContent.jsm:533
[task 2018-07-04T21:15:46.301Z]     INFO -  identifyAutofillFields@resource://formautofill/FormAutofillContent.jsm:533:5
[task 2018-07-04T21:15:46.303Z]     INFO -  @/builds/worker/workspace/build/tests/xpcshell/tests/browser/extensions/formautofill/test/unit/test_markAsAutofillField.js:77:5
[task 2018-07-04T21:15:46.303Z]     INFO -  async*run_next_test/_run_next_test/<@/builds/worker/workspace/build/tests/xpcshell/head.js:1440:22
[task 2018-07-04T21:15:46.303Z]     INFO -  async*_run_next_test@/builds/worker/workspace/build/tests/xpcshell/head.js:1440:10
[task 2018-07-04T21:15:46.304Z]     INFO -  run@/builds/worker/workspace/build/tests/xpcshell/head.js:691:9
[task 2018-07-04T21:15:46.304Z]     INFO -  _do_main@/builds/worker/workspace/build/tests/xpcshell/head.js:219:3
[task 2018-07-04T21:15:46.305Z]     INFO -  _execute_test@/builds/worker/workspace/build/tests/xpcshell/head.js:532:5
[task 2018-07-04T21:15:46.306Z]     INFO -  @-e:1:1
[task 2018-07-04T21:15:46.307Z]     INFO -  exiting test
[task 2018-07-04T21:15:46.307Z]     INFO -  <<<<<<<
[task 2018-07-04T21:15:46.316Z]     INFO -  TEST-START | browser/extensions/formautofill/test/unit/test_onFormSubmitted.js
[task 2018-07-04T21:15:47.121Z]  WARNING -  TEST-UNEXPECTED-FAIL | browser/extensions/formautofill/test/unit/test_onFormSubmitted.js | xpcshell return code: 0
[task 2018-07-04T21:15:47.121Z]     INFO -  TEST-INFO took 802ms
[task 2018-07-04T21:15:47.121Z]     INFO -  >>>>>>>
[task 2018-07-04T21:15:47.121Z]     INFO -  PID 7987 | JavaScript strict warning: /builds/worker/workspace/build/tests/xpcshell/tests/browser/extensions/formautofill/test/unit/head.js -> resource://testing-common/sinon-2.3.2.js, line 8941: ReferenceError: reference to undefined property "iso-8859-8-i"
[task 2018-07-04T21:15:47.123Z]     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2018-07-04T21:15:47.123Z]     INFO -  (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2018-07-04T21:15:47.123Z]     INFO -  (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2018-07-04T21:15:47.123Z]     INFO -  running event loop

	Kris Maglione [:kmag] Assignee
	Comment 15 • 6 years ago

https://hg.mozilla.org/integration/mozilla-inbound/rev/2e81ac623b787f8ffa2cf2b1cd7f80d8d149d5a0
Bug 1470333: Part 1 - Optimize debug logging statements in FormAutoFillContent. r=MattN

https://hg.mozilla.org/integration/mozilla-inbound/rev/b1e3cd7db269d4cc9c61e754a95169da46213dc2
Bug 1470333: Part 2 - Avoid creating ConsoleAPI instances when debug logging is not enabled. r=MattN

	Andrei Ciure[:aciure]
	Comment 16 • 6 years ago
bugherder

https://hg.mozilla.org/mozilla-central/rev/2e81ac623b78
https://hg.mozilla.org/mozilla-central/rev/b1e3cd7db269