Closed Bug 955097 Opened 10 years ago Closed 10 years ago

Enhance imXPCOMUtils debug logging to have module-specific prefs

Categories

(Chat Core :: Debug, defect)

defect
Not set
normal

Tracking

(Not tracked)

RESOLVED FIXED

People

(Reporter: bugzilla, Assigned: Mook)

Details

Attachments

(1 file, 4 obsolete files)

*** Original post on bio 1668 by Mook <mook.moz+bugs.instantbird AT gmail.com> at 2012-08-25 17:05:00 UTC ***

*** Due to BzAPI limitations, the initial description is in comment 1 ***
Attached patch Support additional prefs (obsolete) — Splinter Review
*** Original post on bio 1668 as attmnt 1842 by mook.moz+bugs.instantbird AT gmail.com at 2012-08-25 17:05:00 UTC ***

I swear I wrote similar patches ages ago, but since it's not in tip...
See attached patch. Supports things like
purple.debug.loglevel (current behaviour)
purple.debug.loglevel.irc

and, if you have dots in the module, it does correct fallback (similar to the way python's logging module does).
Comment on attachment 8353601 [details] [diff] [review]
Support additional prefs

*** Original change on bio 1668 attmnt 1842 by mook.moz+bugs.instantbird AT gmail.com at 2012-08-25 17:06:46 UTC was without comment, so any subsequent comment numbers will be shifted ***
Attachment #8353601 - Attachment is patch: true
Attachment #8353601 - Attachment mime type: application/octet-stream → text/plain
Attachment #8353601 - Flags: review?(florian)
*** Original post on bio 1668 at 2012-08-25 17:26:54 UTC ***

Comment on attachment 8353601 [details] [diff] [review] (bio-attmnt 1842)
Support additional prefs

I think I would prefer declaring logPref on a separate line as it's confusing (or at least easy to miss) where it is now.

Wouldn't you want to have the let prefNames = ... as the first part (the initialization) of the for loop, so that prefNames is only defined inside the loop?


Haven't we discussed at some point (but never implemented) doing this with environment variables, similar to what NSPR_LOG_MODULES does?
Attached patch environment variables and stuff (obsolete) — Splinter Review
*** Original post on bio 1668 as attmnt 1845 by mook.moz+bugs.instantbird AT gmail.com at 2012-08-26 05:46:00 UTC ***

(In reply to comment #1)
> I think I would prefer declaring logPref on a separate line as it's confusing
> (or at least easy to miss) where it is now.
Fixed.  Unfortunately, I also made the thing a whole lot more complicated...

> Wouldn't you want to have the let prefNames = ... as the first part (the
> initialization) of the for loop, so that prefNames is only defined inside the
> loop?
I do, but that makes the line too long...

> Haven't we discussed at some point (but never implemented) doing this with
> environment variables, similar to what NSPR_LOG_MODULES does?
Fixed; using NSPR_LOG_MODULES for now (but ridiculous looking: export NSPR_LOG_MODULES=purple.debug.loglevel:0 works for debug), might want to use a different variable or something...
Attachment #8353604 - Flags: review?
Comment on attachment 8353601 [details] [diff] [review]
Support additional prefs

*** Original change on bio 1668 attmnt 1842 by mook.moz+bugs.instantbird AT gmail.com at 2012-08-26 05:46:56 UTC was without comment, so any subsequent comment numbers will be shifted ***
Attachment #8353601 - Attachment is obsolete: true
Attachment #8353601 - Flags: review?(florian)
Assignee: nobody → bugzilla
Comment on attachment 8353604 [details] [diff] [review]
environment variables and stuff

*** Original change on bio 1668 attmnt 1845 by mook.moz+bugs.instantbird AT gmail.com at 2012-08-26 05:48:37 UTC was without comment, so any subsequent comment numbers will be shifted ***
Attachment #8353604 - Flags: review? → review?(florian)
Comment on attachment 8353604 [details] [diff] [review]
environment variables and stuff

*** Original change on bio 1668 attmnt 1845 at 2012-08-26 10:59:00 UTC ***

What about using something like this?
PRPL_LOG=<global level>,<module name>:<level>, ...

So for example one would use:
PRPL_LOG=1 (global log level to 1)
or
PRPL_LOG=irc:1 (log IRC messages at level 1)
or
PRPL_LOG=2,irc:1 (log messages at level 2 but IRC messages at level 1)


I'm also wondering why gLogLevels seems to have all its keys starting with "purple.debug.". Wouldn't we want just the module name there? (that may force having a magic value for the global level though)(In reply to comment #2)


(In reply to comment #2)
> (In reply to comment #1)
> > I think I would prefer declaring logPref on a separate line as it's confusing
> > (or at least easy to miss) where it is now.
> Fixed.  Unfortunately, I also made the thing a whole lot more complicated...

But you like complicated things, don't you? :-P
Attachment #8353604 - Flags: review?(florian) → review-
Attached patch address comment 3 (obsolete) — Splinter Review
*** Original post on bio 1668 as attmnt 1846 by mook.moz+bugs.instantbird AT gmail.com at 2012-08-26 16:56:00 UTC ***

(In reply to comment #3)
> What about using something like this?
> PRPL_LOG=<global level>,<module name>:<level>, ...
Done.  As a bonus, you can use <module>:<level> or <module>=<level>, and separate the module definitions with , or ;
PRPL_LOG=1 (global log level to 1)
PRPL_LOG=1,irc=0 (global log level to 1, irc to 0)
PRPL_LOG=5;irc:3 (global log level to 5, irc to 3)

> I'm also wondering why gLogLevels seems to have all its keys starting with
> "purple.debug.". Wouldn't we want just the module name there? (that may force
> having a magic value for the global level though)
That was because I'm trying avoid having silly people setting funny keys like __proto__.  Now using a : prefix instead.  Hacked things up a bit to get the global level to still work.
Attachment #8353605 - Flags: review?(florian)
Comment on attachment 8353604 [details] [diff] [review]
environment variables and stuff

*** Original change on bio 1668 attmnt 1845 by mook.moz+bugs.instantbird AT gmail.com at 2012-08-26 16:56:29 UTC was without comment, so any subsequent comment numbers will be shifted ***
Attachment #8353604 - Attachment is obsolete: true
*** Original post on bio 1668 at 2012-08-26 21:33:14 UTC ***

Comment on attachment 8353605 [details] [diff] [review] (bio-attmnt 1846)
address comment 3

>diff --git a/chat/modules/imXPCOMUtils.jsm b/chat/modules/imXPCOMUtils.jsm
>index 00cdc7d..a6bfeca 100644
>--- a/chat/modules/imXPCOMUtils.jsm
>+++ b/chat/modules/imXPCOMUtils.jsm
>@@ -27,7 +27,15 @@ const DEBUG_ERROR = 4;
> 
> function scriptError(aModule, aLevel, aMessage) {
>   // Only continue if we want to see this level of logging.

Nit: Please move that comment further down and write another comment here explaining the next 9 lines :).

>-  let logLevel = Services.prefs.getIntPref("purple.debug.loglevel");
>+  let logLevel = -1;
>+  let logKeys = [":"].concat(aModule.split("."));

I think the usage of ":" here is confusing. The code would work the same with "level" instead and be easier to understand.

>+Services.prefs.addObserver("purple.debug.loglevel", gLogLevels, true /* weak */);
>+// initialize with existing log level prefs
>+for each (let pref in Services.prefs.getChildList("purple.debug.loglevel")) {
>+  if (Services.prefs.getPrefType(pref) == Services.prefs.PREF_INT)
>+    gLogLevels[":" + pref.replace(/^purple.debug.loglevel/, "")] =
>+      Services.prefs.getIntPref(pref);
>+}
>+// let environment variables override prefs
>+Cc["@mozilla.org/process/environment;1"]
>+  .getService(Ci.nsIEnvironment)
>+  .get("PRPL_LOG")
>+  .split(/[;,]/)
>+  .filter(function(n) n != "")
>+  .forEach(function(env) {
>+    let [, module, level] = env.match(/(?:(.*?)[:=])?(\d+)/);
>+    gLogLevels[":" + (module ? "." + module : "")] = parseInt(level, 10);
>+  });

I would like all of this to be executed lazily the first time it's actually needed.

And btw, thanks for working on this, I look forward to having it in my debug builds!
Comment on attachment 8353605 [details] [diff] [review]
address comment 3

*** Original change on bio 1668 attmnt 1846 at 2012-08-26 21:33:48 UTC was without comment, so any subsequent comment numbers will be shifted ***
Attachment #8353605 - Flags: review?(florian) → review-
Attached patch address comment 5 (obsolete) — Splinter Review
*** Original post on bio 1668 as attmnt 1854 by mook.moz+bugs.instantbird AT gmail.com at 2012-08-26 21:54:00 UTC ***

Yeah, turns out lazy getter here would be more efficient than just wiping out init... (so that _nothing_ needs to run every time you do logging)
Attachment #8353613 - Flags: review?(florian)
Comment on attachment 8353605 [details] [diff] [review]
address comment 3

*** Original change on bio 1668 attmnt 1846 by mook.moz+bugs.instantbird AT gmail.com at 2012-08-26 21:54:37 UTC was without comment, so any subsequent comment numbers will be shifted ***
Attachment #8353605 - Attachment is obsolete: true
*** Original post on bio 1668 at 2012-08-26 22:11:43 UTC ***

Comment on attachment 8353613 [details] [diff] [review] (bio-attmnt 1854)
address comment 5


> function scriptError(aModule, aLevel, aMessage) {
>+  // Figure out the log level, based on the module and the prefs set

Missing point at the end of this sentence.


>+XPCOMUtils.defineLazyGetter(Cu.getGlobalForObject({}), "gLogLevels", function() {
>+  // This object functions both as an obsever as well as a dict keeping the
>+  // log levels with prefs; the log levels all start with "level" (i.e. "level"
>+  // for the global level, "level.irc" for the IRC module).  The dual-purpose
>+  // is necessary to make sure the observe is left alive while being a weak ref
>+  // to avoid cycles with the pref service.
>+  let logLevels = {
>+    observe: function(subject, topic, data) {

Patrick told you on IRC that our style is aSubject, aTopic, aData.

>+  // Add weak pref observer to see log level pref changes

Needs a .

>+  Services.prefs.addObserver("purple.debug.loglevel", logLevels, true /* weak */);
>+
>+  // Initialize with existing log level prefs

Here too.

>+  for each (let pref in Services.prefs.getChildList("purple.debug.loglevel")) {
>+    if (Services.prefs.getPrefType(pref) == Services.prefs.PREF_INT)
>+      logLevels["level" + pref.replace(/^purple.debug.loglevel/, "")] =
>+        Services.prefs.getIntPref(pref);
>+  }
>+
>+  // Let environment variables override prefs

And here.

Generally if a comment looks like a sentence and starts with an uppercase letter on the first word, it should finish like a sentence too.

Looks good otherwise.
*** Original post on bio 1668 as attmnt 1855 by mook.moz+bugs.instantbird AT gmail.com at 2012-08-26 22:16:00 UTC ***

Sorry about the aSubject &c thing; I had it in my tree, then reverted it because I was testing some other thing that didn't work out...
Attachment #8353614 - Flags: review?(florian)
Comment on attachment 8353613 [details] [diff] [review]
address comment 5

*** Original change on bio 1668 attmnt 1854 by mook.moz+bugs.instantbird AT gmail.com at 2012-08-26 22:16:09 UTC was without comment, so any subsequent comment numbers will be shifted ***
Attachment #8353613 - Attachment is obsolete: true
Attachment #8353613 - Flags: review?(florian)
Comment on attachment 8353614 [details] [diff] [review]
address comment 7

*** Original change on bio 1668 attmnt 1855 at 2012-08-26 22:19:40 UTC was without comment, so any subsequent comment numbers will be shifted ***
Attachment #8353614 - Flags: review?(florian) → review+
Whiteboard: [checkin-needed]
*** Original post on bio 1668 at 2012-08-28 00:54:50 UTC ***

Committed as http://hg.instantbird.org/instantbird/rev/7884bf7cae67

Thanks for this!
Status: NEW → RESOLVED
Closed: 10 years ago
Resolution: --- → FIXED
Whiteboard: [checkin-needed]
Target Milestone: --- → 1.3
*** Original post on bio 1668 at 2012-10-03 14:13:11 UTC ***

Warning: ReferenceError: assignment to undeclared variable logKey Source File: resource:///modules/imXPCOMUtils.jsm Line: 36
*** Original post on bio 1668 at 2012-10-08 18:38:49 UTC ***

(In reply to comment #10)
> Warning: ReferenceError: assignment to undeclared variable logKey Source File:
> resource:///modules/imXPCOMUtils.jsm Line: 36

Fixed in http://hg.instantbird.org/instantbird/rev/4a95984a3031
Assignee: bugzilla → mook.moz+mozbz
You need to log in before you can comment on or make changes to this bug.