seanmonstar

Feb 11 2014

intel v0.5

intel is turning into an even more awesome logging framework than before, as if that was possible! Today, I released version 0.5.0, and am now here to hawk it’s newness. You can check out the full changelog yourself, but I want to highlight a couple bits.

JSON function strings

intel.config is really powerful when coupled with some JSON config files, but Formatters and Filters were never 100% in config, because you could pass a custom function to either to customize to your little kidney’s content. It’s not possible to include typical functions in JSON. Much sad face. So, the formatFn and filterFn options allow you to write a function in a string, and intel will try to parse it into a function. Such JSON.

Logger.trace

A new lowest level was introduced, lower than even VERBOSE, and that’s TRACE. Likewise, Logger.trace behaves like console.trace, providing a stack trace with your message. If you don’t enable loggers with TRACE level logging, then no stacks will be traced, and everything will choo-choo along snappy-like.

Full dbug integration

This is the goods. intel is an awesome application logging library, since it lets you powerfully and easily be a logging switchboard: everything you want to know goes everywhere you want. However, stand-alone libraries have no business deciding where logs go. Libraries should simply provide logging when asked to, and shut up otherwise. That’s why libraries should use something like dbug. Since v0.4, intel has been able to integrate somewhat with dbug, but with 0.5, it can hook directly into it, meaning less bugs, and better performance. Examples!

// hood/lib/csp.js
var dbug = require('dbug')('hood:csp');

exports.csp = function csp(options) {
    dbug('csp options:', options);
    if (!options.policy) {
        dbug.warn('no policy provided. are you sure?');
    }
    // ...
};

// myapp/server.js
var intel = require('intel');
intel.console({ debug: 'hood' });
// will see: 'myapp.node_modules.hood.csp:DEBUG csp options: {}'

Dare I say, using intel and dbug together gives the best logging solution for libraries and apps.

Jan 2 2014

intel 0.4

I released v0.4 of intel last month, but never got around to writing up what’s new.

debug/dbug

I started out all this logging business claiming we should console.log() all the things. intel can easily handle any libaries using console.log. However, I started to see how frustrating it could be for libraries to be spilling logs all over stdout without being asked. dbug is a utility for libraries to provide logging, but to be quiet by default.

intel v0.4 includes the ability to play nice with dbug (and debug). You can call intel.console({ debug: someStr }) to turn on dbug in libraries matching your string. Due to how debug works, by checking an environment variable right when it is required, you’ll need to run intel.console() before requiring any library that uses debug.

performance

As with every release, things get faster. According to meaningless benchmarks, we’re now ~2x faster than winston. Whatever that means.

syslog

Not part of the actual release, but released at the same time, is an intel-syslog library. This provides a simple syslog handler that you can easily use in your app.

require('intel').config({

  handlers: {
    'syslog': {
      'class': 'intel-syslog',
      'address': '127.0.0.1',
      'facility': 'user' //etc...
    }
  },

  loggers: {
    'myapp': {
      'handlers': ['syslog']
    }
  }

});

I’ve created a wiki page to contain handlers such as intel-syslog that work with intel. If you create or find a library for intel, please add it to the list so we all can be happier logging things.

Oct 4 2013

intel 0.2

I’ve already pushed intel 0.2 out the door, after a week of tweaking and massaging it into Persona repos. Here’s the changelog, explanation after:

  • [new] Filters
  • [new] Handler timeout option
  • [new] pid included in LogRecord
  • [new] use JSON with intel.config()
  • [changed] Promises are now LazyPromises
  • [changed] printf is now a small, internal, much faster implementation
  • [removed] node v0.6 support

Filters

There was already a fair amount of filtering possible in v0.1, by combining log levels and named loggers. However, it became apparent that you’d want to also be able to filter messages on arbitrary details, and there wasn’t a super easy way to do that. Now you can. Here’s an example filter:

 handler.addFilter(new intel.Filter(/user/g));

This filter means that the handler will only receive messages that include the string “user” in the message text.

config with JSON

Configuration was powerful, but it required a a JavaScript file to provide Handler classes. Since we use JSON files to define our configuration for our servers, it was immediately noticed that intel needed this as well. So, now, the class property of Handlers and Filters accepts a String, which will be used to require the class. Intel’s handlers are available like this: intel/handlers/console.

Performance

I set up some benchmarks to see just much power intel sucks up, and then cried a little. Clearly, comparing speed to the basic console.log was an exercise meant for trolls, but I also compared against winston. Removing some Array.forEachs, using a light-weight printf, and using LazyPromises made intel faster than winston (woot!).

Specifically, Promises were the biggest slow down. They’re awesome control structures, but boy are they slow. Since most people won’t ever want them anyways, it would suck if everyone had to pay their compute cost. So, log methods now return a proxy with a getter for then. When then is accessed the first time, the Promises are constructed, and handed to the caller. You only pay the cost on the few times you really want their convenience.

intel 0.2

As always, file bugs or feature requests at the issuer tracker. I’m still aiming to be able to call intel at v1.0 soon, so any feedback will help shape this into an excellent go-to logging library.

Sep 30 2013

intel

A couple months ago, I was blagging on about logging libraries in nodejs. After pointing out how annoying it is to use logging libraries with 3rd party modules, I declared that all modules should simply use console.log(), and let applications hijack the console. Then, I looked around the npms, and couldn’t find an excellent example of a logging library that embraced that idea.

So, clearly, that meant I needed to write my own. It’s called intel. Why another logging library? Well duh, cause this one is better.

Loggers get names

Before nodejs, I came from Pythonia. Over yonder, they have an excellent logging module as part of the standard library. It’s glorious. It uses hierarchal named loggers. Winston, the library we currently use in Persona, while being perfectly awesome, doesn’t have support for this. It does allow you to define Containers and Categories, but it’s not as powerful as I’d like.

Specifically, intel adds 2 noteworthy features to Loggers: hierarchy and humane setup.

  1. Loggers use an hierarchy based on their names. Logger foo.bar is a child of foo. So is foo.bar.baz. When a logger receives a log message, after handling itself, it passes the message up to its parents.

    For instance, you could decide that all log messages from foo should go to the terminal. However, your foo/bar.js module has some critical code you want to keep tabs on. You could add a handler to the foo.bar logger that sends all messages of WARN and greater to email. After that handler, foo.bar will hand the message to its parent foo, and also send it to the terminal

  2. Of the other libraries I could fine that supported multiple named loggers, they all required that you instantiate the loggers with all options ahead of time. This adds more friction having a named logger per module in your app. Instead, intel makes it super easy for you get a new named logger.

     var logger = intel.getLogger('foo.bar.baz.quux');
    

    You don’t have to have added any handlers to your newly minted logger. It will just pass the messages right up to it’s parents. The messages will still keep the name of the originating logger, though.

Powerful configuration

Named loggers allow for really powerful yet easy-to-use logging. Combined with a little bit of configuration, and it’s all magical. You can setup a couple root loggers, with various levels pumping messages to various handlers (Console, File, Email, Database, etc). You can see an example in the docs.

Infiltrating the console

The motivating reason I started intel was to do exactly this. I want my apps to have the power to configure logging just the way I want, and I want all my dependencies to play along with my logging rules. So, after you setup your loggers and handlers, you can inject intel into the global console object, and watch as any dependencies that use console.log follow your rules, and automatically get assigned the correct names.

 intel.console();
 intel.getLogger('patrol.node_modules.express').setLevel(intel.WARN);
 // in express.js
 console.log('new request'); // automatically gets assigned to patrol.node_modules.express logger.

intel

I’m starting by a 0.1 release of intel. Any bugs or feature requests can filed in the issue tracker. I don’t want intel to be one of those libraries that is forever sub-1.0. After some use in the wild, with bugs being fixed and possibly APIs being made better, I’d like to get to a 1.0 soon.

So, try swapping out your current logger for intel. Name some loggers. You’ll come around.