Supporting multiple loggers

[rbabayoff]

Hey,

In large projects it is extremely useful to have the flexibility of defining different log levels for different modules / subsystems / files / objects, especially during debugging or bug chasing, in order to only see debug and trace log levels for a specific object / module. I have already implemented something like that in our wrapped loglevel meteor package:

https://github.com/practicalmeteor/meteor-loglevel

It also gave me the flexibility to define log prefixes that maintain line numbers (pushing the prefix as the first argument to apply), which, I suspect, is one of the more asked for features.

Will you accept a PR that allows to create new loglevel() objects? Regarding persistence, the constructor can receive an options object that include a namespace string that will be used to load the log level for that namespace. It can also accept a prefix option and even a map of custom log levels to console log methods.

[Mr0grog]

I’d definitely second this request. It could probably be done in a pretty light-weight fashion and would be extremely valuable for large projects, like one I’m consulting on now.

[pimterry]

Great idea, I can definitely see how this could be useful. At the same time, I'm very much fighting to keep the loglevel API and codebase as simple as possible, since ultra-lightweight reliable quick easy logging is really the most important thing I'm going for here.

What would the API for this look like? If you can come up with something that's:

• Backward compatible
• Simple to use
• Simple to implement

Then I'd be happy for you to put a PR together. Definitely worth discussing the initial API before you do that though.

(Sorry it's taken so long for me to catch up with this! Thanks so much for contributing :+1:)

[rbabayoff]

@pimterry, following is what I suggest as an API that is backwards compatible:

1. Create a new constructor function that actually creates and returns the logger.
2. The default global logger is automatically created on library load, as before.
3. To create a new logger, you call log.newLogger() or log.createLogger(), which calls the constructor function.
4. The constructor function supports 2 options, prefix and logLevel, both of which are optional and default to their current defaults - empty string, and WARN. I've already implemented this here:

https://github.com/practicalmeteor/meteor-loglevel/blob/master/loglevel-1.2.0.js#L3

1. I would also add a setPrefix method to the logger, as in here:

https://github.com/practicalmeteor/meteor-loglevel/blob/master/loglevel-1.2.0.js#L155

To improve on my implementation and to not possibly break code, I would only call the console functions with the prefix, if a prefix existed.

1. Regarding persisting the log level, we can use the prefix (loglevel-prefix) to generate the key name for persistence.

I've already implemented most of this myself in our popular meteor package wrapping loglevel, and will be happy to work on a PR for this.

[pimterry]

I think I'd like to keep this a bit simpler, as long as it's possible to do so while still solving your use case. How does the below sound:

• We add .newLogger() to loglevel - this creates a new independent logger, copying over the level from the logger this is called on.
• We implement prefix logging as a drop-in plugin. I think this should be very doable by extending the logFactory (to add the prefix), adding setPrefix to the prototype, and extending newLogger to also copy the prefix. This lets us get prefixing without having to bring in the complexity and potential browser-compatibility issues (IE6 at least joins multiple arguments different, I think there are some browsers that ignore extra arguments entirely, etc etc) into the core library.

With that implemented, this should mean that adding a prefix to your logger is just something like:

<script src='loglevel.js'></script>
<script src='loglevel-prefix.js'></script>
<script>
var myNewLogger = log.newLogger();
myNewLogger.setPrefix("new message:");
myNewLogger.setLevel("info");

log.info("hi"); // nothing
log.warn("hello"); // logs 'hello'
myNewLogger.info("bye"); // logs 'new message: bye'
</script>

How does that sound?

Oooh, difficult question though regardless of the exact implementation: what newLogger() do with persistence? Do the multiple loggers overwrite each others persisted levels? Do they somehow have namespaced cookies?

[rbabayoff]

This is exactly what I MENT, with the addition of also having a:

options = {prefix: 'my prefix', level: 'info'}
myOtherLogger = new loglevel.Logger(options); 

And newLogger just calls this behind the scenes.

Regarding persistence, right now, I'm treating the prefix as a namespace, and that's why I'd like the possibility to also pass in prefix to a constructor. We can support another .setNamespace function, if we don't use prefix for namespace, but I think it's overkill.

[Mr0grog]

I think having names/namespaces for the loggers is pretty important. To go back to the primary use-case that started this thread:

In large projects it is extremely useful to have the flexibility of defining different log levels for different modules / subsystems / files / objects, especially during debugging or bug chasing, in order to only see debug and trace log levels for a specific object / module.

Having names for the loggers allows you to configure them from somewhere other than inside the module itself, which I think is important to addressing the use-case effectively. You might configure them from the console while debugging or from some sort of application config file, but having those names is what allows you to configure those loggers externally. (Otherwise every module would have to expose additional API for configuring its logging or anybody trying to do this would have to have some sort of dependency injection system to provide a module with the appropriately configured logger. I’m not sure either of those are burdens I’d want to force onto developers.)

That said, I’m not sure naming loggers necessarily implies any sort of prefix that is visible on the console or in the logs. That could still be left up to a plug-in. The logger’s name could be passed as a new, third argument to methodFactory.

As a minor addendum to all that, if we had names for loggers, I’d suggest the API be loglevel.getLogger("name") rather than loglevel.newLogger("name"). The logger would only be instantiated the first time it’s asked for; after that, the pre-existing logger with that name would be returned.

[Mr0grog]

Having names for logging also conveniently solves the persistence problem, too ;)

[rbabayoff]

@Mr0grog I like your approach. To build on that, how about calling it loglevel.logger('name') instead, and after it's created, actually being able to also call it as follows:

loglevel['name'].info(msg);

Which allows you to do the following, if name is myname:

loglevel.myname.info(msg);

[Mr0grog]

Hmmm, I like the convenience there, but I’m not sure that’s really such a good idea in the end. What happens when someone wants to name a logger the same as a built-in loglevel method (e.g. if I name my loggers the same as my modules and I have a module named methodFactory)? Or if loglevel’s methods/properties ever need to be renamed or have new ones added? Feels like we’d be asking for collisions with that design.

[rbabayoff]

I solved it similarly in a sinon stubs factory behaving the same by disallowing reserved names, throwing an exception if a reserved name was used - and the reserved name list can be easily generated by enumerating properties on construction time. And the productivity enhancement, typing and auto-complete wise, was worth it. But, it's definitely not a must to get this out of the door. @pimterry seems like we're awaiting your approval / comments on the suggested API.

[pimterry]

Right, back again. Thoughts:

• Namespaces are the right solution to the persistence problem, very neat. Happy to go with that.
• Have loglevel take a namespace to the new logger method, but know nothing about prefixes (and then having a plugin potentially interpret this as a prefix, or add a separate setPrefix method, or anything else) seems like a nice simple solution, and passing the namespace to the method factory makes that easy.
• I definitely prefer .getLogger(name) to .newLogger(name), good shout.
• I don't think the loggers should be accessible as direct properties from the root loglevel object (log.myLogger.info(...)) - keeping them totally independent makes lots of things easier, and should simplify implementation.

Great! To be clear that means this change is:

• Adding a .getLogger(namespace) method to the API, taking a namespace and returning a new logger, copying the parent logger's level and method factory.
• Keeping track of the namespace a logger was created with, and passing it to the method factory (with default logger having undefined as the namespace, since that's easy perfect compatibility for the methodFactory args)
• Changing level persistence to postfix the cookie/localStorage name with the namespace if one's present (so undefined namespace sets 'loglevel', namespace 'myLogger' sets 'loglevel-myLogger')
• Changing nothing else of the API/external behaviour. Notably I don't want to add a new log.Logger(options) method, or a .getNamespace() method. I'm really really really keen to keep this library simple, minimal and clear, and exposing general purpose methods everywhere we possibly can without clear important use cases is a quick route straight away from that.

How does that sound to everybody? As long as people are happy, does anybody have time to implement it? As might be obvious I'm a little rushed off my feet at the moment, but I'll probably get to this some time in the next month or so, if nobody else does.

[Mr0grog]

This sounds pretty good to me. A few more thoughts I had:

• It might be useful to have a destroy() or dispose() method on logger objects (excepting the default one). In order for getLogger() to return existing loggers, it’ll have to keep a handle on all of them, so they can never be garbage collected (unless maybe we use a WeakMap). On the other hand, it seems unlikely that the number of loggers should ever pose a memory problem.
• I think @rbabayoff’s configuration object idea was a neat one, even if it’s just sugar for calling setDefaultLevel()/setLevel()/etc. But it doesn’t seem required to me, so maybe that can be a separate feature/discussion.
• Hierarchy: you noted getLogger() should be “taking a namespace and returning a new logger, copying the parent logger's level and method factory,” which implies at least some sense of hierarchy.
  1. Should that relationship persist after creating a logger? e.g. if the parent logger as its level changed, should that affect all its children?
  2. Related to the above, what happens when a logger’s level is set less restrictively than its parent? e.g. if the parent is at “error” and the child is at “trace,” what happens when you call child.trace(message)?
  3. Is hierarchy just one level (default -> all other loggers) or can it be a deep tree?
  4. Does getLogger() exist on every logger or just the default one?
  5. If it’s a deep tree structure and getLogger() exists on child loggers, how do the namespace and the parent-child relationship intersect? For example, if I call loglevel.getLogger("datasource").getLogger("users"), what exactly do I wind up with?
     • A logger named "datasource" and one named "datasource.users"?
     • A logger named "datasource" and one named "users"? How would it relate (over time) to "datasource"?
     • Can I access the second logger by calling loglevel.getLogger("whichever-of-the-above")? Or do I have to get it only by calling getLogger() on the first logger?
     • Relatedly, what would happen if I never called loglevel.getLogger("datasource") but instead just called `loglevel.getLogger("datasource.users")?
  6. Anyway, this is a big can of worms. ;)

I might have some free time to take a crack at this this week (maybe sans hierarchy, since there are a bundle of open questions there), but I make no promises. I’ll check back in here if I put in some reasonable time so there’s no duplicated effort.

[pimterry]

I'm not too worried about needing destroy/dispose. Could use a WeakMap where available, but I'm happy to ignore it for now, until somebody ever finds a real problem where it'd be useful.

My concern with configuration is just that it increases complexity, and we don't need it (yet). I really really really want to keep this as simple as possible where we can.

You're right that the hierarchy gets complicated, that was mostly a leftover from the initial proposal I guess. There's some bits where people might assume there's one (set level on log, expect first call to log.getLogger(x) to start from that level too), which concerns me slightly, but I'd rather just keep it simple again for now anyway, so lets drop that entirely too. No copying anything from the parent.

That still leaves the question of nested getLogger calls, which is a tricky one...

It's nice that the whole library is just a logger you can use directly, and that all the loggers involved are the same, which I think require that getLogger() is on every logger instance. There's maybe some slightly strange semantics with that (log.getLogger("accounts").getLogger("other") isn't clear imo), but I think it'll do for now to get started with.

[Mr0grog]

It's nice that the whole library is just a logger you can use directly, and that all the loggers involved are the same, which I think require that getLogger() is on every logger instance.

I agree that it’s great if the package itself is a logger that you can use the same as any other. That said, I don’t think there’s anything wrong with the package itself also having some extra goodies. I think it’s totally reasonable that it be a “logger plus,” as it were.

Personally, I think the hierarchy stuff could be really valuable and important, but I agree we could leave it unaddressed for now. I can imagine how it might be implemented by a plug-in, so maybe that’s where we leave it to start.

How about getLogger() only exists at the package level and not on each logger? That way, we don’t have to worry about what it means to get a logger from another logger (other than the default one, which is special anyway). That also leaves us room to define parent/child relationships later without tripping over too many assumptions users might have made based on previous behavior.

I also think, even if we aren’t addressing hierarchy here, it would still be valuable to inherit the logging level and method factory from the default logger—I didn’t mean to suggest that that would be no good. As a user, at least, I don’t want to have to remember to call setDefaultLevel() every time I call getLogger(). Or hack it by wrapping getLogger() so that happens automatically. I think it’s ok (just far from ideal) if that relationship is only for instantiation and isn’t long-lived over time (again, a plug-in could implement that).

[Mr0grog]

Ok, wrote a really simple implementation in #81 this afternoon.