451283 - (Log.jsm) Add log4moz.js to toolkit as Log.jsm

Status: RESOLVED FIXED

(Toolkit :: General, enhancement)

Description

[David Ascher (:davida)]

[not the best component, but I'm not sure where to put this]

Some of the work in Thunderbird and in Weave is making extensive use of log4moz.js

This great module would make a great deal of sense to have this in the base platform, so that a) we don't have multiple implementations in any one product, b) extensions can rely on a good logging framework.

We're going to need it as soon as Thunderbird 3.0b1 (3 weeks to code freeze), and we'll add it in /mail or /mailnews if necessary, but it'd be great to find it a 'final resting place' before that.

I understand that there are plans to make a C++ API (not through XPCOM) as well, which seems like a Good Idea, but hopefully won't need to block landing the JS side.

Comment 1

[Dan Mills [:thunder]]

Wow, I'm pleased to see there is interest in it :-)  I didn't know Thunderbird was using it extensively.  I agree that we need a better solution for logging in js.

I have no objections to having it live in the mozilla tree, though if there's a lot of work that needs to happen for that, I'm not sure how much I could dedicate to it.

Note that log4moz will not work from C++, and I currently do *not* have plans for doing so (I'm not sure where you heard that?).  I suppose, though, that one could build an XPCOM bridge to it.  But there are already some logging alternatives from C++, so I don't view lack of C++ support as a blocker.

I was recently pinged by a few Flock folks who said they have a similar logging framework they could contribute.  Theirs is written in C++ and exposes an XPCOM interface.  I haven't actually played with it or seen the API, but I'll point them to this bug.  The reason theirs is in C++, they told me, is speed.

Comment 2

[Manish Singh]

Yeah, we have a logger component in Flock that's in C++ that is over XPCOM. There's significant overlap between log4moz and our code, so I was thinking of trying to get this into the platform. The interfaces are here:

http://lxr.flock.com/source//flock/mozilla/flock/base/common/public/flockILogger.idl
http://lxr.flock.com/source/flock/mozilla/flock/base/common/public/flockILoggingService.idl
http://lxr.flock.com/source/flock/mozilla/flock/base/common/public/flockILoggingObserver.idl

Basically, you instantiate a logger object with a given context string, and call it with various logger level methods. The logging service decides whether to emit the message or not, depending on a combination of the default logging level pref, and optional context specific prefs. Then the logging service calls any registered logging observers to show the message. We have two observers, one is just printf to system console, the other is to a file in the profile.

Because flockILoggingObserver is an xpcom interface, you have the option of making custom loggers in JS still, even though the core is in C++.

One thing that I'd like to add that is not in either the current Flock logger code, nor log4moz, is printf style formatting, for both convenience and to minimize string concatenation.

Though there are already C++ logger frameworks in Mozilla, I think it'd be a good idea of there was one framework every language can use, mainly so log message consumers can be shared.

Comment 3

[Manish Singh]

Oh, and as Dan alluded to, the logging framework we have used to be written in JS, and I rewrote it in C++ (keeping the same IDL) for a nice speed boost. 8x faster in isolated benchmarks, which translated into a few hundred milliseconds saved on startup time on the Mac I tested.

Comment 4

[Manish Singh]

So if I was given some indication that pushing the Flock logger upstream (along with any functionality needed so that it has all the features of log4moz) is something that people want and would be accepted, I could have something ready for review by next week.

Comment 5

[Andrew Sutherland [:asuth] (he/him)]

bsmedberg, as toolkit owner, any thoughts on logging for toolkit and flock's c++ implementation?  I could see a world where speed-wise we would want a hybrid so that javascript code could avoid calling across the XPCOM barrier when the logging is disabled, but it seems like any solution will have a C++ side of the equation for unified logging...

Thunderbird has a particular interest in a game-plan right now as we hope to implement a "super status bar", and being able to tie displayed 'activities' to a logging channel for debugging purposes would be a killer app, even if just in DEBUG mode.

Comment 6

[Benjamin Smedberg]

From this bug, it's not clear to me what the goals of the logging system are. We already have the following logging systems:

1) NSPR logging, available only to binary code
2) XPCOM console service, poor API

I'm sure these can be improved on, but there are no details in this bug. What are the design goals? Does this logging system come with UI? Who is the intended target?

1) DEBUG developers
2) release developers/extension authors
3) users, but only when something bad is happening and they want to paste information into a bug report
4) users

What are the expected workloads?

The linked flock APIs don't have any useful documentation. Also this bug doesn't link to the log4moz.js code, so it's difficult to evaluate whether I'd want to consider either of these approaches.

Random side-note: I find the error-notification UI from weave really annoying: when the network or the server is down, I get many multiple notifications of login-failed, and have to dismiss each one individually.

Comment 7

[Andrew Sutherland [:asuth] (he/him)]

(In reply to comment #6)
> The linked flock APIs don't have any useful documentation. Also this bug
> doesn't link to the log4moz.js code, so it's difficult to evaluate whether I'd
> want to consider either of these approaches.

The bug URL link of https://wiki.mozilla.org/Labs/JS_Modules links to the log4moz code at http://hg.mozilla.org/labs/weave/file/tip/modules/log4moz.js

> I'm sure these can be improved on, but there are no details in this bug. What
> are the design goals? Does this logging system come with UI? Who is the
> intended target?

Is log4j-clone a design goal?  I think many developers have become accustomed to hierarchical logging with the ability to attach various output mechanisms to different points in the hierarchy.
 
> 1) DEBUG developers
> 2) release developers/extension authors
> 3) users, but only when something bad is happening and they want to paste
> information into a bug report
> 4) users

I would say Thunderbird cares about 1-3.  We need things that are more user friendly for 4.
 
> What are the expected workloads?

At the high end of the throughput spectrum, Thunderbird likes to be able to log protocol traffic.  This logging subsystem does not need to provide a solution for that, but I don't think we'd complain?  (We use NSPR logging right now for that, but the configuration and retrieval is a pain; we could improve that, of course.)

Comment 8

[Benjamin Smedberg]

> Is log4j-clone a design goal?  I think many developers have become accustomed

No, at least not without articulating what features of log4j make it compelling, and link to what it is.

> At the high end of the throughput spectrum, Thunderbird likes to be able to log
> protocol traffic.  This logging subsystem does not need to provide a solution
> for that, but I don't think we'd complain?  (We use NSPR logging right now for
> that, but the configuration and retrieval is a pain; we could improve that, of
> course.)

If all the code were JS, tracing could give us the ability to trace away even high-throughput debug tracing: that makes using XPCOM pretty much out of the question, though.

Comment 9

[Dan Mills [:thunder]]

(In reply to comment #8)
> > Is log4j-clone a design goal?  I think many developers have become accustomed
> 
> No, at least not without articulating what features of log4j make it
> compelling, and link to what it is.

log4j and its clones provide a hierarchical logging architecture that can be dynamically configured at runtime.  Output modules (called "appenders") are pluggable as well.

The log4* API has been around for a while now, so although it is new to mozilla it's a well-tested API in general.

You mentioned Weave notifications earlier, and this is not that.  log4moz.js does not contain any UI.  It only has a Logger implementation, a hierarchical repository for Loggers, and a few Appenders: one for the error console, one for stdout, and a couple to write to files and rotate logs.

> If all the code were JS, tracing could give us the ability to trace away even
> high-throughput debug tracing: that makes using XPCOM pretty much out of the
> question, though.

In my opinion, a JS module like log4moz.js is now is a good way to go.  I was under the impression, though, that we could additionally write an XPCOM component that could expose log4moz.js to C++, is that incorrect?

I'll attach the latest version of log4moz.js that I'm working with right now.  It has some API changes over what's in hg atm, so I've been holding off on committing it for the time being.

Comment 10

[Dan Mills [:thunder]]

Attachment: log4moz module

Comment 11

[Dave Townsend [:mossop] (PTO until 6/3)]

I agree that a hierarchical logging architecture would be very useful and my experience with the log4* APIs have been generally good. In particular we should be able to, either through providing FUEL wrappers or just best practice documentation, have extension authors follow a similar form and I could then make the extension manager log extension specific messages using the same system, this would allow authors to be able to filter out only the messages relevant to their add-ons.

Comment 12

[(not currently active) Ted Mielczarek]

Would a (non-XPCOM) JS interface to the NSPR logging API be sufficient, or do you really think we need a log4j-alike?

Comment 13

[Dave Townsend [:mossop] (PTO until 6/3)]

(In reply to comment #12)
> Would a (non-XPCOM) JS interface to the NSPR logging API be sufficient, or do
> you really think we need a log4j-alike?

The NSPR logging is neither hierarchical nor offers the same kinds of flexibility with outputting that other APIs offer. Now granted both of those could be improved upon, but as it stands I don't think NSPR logging offers a great deal.

Comment 14

[Benjamin Smedberg]

I'm going to delegate design review/approval of this idea to Mossop, since he's familiar with the APIs and has ideas for use within toolkit itself.

Comment 15

[Mark Finkle (:mfinkle) (use needinfo?)]

Does the log4moz system work well with threading?

Comment 16

[Dave Townsend [:mossop] (PTO until 6/3)]

Comment on attachment 342322 [details]
log4moz module

Doing mainly an initial pass of the API design for now. Will dig down more into details of the workings once we're happy with that. This looks like a pretty good start though.

We'll also need documentation and tests for this.

>  get repository() {
>    delete Log4Moz.repository;
>    Log4Moz.repository = new LoggerRepository();
>    return Log4Moz.repository;
>  },
>  set repository(value) {
>    delete Log4Moz.repository;
>    Log4Moz.repository = value;
>  },

The repository is just a singleton. Is there a reason not just to make Log4Moz the repository? Equally the repository could just be a separate object that callers could then never touch. I think we should have getLogger and getRootLogger on the Log4Moz object regardless as it simplifies the usage.

>  get LogMessage() { return LogMessage; },
>  get Logger() { return Logger; },
>  get LoggerRepository() { return LoggerRepository; },

I'm not sure what the reason of exposing these constructors to callers is. It looks like instantiating your own Logger will not fit it into the hierarchy, LoggerRepository should only ever be a singleton and it seems like creating your own LogMessage can give odd results.

>  get Formatter() { return Formatter; },
>  get BasicFormatter() { return BasicFormatter; },

These are called Layouts in log4j. Any reason for the name change?

>  // Logging helper:
>  // let logger = Log4Moz.repository.getLogger("foo");
>  // logger.info(Log4Moz.enumerateInterfaces(someObject).join(","));
>  enumerateInterfaces: function Log4Moz_enumerateInterfaces(aObject) {
>    let interfaces = [];
>
>    for (i in Ci) {
>      try {
>        aObject.QueryInterface(Ci[i]);
>        interfaces.push(i);
>      }
>      catch(ex) {}
>    }
>
>    return interfaces;
>  },
>
>  // Logging helper:
>  // let logger = Log4Moz.repository.getLogger("foo");
>  // logger.info(Log4Moz.enumerateProperties(someObject).join(","));
>  enumerateProperties: function Log4Moz_enumerateProps(aObject,
>                                                       aExcludeComplexTypes) {
>    let properties = [];
>
>    for (p in aObject) {
>      try {
>        if (aExcludeComplexTypes &&
>            (typeof aObject[p] == "object" || typeof aObject[p] == "function"))
>          continue;
>        properties.push(p + " = " + aObject[p]);
>      }
>      catch(ex) {
>        properties.push(p + " = " + ex);
>      }
>    }
>
>    return properties;
>  }

I'm not sure these enumerate methods really belong to here. Maybe there should be a LoggingHelpers jsm or something.

>LogMessage.prototype = {
>  QueryInterface: XPCOMUtils.generateQI([Ci.nsISupports]),

Any reason for the QIs all over the place?

>  _level: null,
>  get level() {
>    if (this._level != null)
>      return this._level;
>    if (this.parent)
>      return this.parent.level;
>    dump("log4moz warning: root logger configuration error: no level defined\n");
>    return Log4Moz.Level.All;
>  },
>  set level(level) {
>    this._level = level;
>  },

I think it's confusing for the getter to get something other than what the setter sets. Instead provide a regular getter for the set level for this logger and then a getter or method for effectiveLevel to match log4j.

>  // FIXME: need to update all parent values if we do this
>  //set rootLogger(logger) {
>  //  this._rootLogger = logger;
>  //},

I don't think there is ever a need to set the root logger is there?

>  _updateParents: function LogRep__updateParents(name) {
>    let pieces = name.split('.');
>    let cur, parent;
>
>    // find the closest parent
>    for (let i = 0; i < pieces.length; i++) {
>      if (cur)
>        cur += '.' + pieces[i];
>      else
>        cur = pieces[i];
>      if (cur in this._loggers)
>        parent = cur;
>    }

It depends entirely on the structure I guess, but if you run this loop backwards just using indexOf to chop off the last part each time then you can bail at the first parent you find.

>    // trigger updates for any possible descendants of this logger
>    for (let logger in this._loggers) {
>      if (logger != name && name.indexOf(logger) == 0)
>        this._updateParents(logger);

You can speed this up by just checking if the old parent of logger is equal to the parent we found earlier, I don't think there is a need for _updateParents at all then.

>  append: function App_append(message) {
>    if(this._level <= message.level)
>      this.doAppend(this._formatter.format(message));
>  },

This is actually backwards to the log4j API. There the Logger calls Appender.doAppend, which then filters and calls append. I think we should probably do the same for consistency's sake.

>ConsoleAppender.prototype = {
>  __proto__: Appender.prototype,
>
>  doAppend: function CApp_doAppend(message) {
>    if (message.level > Log4Moz.Level.Warn) {
>      Cu.reportError(message);
>      return;
>    }
>    Cc["@mozilla.org/consoleservice;1"].
>      getService(Ci.nsIConsoleService).logStringMessage(message);
>  }
>};

It isn't intuitive for ConsoleAppender to be doing additional filtering. There are three different levels of console messages that you can just map the various logging levels to.

>FileAppender.prototype = {

It is worth checking that writing a log message flushes the text to the disk rather than it being lost in the event of a crash following.

Comment 17

[Andrew Sutherland [:asuth] (he/him)]

Attachment: example implementation of a firebug console.log style of providing context info

While the design/API is up for discussion, I'd like to suggest that a mechanism for providing support for "contexts" (in the sense of log4j's Nested Diagnostic Contexts) be provided.  Also, built-in support for smarter handling of exceptions and object dumping.

Because the platform biases JavaScript development to happen in an asynchronous fashion on a single-thread, log4j's use of thread-local storage to track the context does not translate well.  In a world where there's a standardized, accepted, and commonly used mechanism for the 'driving' mechanism for generators, this may not be as much of an issue.  Another possibility would be to have the logger instances themselves maintain such a stack, but that would seem to be at odds with having the logger indicate the code module in use (because if you don't pass the logger around, you lose that context info.)

My proposal, as this patch against the trunk log4moz from weave implements, is to mimic Firebug's console.log.  Loggers would accept an arbitrary set of objects as their arguments.  A minimal/naive implementation would simply call toString on the objects and join with " ".  If firebug/chromebug is present, console.log could be used directly.

More clever loggers/appenders/whatever can provide explicit support for certain types of objects, or even all objects if so configured.  Exceptions/Errors an example of something that would likely be good to explicitly dump in its entirety.  Contexts could also be handled in this fashion.  By having the loggers be able to explicitly create objects recognized as Contexts, clever things can be done.  For example, only output/log messages associated with contexts where a warning or error occurred.  Users might also be able to tell the loggers that certain types of objects should always be recursively dumped, converted to strings using a custom formatter, etc.

From an efficiency perspective, this doesn't seem too bad.  If logging is disabled, the cost of processing the objects does not have to be taken.  A potential issue is that it potentially couples the roles of formatter/layout and appender in many cases.

As an example of what this enables, please see the pretty picture on my blog post where the contexts allow for visualization of the lifetimes of contexts (and grouping of log messages by contexts):
http://www.visophyte.org/blog/2008/12/14/logsploder-logsploding-its-way-to-your-logs-soon-also-logsplosion/

In terms of the asynchronous driver mechanism mentioned above, I think it may be beneficial to pursue having such a standardized mechanism be logging aware for the contexts, and perhaps recommended for use with this logging mechanism. I know dmills mentioned his async.js coroutine library on m.d.platform, and right now Thunderbird's gloda (global database) has grown something that is probably similar, if simpler.  (async.js lacks much in the way of comments and I'm not familiar with the accepted terminology for coroutines, and have been too rushed to read it deeply, so I'm not sure what all it does.)  I believe it can be found here: http://hg.mozilla.org/labs/weave/file/tip/modules/async.js

Comment 18

[Dave Townsend [:mossop] (PTO until 6/3)]

We really need someone to step up and own this

Comment 19

[Gregory Szorc [:gps]]

Attachment: Logging component strawman, v1

I've gone on the record multiple times saying that I don't want to just uplift log4moz.js into Toolkit. Instead, I want to do it correctly and create a unified logging bus/service/component for Gecko. This arguably exists already in C++ land, but we have nothing "good" for JS. And, I believe what I'm proposing even surpasses what C++ offers.

This patch is just a README describing what I want to build. Read the README the continue with this comment.

You finished the README, good.

Part 1 of this project would likely be uplifting something very similar to log4moz.js into Toolkit. It would likely just consist of basic loggers and appenders. One part I am adding over log4moz is the ability to record structured log events. I think the README summarizes the benefits of structured logging nicely. If not, I'm preparing a blog post that will convince you.

Part 2 would likely be the XPCOM service and all the friendly integration and bells and whistles.

I think just part 1 isn't too useful, as log producers still need to configure all the plumbing. This quickly grows out of hand. Take Sync for example. We have code that buffers log files in memory and only writes at discrete events. We have code that prunes old log files from disk. We use synchronous I/O. We have an about: page showing old logs. There are numerous bugs on file to improve the about: page and various parts of log handling. Arguably all of these are common tasks. In the absence of something holding the low-level logging code together, the wheel will be invented multiple times. I've already invented it 3 times in /services to varying degrees (Sync, AITC, and now FHR). I don't want this horse to leave the stable by landing just part 1 in Toolkit (at least not without a giant asterisk).

I want to build a unified logging component so logging is simple and powerful. Any component (be it a Gecko service or an add-on) could easily obtain a logger and start writing events. Configuring the plumbing of where to write log messages should be as simple as defining a few preferences. In the worst case, it's a few lines of JavaScript. We should also define an about: page that is used to aggregate (and even search) all logs across the entire application.

The patch is a strawman of what I think the technical implementation of that plan might look like. I anticipate many will have constructive things to say. Let's start with: 1) Whether a unified logging component like what I've proposed makes sense 2) bikeshedding on what it looks like and what the rollout plan will be.

Comment 20

[Joshua Cranmer [:jcranmer]]

(In reply to Gregory Szorc [:gps] from comment #19)
> I've gone on the record multiple times saying that I don't want to just
> uplift log4moz.js into Toolkit. Instead, I want to do it correctly and
> create a unified logging bus/service/component for Gecko. This arguably
> exists already in C++ land

No. NSPR logging has several problems with it. Most notably, the inability to separate out logstreams from different loggers, inability to change logging on the fly, etc. The only good things about it are that it works from multiple threads and it can be enabled by environment options.

> I want to build a unified logging component so logging is simple and
> powerful. Any component (be it a Gecko service or an add-on) could easily
> obtain a logger and start writing events. Configuring the plumbing of where
> to write log messages should be as simple as defining a few preferences. In
> the worst case, it's a few lines of JavaScript. We should also define an
> about: page that is used to aggregate (and even search) all logs across the
> entire application.

Some basic things I want to draw out wrt unified logging:
1. I would very much like to have a unified logging infrastructure that can handle loggers in both C++ and JS domains, and also off-main-thread (in C++) / via chromeworkers (for JS) logging support. Obviously, API can't exactly be identical between C++ and JS, but they should feel natural: C++ needs printf-like APIs, JS needs dump-this-Object. This also implies as corollary that C++ needs a non-XPIDL-ified API.

2. Please let me enable loggers via environment variables. It's how I debug xpcshell test issues. Obviously, I don't need full control over logging; NSPR_LOG_MODULES/NSPR_LOG_FILE-equivalent support is sufficient.

3. Replacing uses of NSPR logging in C++ means we probably need the ability to say if a logger should be enableable in release builds or not.

4. When writing to files, watch out for multiple processes trying to log to the same file.

Comment 21

[Gregory Szorc [:gps]]

(In reply to Joshua Cranmer [:jcranmer] from comment #20)
> 4. When writing to files, watch out for multiple processes trying to log to
> the same file.

I would like to think we can work around this by some combination of a) always writing log files inside the profile directory (1 process per profile - today at least), b) obtaining an exclusive write lock on the files, c) having a dedicated thread/process that handles I/O.

I'm really not sure what the performance implications of c) might be. I'm guessing throwing a JS object to another worker thread isn't as cheap as "transferring ownership" of a memory address between threads :)

Comment 22

[Richard Newman [:rnewman]]

(In reply to Joshua Cranmer [:jcranmer] from comment #20)

> 1. I would very much like to have a unified logging infrastructure that can
> handle loggers in both C++ and JS domains, and also off-main-thread (in C++)
> / via chromeworkers (for JS) logging support.

I'd like to call "perfect as an enemy of good", here.

log4moz is already being used in multiple places. We'd like to use it in more places. There's more pressing need for a polished, convenient, integrated JS logger than a shared JS + C++ logger; I don't think we should consider C++ logging in scope for v1 at all.

In the future, sure. But if we scope it now, I'd bet nothing will land within a year.

Comment 23

[Mike Conley (:mconley) (:⚙️) (PTO: May 27-31)]

Just tossing in my two cents - I think the proposal looks pretty snazzy, and I'm looking forward to using it. I'd also be happy to chip in a few cycles to get it built.

Comment 24

[Dave Townsend [:mossop] (PTO until 6/3)]

Comment on attachment 685850 [details] [diff] [review]
Logging component strawman, v1

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

Looks like a good start to me:

It's not clear to me how the xpcom service and JS module differ. Why is the service needed at all?
I'd love to see some kind of first class handling of including source file and line numbers and at certain levels full stack traces, either from the caller of the log function or from an exception passed to the function.
Structured logging is not completely clear to me, what is an action and fields and what would you do with them?

Comment 25

[Gregory Szorc [:gps]]

(In reply to Dave Townsend (:Mossop) from comment #24)
> Structured logging is not completely clear to me, what is an action and
> fields and what would you do with them?

http://gregoryszorc.com/blog/2012/12/06/thoughts-on-logging---part-1---structured-logging/

Comment 26

[Dave Townsend [:mossop] (PTO until 6/3)]

(In reply to Gregory Szorc [:gps] from comment #25)
> (In reply to Dave Townsend (:Mossop) from comment #24)
> > Structured logging is not completely clear to me, what is an action and
> > fields and what would you do with them?
> 
> http://gregoryszorc.com/blog/2012/12/06/thoughts-on-logging---part-1---
> structured-logging/

Ok, I think it makes more sense to call it "event" rather than "action" since you're generally logging that a particular event has occurred. I also posted some comments to the blog post.

Comment 27

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

Comment on attachment 685850 [details] [diff] [review]
Logging component strawman, v1

Looks good to me! I may have more interesting opinions once there is code here.

Comment 28

[Gregory Szorc [:gps]]

Reading through the comments, I think copying log4moz.js to toolkit in its current state or close to it is a good first step. The most important part of a JS logging module is the actual logging APIs (the Logger in log4moz terms). I think most are pretty happy with what log4moz currently has. Most of the contention is around implementation details of the appenders (sync vs async I/O), advanced/unimplemented features (such as automagic prefs configuration), chrome worker support, etc.

My vote is to do something like:

1) Copy log4moz.js into /toolkit/modules/log4moz.jsm (or logging.jsm).
2a) Address known issues as they bite us
2b) Add support for structured logging
2c) Chrome worker support
2d) Unified appender management, other advanced service-y features

With 1, we say the Logger API is stable but appenders and formatters may change. We then try to quickly address 2d and have a story in place for turnkey appender management. At that point, we have a story for a supported JS logging API. We can iterate on the other 2* items as needed.

Pending any objections, Chris Manchester may immediately take up this as part 1 of his summer project to improve how test data is captured.

Comment 29

[Mark Hammond [:markh] [:mhammond]]

One thing to consider is that Console.jsm is slowly creeping into more of our code - eg, bug 877389 is calling for all Cu.reportError() calls to be replaced with console.error() calls.

It would be a shame to find modules that import both Console.jsm and log4moz, both offering methods which clearly overlap, leading to potentially inconsistent and arbitrary uses of both inside a single module...

Comment 30

[Gregory Szorc [:gps]]

While I think there is room for Console.jsm and log4moz to converge, I think there is sufficient separation between them and am not too worried about overlap. That being said, there is overlap. It would be nice for us to unite behind one JS logging API.

Since AFAICT Console.jsm seems focused on the user presentation (presumably through the devtools console) and log4moz aims to be something much more (a generic message transport bus/service), I'd argue that log4moz is better suited than Console.jsm to be that logging API.

Of course, I don't know what the visions for Console.jsm are or if dev tools has grand ideas for logging. I haven't heard anything beside what I described in comment #19, so I'm assuming there isn't something that rivals it and am thus running with log4moz. If others have ideas around logging in JS, now is the time to talk about them (preferably on dev-platform?).

Comment 31

[Dave Camp (:dcamp)]

Someone else might have a grand vision, but my 2c:

Console.jsm is there to provide some simple debugging tools that match the experience web developers have in the browser.  I don't think it's intended to be heavy-duty logging, but it's nice to have console.log()/console.error() readily available in chrome code.

Comment 32

[Mark Hammond [:markh] [:mhammond]]

I'm certainly lacking a grand vision, but do have a spare 2c:

console.log() in the browser is going to generate too much noise.  It might make sense while developing/debugging, but it's not going to scale to have lots of browser code doing console.log calls "for real".  In some ways this makes dump() a better option - there's often less noise where dump() goes than there is on the browser console already, and both would need to be removed/disabled before being checked in.

This leaves console.warn() and console.error() as the only things that could reasonably be checked in.  We already have Cu.reportError() which can be called without an import.  console.error() does have a better API, but in the relatively common case of just logging a message, the benefit is marginal - so Console.jsm ends up simply as a heavy-weight replacement for Cu.reportError()/dump()

What I'd prefer to see is Console.jsm being the simple/common API to the better logging system.  The contract would be something like:

* console.error() and console.warn() *always* go to the browser console.
* The logging infrastructure (ie, most of the cool parts of log4moz) can be used to optionally direct the other console.* calls to interesting places (including the browser console).

This would mean that the vast majority of use-cases can be met with Console.jsm, and in many cases it would be acceptable for console.log() calls to be checked in.  Developer tools would allow a simple way of allowing a developer to see such console.log() calls on a per-module basis (where somehow the module name magically maps to a log4moz logger name).  More advanced requirements (eg, structured logging for test purposes etc) could be implemented using the "back-end" parts of the logging infrastructure.  The end result would hopefully be that for the vast majority of developers, "use Console.jsm, but sparingly" is the very simple and appropriate advice.

It's a bit hand-wavey, I know...

Comment 33

[Gregory Szorc [:gps]]

jst just mentioned something in the engineering meeting about better logging coming. I assume he's talking C++ land. But we should consider how C++ and JS will play together.

Comment 34

[Gregory Szorc [:gps]]

I believe jst was referring to bug 881389. I've left a note in that bug to look here for the JS side of things.

Comment 35

[Richard Newman [:rnewman]]

Comment on attachment 685850 [details] [diff] [review]
Logging component strawman, v1

What's the status of this, gps?

Comment 36

[Gregory Szorc [:gps]]

Chris Manchester has been landing a number of improvements in log4moz in /services. I was originally thinking we shouldn't steam ahead on moving log4moz to toolkit so as to minimize his bit rot. But I believe his work is mostly done and I think now is a good a time as any to move log4moz to toolkit.

Anyway want to write a patch? The hardest part is probably updating references all over the tree.

Comment 37

[Gregory Szorc [:gps]]

Mossop: I heard mumblings about this bug today. As Toolkit module owner, do you bless moving log4moz into Toolkit in its current state? If not, what needs done before log4moz can be accepted?

Comment 38

[Dave Townsend [:mossop] (PTO until 6/3)]

(In reply to Gregory Szorc [:gps] from comment #37)
> Mossop: I heard mumblings about this bug today. As Toolkit module owner, do
> you bless moving log4moz into Toolkit in its current state? If not, what
> needs done before log4moz can be accepted?

It's already used all over the place in it's current form, might as well move it as-is and clean up there if time allows.

Comment 39

[Gregory Szorc [:gps]]

Attachment: Move log4moz.js to Toolkit

Moved and renamed log4moz.js to Log4Moz.jsm, moved test, and updated
references. Pretty boilerplate. Review should go well with a beer.

https://tbpl.mozilla.org/?tree=Try&rev=219cb25cf438

Comment 40

[Dão Gottwald [:dao]]

(In reply to Gregory Szorc [:gps] from comment #39)
> Created attachment 794899 [details] [diff] [review]
> Move log4moz.js to Toolkit
> 
> Moved and renamed log4moz.js to Log4Moz.jsm,

What's the point of the "4Moz" part?

Comment 41

[Gregory Szorc [:gps]]

(In reply to Dão Gottwald [:dao] from comment #40)
> (In reply to Gregory Szorc [:gps] from comment #39)
> > Created attachment 794899 [details] [diff] [review]
> > Move log4moz.js to Toolkit
> > 
> > Moved and renamed log4moz.js to Log4Moz.jsm,
> 
> What's the point of the "4Moz" part?

Just preserving the name.

Comment 42

[Gregory Szorc [:gps]]

Attachment: Move log4moz.js to Toolkit

Rebased on bit rot. Added a Cu declaration to the test file.

Comment 43

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

(In reply to Gregory Szorc [:gps] from comment #41)
> > > Moved and renamed log4moz.js to Log4Moz.jsm,
> > 
> > What's the point of the "4Moz" part?
> 
> Just preserving the name.

I don't particularly like the name, and it doesn't fit in with our other module names. Any significant downsides to taking this opportunity to rename it to Log.jsm?

Comment 44

[Andrew Sutherland [:asuth] (he/him)]

(In reply to :Gavin Sharp (use [e-mail] for email) from comment #43)
> > > What's the point of the "4Moz" part?
> > 
> > Just preserving the name.
> 
> I don't particularly like the name, and it doesn't fit in with our other
> module names. Any significant downsides to taking this opportunity to rename
> it to Log.jsm?

I think the original rationale was consistency with the family of Log4J/Log4Net/etc.  The 4Moz makes it unique/unambiguous, but also no one outside of mozilla uses ".jsm" extensions anyways, so "Log.jsm" is going to be pretty unique too.

Comment 45

[Dave Townsend [:mossop] (PTO until 6/3)]

Comment on attachment 795572 [details] [diff] [review]
Move log4moz.js to Toolkit

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

Sounds like people are in favour of Log.jsm so lets do that.

Is it worth leaving a forwarding module in place at services-central/log4moz.js to avoid breaking other users?

Comment 46

[Blair McBride [:Unfocused] (UNAVAILABLE)]

Comment on attachment 685850 [details] [diff] [review]
Logging component strawman, v1

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

(Better late than never?)

So, basically yes to everything said in this bug. Like the overall idea outlined here, but lets just get Log.jsm into Toolkit and improve things as we go along. Perfect is the enemy of shipped.

gps: It's been awhile since that Mossop gave that r+, would you like me to un-bitrot the patch (and rename to Log.jsm)?

Comment 47

[Gregory Szorc [:gps]]

Unfocused: If you would like to take over this patch, please do!

Comment 48

[Blair McBride [:Unfocused] (UNAVAILABLE)]

Attachment: Patch v2

Renaming to Log.jsm ended up adding 100kb to the patch file... it ran through Try with no issues, but would be good to get a sanity check (it's nearly all /services/ code).

Comment 49

[Dão Gottwald [:dao]]

(In reply to Blair McBride [:Unfocused] from comment #48)
> Created attachment 815194 [details] [diff] [review]
> Patch v2
> 
> Renaming to Log.jsm ended up adding 100kb to the patch file...

You could just have left resource://services-common/log4moz.js in place, importing resource://gre/modules/Log.jsm and exporting log4moz as an alias. See also:

(In reply to Dave Townsend (:Mossop) from comment #45)
> Is it worth leaving a forwarding module in place at
> services-central/log4moz.js to avoid breaking other users?

Comment 50

[Blair McBride [:Unfocused] (UNAVAILABLE)]

I'd rather not be left with the technical debt from doing that. It has to be fixed at some stage.

Comment 51

[Gregory Szorc [:gps]]

Comment on attachment 815194 [details] [diff] [review]
Patch v2

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

Congratulations on becoming a Services peer :P

Comment 52

[Blair McBride [:Unfocused] (UNAVAILABLE)]

I plead the fifth.


https://hg.mozilla.org/integration/fx-team/rev/2f67ed3d7d6c

Comment 53

[Blair McBride [:Unfocused] (UNAVAILABLE)]

This would definitely benefit from some docs. Will see about getting some up next week.

Comment 54

[Blair McBride [:Unfocused] (UNAVAILABLE)]

And I broke Marionette with a typo.
https://hg.mozilla.org/integration/fx-team/rev/1ee5030003af

Comment 55

[Carsten Book [:Tomcat]]

hey Blair, sorry i had to backout the 2 changes (checkin and bustage fix) since also after the bustage fix we still had failures in mochitest and marionette like

https://tbpl.mozilla.org/php/getParsedLog.php?id=29028634&tree=Fx-Team
https://tbpl.mozilla.org/php/getParsedLog.php?id=29028871&tree=Fx-Team

Comment 56

[Blair McBride [:Unfocused] (UNAVAILABLE)]

Had a typo in my typo fix. How meta.

Third time lucky:
https://hg.mozilla.org/integration/fx-team/rev/2ac3c7f8b12c

Comment 57

[Blair McBride [:Unfocused] (UNAVAILABLE)]

Started a very basic docs page:
https://developer.mozilla.org/en-US/docs/Mozilla/JavaScript_code_modules/Log.jsm

Comment 58

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/2ac3c7f8b12c