make handlers and transforms pluggable

.gitignore

@@ -2,3 +2,4 @@ node_modules
 .DS_Store
 coverage
 *.log
+.nyc_output

.travis.yml

@@ -1,7 +1,6 @@
 language: node_js
 node_js:
-  - "0.12"
   - "4"
   - "5"
-script: "npm run test:coverage:check"
+script: npm run test:coverage:check
 after_script: npm run coveralls

README.md

@@ -2,17 +2,9 @@
 
 [![Build Status](https://travis-ci.org/achingbrain/good-enough.svg?branch=master)](https://travis-ci.org/achingbrain/good-enough) [![Coverage Status](https://coveralls.io/repos/achingbrain/good-enough/badge.svg?branch=master&service=github)](https://coveralls.io/github/achingbrain/good-enough?branch=master) [![Dependency Status](https://david-dm.org/achingbrain/good-enough.svg)](https://david-dm.org/achingbrain/good-enough)
 
-Sometimes you just want easily machine parseable `DEBUG`, `INFO`, `WARN`, `ERROR` style logging:
+A multiple transport logging plugin that lets you apply arbitrary transforms to incoming log events.
 
-```sh
-2015-07-16 16:53:22+0100 worker#2 30791 DEBUG my:request-handler request-id:51236 Hello world
-```
-
-The format is:
-
-```sh
-$TIME_STAMP $WORKER_ID $PID $LEVEL $CONTEXT $REQUEST_ID $MESSAGE
-```
+Supports classic `DEBUG`, `INFO`, `WARN` and `ERROR` style logging.
 
 ## Usage
 
@@ -55,11 +47,7 @@ var CONTEXT = 'my:request-handler'
 var requestHandler = (request, reply) => {
   request.log([INFO, CONTEXT], 'Hello world')
 
-  request.log([WARN, CONTEXT], 'I can be a string')
-
-  request.log([DEBUG, CONTEXT], () => {
-    return 'If an expensive operation is needed for logging, wrap it in a function'.
-  })
+  request.log([WARN, CONTEXT], `I can be template string: ${request.payload}`)
 }
 ```
 
@@ -99,6 +87,8 @@ var logger = require('good-enough')
 var INFO = require('good-enough').INFO
 
 console.info(INFO === logger.logLevelFromString('INFO')) // true
+
+console.info(INFO === logger.logLevelFromString('info')) // true (not case sensitive)
 ```
 
 ## Specifying message output
@@ -129,11 +119,15 @@ server.register({
 });
 ```
 
-## Formatting messages
+## Transforming messages
 
-By default messages are formatted as human readable strings.  To format errors and performance information as JSON, pass `json: true` as plugin config:
+Be default events are formatted and turned into strings.  This has the side effect of losing information (log levels, timestamps, etc).
+
+To define your own transforms, pass a `transforms` hash as an option:
 
 ```javascript
+var through = require('through2');
+
 server.register({
   register: Good,
   options: {
@@ -143,8 +137,100 @@ server.register({
         // ...
       },
       config: {
-        // ..
-        json: true
+        transforms: {
+          toString: function (event, callback) {
+            callback(null, JSON.stringify(event))
+          }
+        },
+        transports: {
+          // ...
+        }
+      }
+    }]
+  }
+});
+```
+
+The first transform in the hash will be passed an event object which will have some or all of the following properties:
+
+```javascript
+{
+  host: String, // defaults to `os.hostname()`
+  pid: Number, // id of the current process
+  request: String, // the id of the request that was in flight when this event was logged
+  tags: Array,
+  type: String, // 'wreck', 'request', 'response', 'ops', 'error' or 'log'
+  timestamp: Date, // when the message was logged
+  level: String, // 'INFO', 'WARN', 'ERROR' or 'DEBUG'
+
+  // optional fields
+  message: String, // a message
+  context: String, // if `type` is log, the context you passed to `request.log`
+  statusCode: Number, // if `type` is 'wreck' this is the response from the wreck request, if it is `response` it's the response from your app
+  headers: Object // if `type` is 'wreck' this will be the response headers from the request
+}
+```
+
+## Specifying which transforms to apply to transports
+
+By default all transforms will be applied to an event in the order they are specified.  To override this, pass an array as a transport with the transport function being the last item in the array.
+
+```javascript
+server.register({
+  register: Good,
+  options: {
+    reporters: [{
+      reporter: require('good-enough'),
+      events: {
+        // ...
+      },
+      config: {
+        transforms: {
+          toString: (event, callback) => {
+            callback(null, JSON.stringify(event))
+          },
+          overrideHostName: (event, callback) => {
+            event.host = 'foo'
+            callback(null, event)
+          }
+        },
+        transports: {
+          // will have toString applied to all events before passing to stdout
+          stdout: ['toString', process.stdout.write.bind(process.stdout)],
+          // will not have the toString transform applied to any arguments
+          stderr: process.stderr.write.bind(process.stdout),
+          // will have overrideHostName and toString applied sequentially to all events
+          stdout: ['overrideHostName', 'toString', (chunk, encoding, callback) => {
+            // ... some code here
+          }],
+        }
+      }
+    }]
+  }
+});
+```
+
+## Handling log events
+
+There are a [default set of event handlers available](./handlers) but these can be overridden:
+
+```javascript
+server.register({
+  register: Good,
+  options: {
+    reporters: [{
+      reporter: require('good-enough'),
+      events: {
+        // ...
+      },
+      config: {
+        handlers: {
+          error: (stream, event) => {
+            // change `event` properties here
+
+            stream.push(event)
+          }
+        }
       }
     }]
   }

handlers/error.js

@@ -0,0 +1,18 @@
+'use strict'
+
+const os = require('os')
+const ERROR = require('../levels').ERROR
+
+module.exports = (stream, event) => {
+  stream.push({
+    host: os.hostname(),
+    pid: process.pid,
+    request: event.request,
+    tags: event.tags || [ERROR],
+    timestamp: event.timestamp || new Date(),
+    type: 'error',
+    level: ERROR,
+
+    message: event.error.stack ? event.error.stack : event.error.toString()
+  })
+}

handlers/log.js

@@ -0,0 +1,26 @@
+'use strict'
+
+const os = require('os')
+const levels = Object.keys(require('../levels'))
+
+module.exports = (stream, event) => {
+  var message = event.data
+
+  if (message instanceof Error) {
+    message = message.stack || message.toString()
+  }
+
+  stream.push({
+    host: os.hostname(),
+    pid: process.pid,
+    request: event.request,
+    tags: event.tags,
+    timestamp: event.timestamp || new Date(),
+    type: 'log',
+    level: event.tags.find((tag) => {
+      return levels.indexOf(tag.toString().toUpperCase()) !== -1
+    }),
+
+    message: message
+  })
+}

handlers/ops.js

@@ -0,0 +1,78 @@
+'use strict'
+
+const os = require('os')
+const moment = require('moment')
+const pretty = require('prettysize')
+const util = require('util')
+const INFO = require('../levels').INFO
+
+module.exports = (stream, event) => {
+  stream.push({
+    host: os.hostname(),
+    pid: process.pid,
+    request: event.request,
+    tags: [INFO, 'system'],
+    timestamp: event.timestamp || new Date(),
+    type: 'ops',
+    level: INFO,
+
+    message: util.format('Load average: %s, Memory: %s of %s used, Uptime: %s',
+      event.os.load.map(function (num) {
+        return ' ' + parseFloat(num).toFixed(2)
+      }).toString().trim().replace(/,/g, ''),
+      pretty(event.os.mem.total - event.os.mem.free),
+      pretty(event.os.mem.total),
+      moment.duration(event.os.uptime * 1000).humanize()
+    )
+  })
+  stream.push({
+    host: os.hostname(),
+    pid: process.pid,
+    request: event.request,
+    tags: [INFO, 'process'],
+    timestamp: event.timestamp || new Date(),
+    type: 'ops',
+    level: INFO,
+
+    message: util.format('Uptime: %s, Heap: %s of %s used, RSS: %s, Delay: %sms',
+      moment.duration(event.proc.uptime * 1000).humanize(),
+      pretty(event.proc.mem.heapUsed),
+      pretty(event.proc.mem.heapTotal),
+      pretty(event.proc.mem.rss),
+      parseFloat(event.proc.delay).toFixed(2)
+    )
+  })
+
+  if (!event.load.requests) {
+    return
+  }
+
+  Object.keys(event.load.requests).forEach((port) => {
+    var requests = event.load.requests[port] || {}
+    var statusCodes = requests.statusCodes || {}
+    var responseTimes = (event.load.responseTimes || {})[port] || {}
+    var concurrents = (event.load.concurrents || {})[port] || 0
+
+    stream.push({
+      host: os.hostname(),
+      pid: process.pid,
+      request: event.request,
+      tags: [INFO, 'requests'],
+      timestamp: event.timestamp || new Date(),
+      type: 'ops',
+      level: INFO,
+
+      message: util.format('Port: %s, Total: %d, Disconnects: %d, Status codes: %s, Concurrent: %d, Response times: average %sms, max %sms',
+        port,
+        requests.total,
+        requests.disconnects,
+        Object.keys(statusCodes).map((code) => {
+          return ' ' + code + ': ' + statusCodes[code]
+        }).toString().trim() || '200: 0',
+        concurrents,
+        parseFloat(responseTimes.avg || 0).toFixed(2),
+        parseFloat(responseTimes.max || 0).toFixed(2)
+      )
+    })
+  })
+}

handlers/request.js

@@ -0,0 +1,36 @@
+'use strict'
+
+const os = require('os')
+const errorLogger = require('./error')
+const ERROR = require('../levels').ERROR
+const INFO = require('../levels').INFO
+
+module.exports = (stream, event) => {
+  if (event.tags.indexOf(ERROR) !== -1) {
+    var error = event.data
+
+    if (!(error instanceof Error)) {
+      // convert string stack trace back into error message
+      error = new Error(event.data.toString().split(/\n/)[0].trim())
+      error.stack = event.data
+    }
+
+    return errorLogger(stream, {
+      request: event.id,
+      tags: event.tags,
+      error: error
+    })
+  }
+
+  stream.push({
+    host: os.hostname(),
+    pid: process.pid,
+    request: event.request,
+    tags: [INFO, 'request'],
+    timestamp: event.timestamp || new Date(),
+    type: 'request',
+    level: INFO,
+
+    message: event.data
+  })
+}

handlers/response.js

@@ -0,0 +1,22 @@
+'use strict'
+
+const os = require('os')
+const INFO = require('../levels').INFO
+
+module.exports = (stream, event) => {
+  stream.push({
+    host: os.hostname(),
+    pid: process.pid,
+    request: event.id,
+    tags: [INFO, 'response'],
+    timestamp: event.timestamp || new Date(),
+    type: 'response',
+    level: INFO,
+
+    method: event.method.toUpperCase(),
+    responseTime: event.responseTime,
+    path: event.path,
+    statusCode: event.statusCode,
+    remoteAddress: event.source.remoteAddress
+  })
+}