Prefer Pino logger over Bunyan (#1841)

BREAKING CHANGE: removes `RequestCaptureStream` and replaces `Bunyan` with `Pino`

Author: ghermeto

docs/guides/8to9guide.md

@@ -5,7 +5,7 @@ permalink: /docs/8to9/
 
 ## Introduction
 
-restify `9.x` comes with `async/await` support!
+Restify `9.x` comes with `async/await` support, `pino` and more!
 
 ## Breaking Changes
 
@@ -94,3 +94,18 @@ server.use(async (req, res, next) => {
   });
 });
 ````
+
+### Remove `RequestCaptureStream`
+
+Removes `RequestCaptureStream` from Restify core.
+
+### Use `Pino` as default logger (removes dependency on `Bunyan`)
+
+[Pino](https://github.com/pinojs/pino) is well maintained, performance-focused, 
+compatible API. It does have a few key differences from `Bunyan`:
+
+- As a performance optimization, it stores bindings a single serialized `string`, 
+while `Bunyan` stores them as object keys;
+- It uses a `setter` to set the log level, `Bunyan` uses a method;
+- It only accepts one stream. If you need the multi-stream functionality, you
+must use [pino-multistream](https://github.com/pinojs/pino-multi-stream).  

docs/guides/client.md

@@ -120,7 +120,7 @@ Options:
 |dtrace|Object|node-dtrace-provider handle|
 |gzip|Object|Will compress data when sent using `content-encoding: gzip`|
 |headers|Object|HTTP headers to set in all requests|
-|log|Object|[bunyan](https://github.com/trentm/node-bunyan) instance|
+|log|Object|[pino](https://github.com/pinojs/pino) instance|
 |retry|Object|options to provide to node-retry;"false" disables retry; defaults to 4 retries|
 |signRequest|Function|synchronous callback for interposing headers before request is sent|
 |url|String|Fully-qualified URL to connect to|

examples/dtrace/demo.js

@@ -69,7 +69,7 @@
 //              512 |                                         0
 
 var restify = require('../../lib');
-var Logger = require('bunyan');
+var Logger = require('pino');
 
 ///--- Globals
 
@@ -80,8 +80,7 @@ var NAME = 'exampleapp';
 var log = new Logger({
     name: NAME,
     level: 'trace',
-    service: NAME,
-    serializers: restify.bunyan.serializers
+    base: { service: NAME }
 });
 
 var server = restify.createServer({

examples/http2/http2.js

@@ -1,6 +1,6 @@
 var path = require('path');
 var fs = require('fs');
-var bunyan = require('bunyan');
+var pino = require('pino');
 var restify = require('../../lib');
 
 var srv = restify.createServer({
@@ -21,10 +21,10 @@ srv.on(
     restify.plugins.auditLogger({
         event: 'after',
         body: true,
-        log: bunyan.createLogger({
-            name: 'audit',
-            stream: process.stdout
-        })
+        log: pino(
+            { name: 'audit' },
+            process.stdout
+        )
     })
 );
 

examples/spdy/spdy.js

@@ -1,6 +1,6 @@
 var path = require('path');
 var fs = require('fs');
-var bunyan = require('bunyan');
+var pino = require('pino');
 var restify = require('../../lib');
 
 var srv = restify.createServer({
@@ -21,10 +21,7 @@ srv.on(
     restify.plugins.auditLogger({
         event: 'after',
         body: true,
-        log: bunyan.createLogger({
-            name: 'audit',
-            stream: process.stdout
-        })
+        log: pino({name: 'audit'})
     })
 );
 

examples/todoapp/README.md

@@ -37,20 +37,20 @@ First, this has a `package.json`, so you'll need to run `npm install` in the
 directory. Once you've done that, to get started _and_ see audit logs on your
 terminal, run it like this:
 
-    $ node main.js 2>&1 | bunyan
+    $ node main.js 2>&1 | npx pino-pretty
 
 If you want to see all the built in restify tracing:
 
-    $ node main.js -vv 2>&1 | bunyan
+    $ node main.js -vv 2>&1 | npx pino-pretty
 
 By default, this program writes to a directory in `/tmp`, but you can override
 with a `-d` option.  Additionally, by default it does not require
 authentication, but you can require that with:
 
-    $ node main.js -u admin -z secret 2>&1 | bunyan
+    $ node main.js -u admin -z secret 2>&1 | npx pino-pretty
 
-Lastly, re: the `2>&1 | bunyan` bit.  In production, you assuredly would *not*
-want to pipe to the [bunyan](https://github.com/trentm/node-bunyan) CLI, but
+Lastly, re: the `2>&1 | npx pino-pretty` bit.  In production, you assuredly would *not*
+want to pipe to the [pino-pretty](https://github.com/pinojs/pino-pretty) CLI, but
 rather capture the audit records in their raw form, so they would be easy to
 post process and perform analytics on.  Like all UNIX programs should, this
 example writes "informational" messages to `stderr`, and `audit` records to
@@ -61,7 +61,7 @@ stdout.  It's up to you to redirect them as appropriate.
 
 Let's get the full magilla (i.e., with auth) running:
 
-    $ node main.js -u admin -z secret 2>&1 | bunyan
+    $ node main.js -u admin -z secret 2>&1 | npx pino-pretty
 
 Also, before we go any further, install the
 [json](https://github.com/trentm/json) tool as all the examples below use that.

examples/todoapp/lib/server.js

@@ -5,7 +5,7 @@ var path = require('path');
 var util = require('util');
 
 var assert = require('assert-plus');
-var bunyan = require('bunyan');
+var pino = require('pino');
 var restify = require('restify');
 var errors = require('restify-errors');
 
@@ -326,7 +326,7 @@ function createServer(options) {
     // Handles annoying user agents (curl)
     server.pre(restify.pre.userAgentConnection());
 
-    // Set a per request bunyan logger (with requestid filled in)
+    // Set a per request pino logger (with requestid filled in)
     server.use(restify.requestLogger());
 
     // Allow 5 requests/second by IP, and burst to 10
@@ -422,11 +422,7 @@ function createServer(options) {
             'after',
             restify.auditLogger({
                 body: true,
-                log: bunyan.createLogger({
-                    level: 'info',
-                    name: 'todoapp-audit',
-                    stream: process.stdout
-                })
+                log: pino({ level: 'info', name: 'todoapp-audit' })
             })
         );
     }

examples/todoapp/main.js

@@ -3,7 +3,7 @@
 var fs = require('fs');
 var path = require('path');
 
-var bunyan = require('bunyan');
+var pino = require('pino');
 var getopt = require('posix-getopt');
 var restify = require('restify');
 
@@ -13,32 +13,7 @@ var todo = require('./lib');
 
 var NAME = 'todoapp';
 
-// In true UNIX fashion, debug messages go to stderr, and audit records go
-// to stdout, so you can split them as you like in the shell
-var LOG = bunyan.createLogger({
-    name: NAME,
-    streams: [
-        {
-            level: process.env.LOG_LEVEL || 'info',
-            stream: process.stderr
-        },
-        {
-            // This ensures that if we get a WARN or above all debug records
-            // related to that request are spewed to stderr - makes it nice
-            // filter out debug messages in prod, but still dump on user
-            // errors so you can debug problems
-            level: 'debug',
-            type: 'raw',
-            stream: new restify.bunyan.RequestCaptureStream({
-                level: bunyan.WARN,
-                maxRecords: 100,
-                maxRequestIds: 1000,
-                stream: process.stderr
-            })
-        }
-    ],
-    serializers: restify.bunyan.serializers
-});
+var LOG = pino({ name: NAME });
 
 ///--- Helpers
 
@@ -49,7 +24,7 @@ var LOG = bunyan.createLogger({
  * the 'verbose' or '-v' option afflicts the log level, repeatedly. So you
  * can run something like:
  *
- * node main.js -p 80 -vv 2>&1 | bunyan
+ * node main.js -p 80 -vv 2>&1 | npx pino-pretty
  *
  * And the log level will be set to TRACE.
  */
@@ -79,9 +54,9 @@ function parseOptions() {
             case 'v':
                 // Allows us to set -vvv -> this little hackery
                 // just ensures that we're never < TRACE
-                LOG.level(Math.max(bunyan.TRACE, LOG.level() - 10));
+                LOG.level(Math.max(pino.levels.values.trace, LOG.level - 10));
 
-                if (LOG.level() <= bunyan.DEBUG) {
+                if (LOG.level <= pino.levels.values.debug) {
                     LOG = LOG.child({ src: true });
                 }
                 break;

examples/todoapp/package.json

@@ -5,16 +5,17 @@
         "main": "main.js",
         "dependencies": {
                 "assert-plus": "0.2.0",
-                "bunyan": "1.8.13",
+                "pino": "^6.3.2",
                 "posix-getopt": "1.2.0",
-                "restify-errors": "^3.1.0",
+                "restify-errors": "^4.0.0",
                 "restify": "^4.0.3"
         },
         "devDependencies": {
-                "nodeunit": "0.9.1"
+                "nodeunit": "0.9.1",
+                "pino-pretty": "^4.0.0"
         },
         "scripts": {
-                "start": "node main.js 2>&1 | bunyan",
+                "start": "node main.js 2>&1 | pino-pretty",
                 "test": "nodeunit test"
         },
         "author": "Mark Cavage",

examples/todoapp/test/todo.test.js

@@ -2,7 +2,7 @@
 
 var fs = require('fs');
 
-var bunyan = require('bunyan');
+var pino = require('pino');
 var restify = require('restify');
 
 var todo = require('../lib');
@@ -17,11 +17,9 @@ var SOCK = '/tmp/.todo_sock';
 ///--- Tests
 
 exports.setup = function(t) {
-    var log = bunyan.createLogger({
+    var log = pino({
         name: 'todo_unit_test',
-        level: process.env.LOG_LEVEL || 'info',
-        serializers: restify.bunyan.serializers,
-        stream: process.stdout
+        level: process.env.LOG_LEVEL || 'info'
     });
 
     fs.mkdir(DIR, function(err) {