Remove some obvious pitfalls. Migrate to winston@3 API (#232)

* [refactor] Never use the default logger if you have hard performance needs (like benchmarking). Use a stream Transport to be more closely aligned with feature set offered by peer sets. Begin to move to winston@3 API * [dist] Update to `[email protected]` * [tiny bin] Update benchmarks to have consistent formatting of benchmark name when reporting averages. * [doc] Update README.md with numbers. * [doc] Update benchmarks to [email protected]
pinojs · Apr 6, 2018 · 3ed4fcd · 3ed4fcd
1 parent 0703597
commit 3ed4fcd
Show file tree

Hide file tree

Showing 8 changed files with 82 additions and 56 deletions.
diff --git a/README.md b/README.md
@@ -86,56 +86,57 @@ As far as we know, it is one of the fastest loggers in town:
 `pino.info('hello world')`:
 
 ```
-benchBunyan*10000: 1355.229ms
-benchWinston*10000: 2226.117ms
-benchBole*10000: 291.727ms
-benchDebug*10000: 445.291ms
-benchLogLevel*10000: 322.181ms
-benchPino*10000: 269.109ms
-benchPinoExtreme*10000: 102.239ms
+BASIC benchmark averages
+Bunyan average: 549.042ms
+Winston average: 467.873ms
+Bole average: 201.529ms
+Debug average: 253.724ms
+LogLevel average: 282.653ms
+Pino average: 188.956ms
+PinoExtreme average: 108.809ms
 ```
 
 `pino.info({'hello': 'world'})`:
 
 ```
-benchBunyanObj*10000: 1464.568ms
-benchWinstonObj*10000: 2177.602ms
-benchBoleObj*10000: 322.105ms
-benchLogLevelObject*10000: 1443.148ms
-benchPinoObj*10000: 309.564ms
-benchPinoUnsafeObj*10000: 301.308ms
-benchPinoExtremeObj*10000: 130.343ms
-benchPinoUnsafeExtremeObj*10000: 131.322ms
+OBJECT benchmark averages
+BunyanObj average: 564.363ms
+WinstonObj average: 464.824ms
+BoleObj average: 230.220ms
+LogLevelObject average: 474.857ms
+PinoObj average: 201.442ms
+PinoUnsafeObj average: 202.687ms
+PinoExtremeObj average: 108.689ms
+PinoUnsafeExtremeObj average: 106.718ms
 ```
 
 `pino.info(aBigDeeplyNestedObject)`:
 
 ```
-benchBunyanDeepObj*10000: 8749.174ms
-benchWinstonDeepObj*10000: 17761.409ms
-benchBoleDeepObj*10000: 5252.563ms
-benchLogLevelDeepObj*10000: 43518.525ms
-benchPinoDeepObj*10000: 5124.361ms
-benchPinoUnsafeDeepObj*10000: 3539.253ms
-benchPinoExtremeDeepObj*10000: 5138.457ms
-benchPinoUnsafeExtremeDeepObj*10000: 3480.270ms
+DEEPOBJECT benchmark averages
+BunyanDeepObj average: 5293.279ms
+WinstonDeepObj average: 9020.292ms
+BoleDeepObj average: 9169.043ms
+LogLevelDeepObj average: 15260.917ms
+PinoDeepObj average: 8467.807ms
+PinoUnsafeDeepObj average: 6159.227ms
+PinoExtremeDeepObj average: 8354.557ms
+PinoUnsafeExtremeDeepObj average: 6214.073ms
 ```
 
 `pino.info('hello %s %j %d', 'world', {obj: true}, 4, {another: 'obj'})`:
 
 ```
-benchDebugInterpolateExtra*10000: 640.001ms
-benchBunyanInterpolateExtra*10000: 2888.825ms
-benchWinstonInterpolateExtra*10000: 2616.285ms
-benchBoleInterpolateExtra*10000: 1313.470ms
-benchLogLevelInterpolateExtra*10000: 1487.610ms
-benchPinoInterpolateExtra*10000: 486.367ms
-benchPinoUnsafeInterpolateExtra*10000: 457.778ms
-benchPinoExtremeInterpolateExtra*10000: 314.635ms
-benchPinoUnsafeExtremeInterpolateExtra*10000: 294.915ms
+BunyanInterpolateExtra average: 778.408ms
+WinstonInterpolateExtra average: 627.956ms
+BoleInterpolateExtra average: 429.757ms
+PinoInterpolateExtra average: 316.043ms
+PinoUnsafeInterpolateExtra average: 316.809ms
+PinoExtremeInterpolateExtra average: 218.468ms
+PinoUnsafeExtremeInterpolateExtra average: 215.040ms
 ```
 
-In many cases, pino is over 6x faster than alternatives.
+In many cases, pino is over 5x faster than alternatives.
 
 For a fair comparison, [LogLevel](http://npm.im/loglevel) was extended
 to include a timestamp and [bole](http://npm.im/bole) had

diff --git a/benchmarks/basic.bench.js b/benchmarks/basic.bench.js
@@ -31,8 +31,13 @@ require('bole').output({
   stream: dest
 }).setFastTime(true)
 
-winston.add(winston.transports.File, { filename: '/dev/null' })
-winston.remove(winston.transports.Console)
+var chill = winston.createLogger({
+  transports: [
+    new winston.transports.Stream({
+      stream: fs.createWriteStream('/dev/null')
+    })
+  ]
+})
 
 var run = bench([
   function benchBunyan (cb) {
@@ -43,7 +48,7 @@ var run = bench([
   },
   function benchWinston (cb) {
     for (var i = 0; i < max; i++) {
-      winston.info('hello world')
+      chill.log('info', 'hello world')
     }
     setImmediate(cb)
   },

diff --git a/benchmarks/deep-object.bench.js b/benchmarks/deep-object.bench.js
@@ -17,7 +17,7 @@ var plogUnsafeExtreme = require('../')({extreme: true, safe: false}, dest)
 
 var loglevel = require('./loglevelMock')(dest)
 
-var deep = require('../package.json')
+var deep = Object.assign({}, require('../package.json'), { level: 'info' })
 deep.deep = Object.assign({}, JSON.parse(JSON.stringify(deep)))
 deep.deep.deep = Object.assign({}, JSON.parse(JSON.stringify(deep)))
 deep.deep.deep.deep = Object.assign({}, JSON.parse(JSON.stringify(deep)))
@@ -36,8 +36,13 @@ require('bole').output({
   stream: dest
 }).setFastTime(true)
 
-winston.add(winston.transports.File, { filename: '/dev/null' })
-winston.remove(winston.transports.Console)
+var chill = winston.createLogger({
+  transports: [
+    new winston.transports.Stream({
+      stream: fs.createWriteStream('/dev/null')
+    })
+  ]
+})
 
 var run = bench([
   function benchBunyanDeepObj (cb) {
@@ -48,7 +53,7 @@ var run = bench([
   },
   function benchWinstonDeepObj (cb) {
     for (var i = 0; i < max; i++) {
-      winston.info(deep)
+      chill.log(deep)
     }
     setImmediate(cb)
   },

diff --git a/benchmarks/long-string.bench.js b/benchmarks/long-string.bench.js
@@ -32,8 +32,13 @@ require('bole').output({
   stream: dest
 }).setFastTime(true)
 
-winston.add(winston.transports.File, { filename: '/dev/null' })
-winston.remove(winston.transports.Console)
+var chill = winston.createLogger({
+  transports: [
+    new winston.transports.Stream({
+      stream: fs.createWriteStream('/dev/null')
+    })
+  ]
+})
 
 var run = bench([
   function benchBunyan (cb) {
@@ -44,7 +49,7 @@ var run = bench([
   },
   function benchWinston (cb) {
     for (var i = 0; i < max; i++) {
-      winston.info(longStr)
+      chill.info(longStr)
     }
     setImmediate(cb)
   },

diff --git a/benchmarks/multiArg.bench.js b/benchmarks/multiArg.bench.js
@@ -40,8 +40,13 @@ require('bole').output({
   stream: dest
 }).setFastTime(true)
 
-winston.add(winston.transports.File, { filename: '/dev/null' })
-winston.remove(winston.transports.Console)
+var chill = winston.createLogger({
+  transports: [
+    new winston.transports.Stream({
+      stream: fs.createWriteStream('/dev/null')
+    })
+  ]
+})
 
 var run = bench([
   function benchBunyanMulti (cb) {
@@ -52,7 +57,7 @@ var run = bench([
   },
   function benchWinstonMulti (cb) {
     for (var i = 0; i < max; i++) {
-      winston.info('hello', 'world')
+      chill.log('info', 'hello', 'world')
     }
     setImmediate(cb)
   },
@@ -94,7 +99,7 @@ var run = bench([
   },
   function benchWinstonInterpolate (cb) {
     for (var i = 0; i < max; i++) {
-      winston.info('hello %s', 'world')
+      chill.log('info', 'hello %s', 'world')
     }
     setImmediate(cb)
   },
@@ -125,7 +130,7 @@ var run = bench([
 
   function benchWinstonInterpolateAll (cb) {
     for (var i = 0; i < max; i++) {
-      winston.info('hello %s %j %d', 'world', {obj: true}, 4)
+      chill.log('info', 'hello %s %j %d', 'world', {obj: true}, 4)
     }
     setImmediate(cb)
   },
@@ -167,7 +172,7 @@ var run = bench([
   },
   function benchWinstonInterpolateExtra (cb) {
     for (var i = 0; i < max; i++) {
-      winston.info('hello %s %j %d', 'world', {obj: true}, 4, {another: 'obj'})
+      chill.log('info', 'hello %s %j %d', 'world', {obj: true}, 4, {another: 'obj'})
     }
     setImmediate(cb)
   },
@@ -209,7 +214,7 @@ var run = bench([
   },
   function benchWinstonInterpolateDeep (cb) {
     for (var i = 0; i < max; i++) {
-      winston.info('hello %j', deep)
+      chill.log('info', 'hello %j', deep)
     }
     setImmediate(cb)
   },

diff --git a/benchmarks/object.bench.js b/benchmarks/object.bench.js
@@ -30,8 +30,13 @@ require('bole').output({
   stream: dest
 }).setFastTime(true)
 
-winston.add(winston.transports.File, { filename: '/dev/null' })
-winston.remove(winston.transports.Console)
+var chill = winston.createLogger({
+  transports: [
+    new winston.transports.Stream({
+      stream: fs.createWriteStream('/dev/null')
+    })
+  ]
+})
 
 var run = bench([
   function benchBunyanObj (cb) {
@@ -42,7 +47,7 @@ var run = bench([
   },
   function benchWinstonObj (cb) {
     for (var i = 0; i < max; i++) {
-      winston.info({ hello: 'world' })
+      chill.info({ hello: 'world' })
     }
     setImmediate(cb)
   },

diff --git a/benchmarks/runbench.js b/benchmarks/runbench.js
@@ -76,13 +76,13 @@ function displayResults (results) {
   console.log('==========')
   var benchNames = Object.keys(results)
   for (var i = 0; i < benchNames.length; i += 1) {
-    console.log(benchNames[i] + ' averages')
+    console.log(benchNames[i].toUpperCase() + ' benchmark averages')
     var benchmark = results[benchNames[i]]
     var loggers = Object.keys(benchmark)
     for (var j = 0; j < loggers.length; j += 1) {
       var logger = benchmark[loggers[j]]
       var average = sum(logger) / logger.length
-      console.log(loggers[j] + ' average: ' + average)
+      console.log(loggers[j] + ' average: ' + average.toFixed(3) + 'ms')
     }
   }
   console.log('==========')

diff --git a/package.json b/package.json
@@ -72,7 +72,7 @@
     "tap": "^11.1.3",
     "tape": "^4.9.0",
     "through2": "^2.0.3",
-    "winston": "^2.4.1",
+    "winston": "^3.0.0-rc3",
     "zuul": "^3.11.1"
   },
   "dependencies": {