644419 - Console should have user-settable log limits for each message category

Status: RESOLVED FIXED

(DevTools :: General, defect)

Description

[Rob Campbell [:rc] (:robcee)]

Currently the Web Console has a single pref (devtools.hud.loglimit) controlling maximum number of retained lines. This maximum number includes items that may be hidden by the filter buttons, so it can be quite jarring if a user only sees 5 network requests and they start to disappear because there were 195 CSS errors even though they're invisible.

We should have prefs for each of JS/Web Developer, CSS and Network so someone trying to catch a network request doesn't have older items removed from the console when they start getting pruned by other message categories.

Comment 2

[Panos Astithas (he/him) [:past] (please ni?)]

Attachment: Proposed patch

The patch replaces devtools.hud.loglimit with four separate knobs, devtools.hud.loglimit.{console,network,cssparser,exception} (for consistency with the names in CATEGORY_CLASS_FRAGMENTS), adds a test, and updates a few more. For faster pruning I've changed the signature of a helper function, in order to take advantage of the fact that we prune on each console output.

Comment 3

[Rob Campbell [:rc] (:robcee)]

Comment on attachment 531032 [details] [diff] [review]
Proposed patch

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

// "devtools.hud.loglimit.<CATEGORY_CLASS_FRAGMENT>" preference.

what is <CATEGORY_CLASS_FRAGMENT>? I think I'd prefer to see the actual prefs enumerated here.

Overall, I think the patch looks good, but I'd like to see some additional tests for each class. Afaict, you're only testing the console pref and css.

Comment 4

[Panos Astithas (he/him) [:past] (please ni?)]

Attachment: Updated patch

Fixed comment and added more tests.

Comment 5

[Panos Astithas (he/him) [:past] (please ni?)]

The removal of the devtools.hud.loglimit knob was discussed in this thread: http://groups.google.com/group/mozilla.dev.apps.firefox/browse_thread/thread/582be2d9d19befd2#

Comment 6

[Rob Campbell [:rc] (:robcee)]

Comment on attachment 531566 [details] [diff] [review]
Updated patch

looks good.

I think you should add a comment to firefox.js to include a reference to these hidden prefs and explain what they can be used for.

with that...

Comment 7

[Panos Astithas (he/him) [:past] (please ni?)]

Attachment: Updated patch

Good idea, default preferences added.

Comment 8

[Panos Astithas (he/him) [:past] (please ni?)]

(In reply to comment #7)
> Created attachment 531885 [details] [diff] [review] [review]
> Updated patch
> 
> Good idea, default preferences added.

...or did you mean to keep them hidden and just put the comments in?

Comment 9

[Rob Campbell [:rc] (:robcee)]

I did originally, though we might as well put them in explicitly to aid discoverability.

Comment 10

[Rob Campbell [:rc] (:robcee)]

Comment on attachment 531885 [details] [diff] [review]
Updated patch

in browser_webconsole_bug_644419_log_limits.js

+  // Find the sentinel entry.
+  findLogEntry("testing Net limits");
+  // Fill the log with network messages.
+  let body = content.document.getElementsByTagName("body")[0];
+  for (let i = 0; i < 10; i++) {
+    var image = content.document.createElement("img");
+    image.src = "test-image.png?_fubar=" + i;
+    body.insertBefore(image, body.firstChild);
+  }
+  image.addEventListener("load", onImageLoad, true);
+}

adding the listener on the last image seems a bit iffy. I think it'll work, but you're betting on out-running the image load.

Anyway, this looks fine to me. Thanks for adding the additional tests. R+ with successful run through try server.

Comment 11

[Panos Astithas (he/him) [:past] (please ni?)]

(In reply to comment #10)
> flag: review?([e-mail]) => review+Comment on attachment 531885 [details] [diff] [review]
> [details] [review]
> Updated patch
> 
> in browser_webconsole_bug_644419_log_limits.js
> 
> +  // Find the sentinel entry.
> +  findLogEntry("testing Net limits");
> +  // Fill the log with network messages.
> +  let body = content.document.getElementsByTagName("body")[0];
> +  for (let i = 0; i < 10; i++) {
> +    var image = content.document.createElement("img");
> +    image.src = "test-image.png?_fubar=" + i;
> +    body.insertBefore(image, body.firstChild);
> +  }
> +  image.addEventListener("load", onImageLoad, true);
> +}
> 
> adding the listener on the last image seems a bit iffy. I think it'll work,
> but you're betting on out-running the image load.

I'm waiting for the images to load first, before I check for the relevant messages. I had to resort to this, since executeSoon() would fire before the network messages were displayed in the console. 

> Anyway, this looks fine to me. Thanks for adding the additional tests. R+
> with successful run through try server.

Will get one running as soon as I receive my commit access, thanks!

Comment 12

[:Gavin Sharp [email: [e-mail]]]

Comment on attachment 531885 [details] [diff] [review]
Updated patch

>diff --git a/browser/app/profile/firefox.js b/browser/app/profile/firefox.js

nit: don't repeat the same slightly-tweaked comment multiple times, just make it generic enough to put above all of the prefs, and group them together in a block.

>diff --git a/toolkit/components/console/hudservice/HUDService.jsm b/toolkit/components/console/hudservice/HUDService.jsm

>+function pruneConsoleOutputIfNecessary(aConsoleNode, aCategory)

>+    let prefBranch = Services.prefs.getBranch("devtools.hud.loglimit.");
>+    logLimit = prefBranch.getIntPref(CATEGORY_CLASS_FRAGMENTS[aCategory]);

Not new to your code, but one other thing worth changing while you're here:
Just use Services.prefs.getIntPref directly rather than getting a branch (with a local variable for the pref name if the line ends up too long).

Comment 13

[Panos Astithas (he/him) [:past] (please ni?)]

Attachment: Updated patch

Updated patch to address Gavin's comments, but still waiting for a try build. Gavin, should I ping you for a formal review after a successful run through try?

Comment 14

[:Gavin Sharp [email: [e-mail]]]

sure

Comment 15

[Panos Astithas (he/him) [:past] (please ni?)]

Attachment: Updated patch

Removed some whitespace fixes that crept in the last version. Try run was successful: http://tbpl.mozilla.org/?tree=Try&rev=00a257c7a45c

Comment 16

[:Gavin Sharp [email: [e-mail]]]

Comment on attachment 532957 [details] [diff] [review]
Updated patch

>diff --git a/toolkit/components/console/hudservice/HUDService.jsm b/toolkit/components/console/hudservice/HUDService.jsm

>  * Destroys lines of output if more lines than the allowed log limit are
>+ * present. The implementation takes advantage of the fact that the function is
>+ * called on each update to the console, by using the last message category to
>+ * limit the search for necessary pruning.

I don't understand this comment at all ("implementation takes advantage" and "last message" are just confusing). "Ensures that the number of message nodes of type aCategory don't exceed that category's line limit by removing old messages as needed." is more concise and accurate, I think?

>+ * @param integer aCategory
>+ *        The category of the last message that was displayed in the console.

Similarly, reference to "last message" is confusing. Just say "category of message nodes to limit" or something like that.

>diff --git a/toolkit/components/console/hudservice/tests/browser/browser_webconsole_bug_644419_log_limits.js b/toolkit/components/console/hudservice/tests/browser/browser_webconsole_bug_644419_log_limits.js

>+function testWebDevLimits(aEvent) {
>+  browser.removeEventListener(aEvent.type, arguments.callee, true);
>+
>+  gOldPref = 200;
>+  try {
>+    gOldPref = Services.prefs.getIntPref("devtools.hud.loglimit.console");
>+  }
>+  catch (ex) { }

Don't need the try/catch since you're adding a default pref value (applies to this block elsewhere in the test).

I'm a bit confused by these tests - you're adding a sentinel log entry, setting the limit pref to 10, and then adding ten more entries and testing that the sentinel entry is still there - but shouldn't it have been pushed out by the 10 new entries? What am I missing?

>+function testNetLimits(aEvent) {

>+  for (let i = 0; i < 10; i++) {
>+    var image = content.document.createElement("img");
>+    image.src = "test-image.png?_fubar=" + i;
>+    body.insertBefore(image, body.firstChild);
>+  }
>+  image.addEventListener("load", onImageLoad, true);

I don't see any guarantee that the last inserted image's onload will fire last, which seems like it could cause intermittent orange.

Comment 17

[Panos Astithas (he/him) [:past] (please ni?)]

Attachment: Updated patch

New version with review comments incorporated.

Comment 18

[Panos Astithas (he/him) [:past] (please ni?)]

(In reply to comment #16)
> Comment on attachment 532957 [details] [diff] [review] [review]
> Updated patch
> 
> >diff --git a/toolkit/components/console/hudservice/HUDService.jsm b/toolkit/components/console/hudservice/HUDService.jsm
> 
> >  * Destroys lines of output if more lines than the allowed log limit are
> >+ * present. The implementation takes advantage of the fact that the function is
> >+ * called on each update to the console, by using the last message category to
> >+ * limit the search for necessary pruning.
> 
> I don't understand this comment at all ("implementation takes advantage" and
> "last message" are just confusing). "Ensures that the number of message
> nodes of type aCategory don't exceed that category's line limit by removing
> old messages as needed." is more concise and accurate, I think?

Indeed, I've used your suggested wording.

> >+ * @param integer aCategory
> >+ *        The category of the last message that was displayed in the console.
> 
> Similarly, reference to "last message" is confusing. Just say "category of
> message nodes to limit" or something like that.

Done.

> >diff --git a/toolkit/components/console/hudservice/tests/browser/browser_webconsole_bug_644419_log_limits.js b/toolkit/components/console/hudservice/tests/browser/browser_webconsole_bug_644419_log_limits.js
> 
> >+function testWebDevLimits(aEvent) {
> >+  browser.removeEventListener(aEvent.type, arguments.callee, true);
> >+
> >+  gOldPref = 200;
> >+  try {
> >+    gOldPref = Services.prefs.getIntPref("devtools.hud.loglimit.console");
> >+  }
> >+  catch (ex) { }
> 
> Don't need the try/catch since you're adding a default pref value (applies
> to this block elsewhere in the test).

Removed everywhere.

> I'm a bit confused by these tests - you're adding a sentinel log entry,
> setting the limit pref to 10, and then adding ten more entries and testing
> that the sentinel entry is still there - but shouldn't it have been pushed
> out by the 10 new entries? What am I missing?

The point of the patch and the tests is to make sure that one category's entries don't interfere with those from other categories. You'll see that the sentinel entry is always from a different category than the one being flooded.

> >+function testNetLimits(aEvent) {
> 
> >+  for (let i = 0; i < 10; i++) {
> >+    var image = content.document.createElement("img");
> >+    image.src = "test-image.png?_fubar=" + i;
> >+    body.insertBefore(image, body.firstChild);
> >+  }
> >+  image.addEventListener("load", onImageLoad, true);
> 
> I don't see any guarantee that the last inserted image's onload will fire
> last, which seems like it could cause intermittent orange.

Actually it would succeed even when it shouldn't, since we only checked that one file was loaded later on. But yes, this was definitely not a good test. Fixed.

Comment 19

[Panos Astithas (he/him) [:past] (please ni?)]

And another try run, just to be on the safe side:

http://tbpl.mozilla.org/?tree=Try&rev=e1731f420acc

Comment 20

[:Gavin Sharp [email: [e-mail]]]

Comment on attachment 533224 [details] [diff] [review]
Updated patch

(In reply to comment #18)
> The point of the patch and the tests is to make sure that one category's
> entries don't interfere with those from other categories.

Oh, I see. Should they also verify that truncation occurs while they're at it? Or is that covered by other tests?

Comment 21

[Panos Astithas (he/him) [:past] (please ni?)]

Attachment: [checked-in] [in-devtools] Final patch

(In reply to comment #20)
>> The point of the patch and the tests is to make sure that one category's
>> entries don't interfere with those from other categories.
>
> Oh, I see. Should they also verify that truncation occurs while they're at
> it? Or is that covered by other tests?

There are a couple of other tests, but you are right, this test should be
more thorough, so I made a trivial change to that effect. Also rebased to
the latest tip.

Comment 22

[Rob Campbell [:rc] (:robcee)]

Comment on attachment 533561 [details] [diff] [review]
[checked-in] [in-devtools] Final patch

http://hg.mozilla.org/projects/devtools/rev/b00797b2e0b9

Comment 23

[Dave Camp (:dcamp)]

Comment on attachment 533561 [details] [diff] [review]
[checked-in] [in-devtools] Final patch

http://hg.mozilla.org/mozilla-central/rev/b00797b2e0b9