node-bunyan-lite/tools/timechild.js

#!/usr/bin/env node
/*
 * Time `log.child(...)`.
 *
 * Getting 0.011ms on my Mac. For about 1000 req/s that means that the
 * `log.child` would be about 1% of the time handling that request.
 * Could do better. I.e. consider a hackish fast path.
 *
 * ...
 *
 * Added: `log.fastchild({...}, true)`. Use the `true` to assert that
 * the given options are just new fields (and no serializers).
 * Result: Another order of magnitude.
 */

var ben = require('ben');  // npm install ben
var Logger = require('../lib/bunyan');

var log = new Logger({
  name: 'svc',
  streams: [
    {
      path: __dirname + '/timechild.log'
    },
    {
      stream: process.stdout
    }
  ],
  serializers: {
    err: Logger.stdSerializers.err
  }
});

console.log('Time `log.child`:');

var ms = ben(1e5, function () {
  var child = log.child();
});
console.log(' - adding no fields:  %dms per iteration', ms);

var ms = ben(1e5, function () {
  var child = log.child({a:1});
});
console.log(' - adding one field:  %dms per iteration', ms);

var ms = ben(1e5, function () {
  var child = log.child({a:1, b:2});
});
console.log(' - adding two fields: %dms per iteration', ms);

function fooSerializer(obj) {
  return {bar: obj.bar};
}
var ms = ben(1e5, function () {
  var child = log.child({
    a: 1,
    serializers: {foo: fooSerializer}
  });
});
console.log(' - adding serializer and one field: %dms per iteration', ms);

var ms = ben(1e5, function () {
  var child = log.child({
    a: 1,
    streams: [ {stream: process.stderr} ]
  });
});
console.log(' - adding a (stderr) stream and one field: %dms per iteration',
  ms);

var ms = ben(1e6, function () {
  var child = log.child({}, true);
});
console.log(' - [fast] adding no fields:  %dms per iteration', ms);

var ms = ben(1e6, function () {
  var child = log.child({a:1}, true);
});
console.log(' - [fast] adding one field:  %dms per iteration', ms);

var ms = ben(1e6, function () {
  var child = log.child({a:1, b:2}, true);
});
console.log(' - [fast] adding two fields: %dms per iteration', ms);