Repository: pinojs/pino (js)

Issue:
An error with Errors?
Very minor issue I came across, but it suddenly crashes node when it happens.

When I failed to wrap my Error object (which may be null) in an object, pino threw this message:

Code:

    logger.info(err, 'End of playback');

Error:

    C:\Users\<me>\Projects\<projectname>\node_modules\pino\pino.js:378
        pos = s.indexOf(i, pos);
               ^

    TypeError: Cannot read property 'indexOf' of null
        at countInterp (C:\Users\<me>\Projects\<projectname>\node_modules\pino\pino.js:378:12)
 
I tried doing this in the indicated function:

    pos = s ? s.indexOf(i, pos) : -1

And it revealed that I did not enclose my `err` in an object.

    { ... "msg":"null \"End of playback\"" ... }

However, I usually choose not to wrap `err`, because it results in the following log:

    logger.error({ error: err }, err.message);

    [2016-12-12T09:13:37.051Z] ERROR(appname/### on computer): <The contents of err.message -- this string has content>
       error: {}

The error is rendered as empty, but it does in fact have an message. The only way to get the full stack trace is to use `logger.error(err)`. This scenario works well with Promises (where err is guaranteed in the catch block); in this instance, `err` was a parameter in a callback. Thus, the above.

To wrap up:

1. It boils down to Errors being a special case, for some reason, and it is rendered as an empty object -- is this a bug?

2. Could the if-else above (`pos = s ? s.indexOf(i, s) : -1`) be incorporated into the `countInterp` function? It would at least prevent unexpected crashing.

Pull request:
New error serializer
Includes both #134 and #149.

Fixes #146.

Patch:
diff --git a/pino.js b/pino.js
index b6aedc8..2b8482f 100644
--- a/pino.js
+++ b/pino.js
@@ -157,7 +157,6 @@ function Pino (opts, stream) {
     if (levelIsStandard === false && valIsStandard === false) this.addLevel(opts.level, opts.levelVal)
   }
   this._setLevel(opts.level)
-
   this._baseLog = flatstr(baseLog +
     (this.name === undefined ? '' : '"name":' + this.stringify(this.name) + ','))
 
@@ -241,14 +240,13 @@ Pino.prototype.asJson = function asJson (obj, msg, num) {
   if (obj) {
     if (obj.stack) {
       data += ',"type":"Error","stack":' + this.stringify(obj.stack)
-    } else {
-      for (var key in obj) {
-        value = obj[key]
-        if (obj.hasOwnProperty(key) && value !== undefined) {
-          value = this.stringify(this.serializers[key] ? this.serializers[key](value) : value)
-          if (value !== undefined) {
-            data += ',"' + key + '":' + value
-          }
+    }
+    for (var key in obj) {
+      value = obj[key]
+      if (obj.hasOwnProperty(key) && value !== undefined) {
+        value = this.stringify(this.serializers[key] ? this.serializers[key](value) : value)
+        if (value !== undefined) {
+          data += ',"' + key + '":' + value
         }
       }
     }
@@ -364,11 +362,17 @@ function asResValue (res) {
 }
 
 function asErrValue (err) {
-  return {
+  var obj = {
     type: err.constructor.name,
     message: err.message,
     stack: err.stack
   }
+  for (var key in err) {
+    if (obj[key] === undefined) {
+      obj[key] = err[key]
+    }
+  }
+  return obj
 }
 
 function countInterp (s, i) {


Test patch:
diff --git a/test/basic.test.js b/test/basic.test.js
index b1cea58..fe57789 100644
--- a/test/basic.test.js
+++ b/test/basic.test.js
@@ -67,28 +67,6 @@ function levelTest (name, level) {
     instance[name]('hello %d', 42)
   })
 
-  test('passing error at level ' + name, function (t) {
-    t.plan(2)
-    var err = new Error('myerror')
-    var instance = pino(sink(function (chunk, enc, cb) {
-      t.ok(new Date(chunk.time) <= new Date(), 'time is greater than Date.now()')
-      delete chunk.time
-      t.deepEqual(chunk, {
-        pid: pid,
-        hostname: hostname,
-        level: level,
-        type: 'Error',
-        msg: err.message,
-        stack: err.stack,
-        v: 1
-      })
-      cb()
-    }))
-
-    instance.level = name
-    instance[name](err)
-  })
-
   test('passing error with a serializer at level ' + name, function (t) {
     t.plan(2)
     var err = new Error('myerror')
diff --git a/test/error.test.js b/test/error.test.js
new file mode 100644
index 0000000..cc932a3
--- /dev/null
+++ b/test/error.test.js
@@ -0,0 +1,107 @@
+'use strict'
+var test = require('tap').test
+var pino = require('../')
+var sink = require('./helper').sink
+
+var os = require('os')
+var pid = process.pid
+var hostname = os.hostname()
+var level = 50
+var name = 'error'
+
+test('err is serialized with additional properties set on the Error object', function (t) {
+  t.plan(2)
+  var err = Object.assign(new Error('myerror'), {foo: 'bar'})
+  var instance = pino(sink(function (chunk, enc, cb) {
+    t.ok(new Date(chunk.time) <= new Date(), 'time is greater than Date.now()')
+    delete chunk.time
+    t.deepEqual(chunk, {
+      pid: pid,
+      hostname: hostname,
+      level: level,
+      type: 'Error',
+      msg: err.message,
+      stack: err.stack,
+      foo: err.foo,
+      v: 1
+    })
+    cb()
+  }))
+
+  instance.level = name
+  instance[name](err)
+})
+
+test('type should be retained, even if type is a property', function (t) {
+  t.plan(2)
+  var err = Object.assign(new Error('myerror'), {type: 'bar'})
+  var instance = pino(sink(function (chunk, enc, cb) {
+    t.ok(new Date(chunk.time) <= new Date(), 'time is greater than Date.now()')
+    delete chunk.time
+    t.deepEqual(chunk, {
+      pid: pid,
+      hostname: hostname,
+      level: level,
+      type: 'bar',
+      msg: err.message,
+      stack: err.stack,
+      v: 1
+    })
+    cb()
+  }))
+
+  instance.level = name
+  instance[name](err)
+})
+
+test('type, message and stack should be first level properties', function (t) {
+  t.plan(2)
+  var err = Object.assign(new Error('foo'), { foo: 'bar' })
+  var instance = pino(sink(function (chunk, enc, cb) {
+    t.ok(new Date(chunk.time) <= new Date(), 'time is greater than Date.now()')
+    delete chunk.time
+    t.deepEqual(chunk, {
+      pid: pid,
+      hostname: hostname,
+      level: level,
+      type: 'Error',
+      msg: err.message,
+      stack: err.stack,
+      foo: err.foo,
+      v: 1
+    })
+    cb()
+  }))
+
+  instance.level = name
+  instance[name](err)
+})
+
+test('err serializer', function (t) {
+  t.plan(2)
+  var err = Object.assign(new Error('myerror'), {foo: 'bar'})
+  var instance = pino({
+    serializers: {
+      err: pino.stdSerializers.err
+    }
+  }, sink(function (chunk, enc, cb) {
+    t.ok(new Date(chunk.time) <= new Date(), 'time is greater than Date.now()')
+    delete chunk.time
+    t.deepEqual(chunk, {
+      pid: pid,
+      hostname: hostname,
+      level: level,
+      err: {
+        type: 'Error',
+        message: err.message,
+        stack: err.stack,
+        foo: err.foo
+      },
+      v: 1
+    })
+    cb()
+  }))
+
+  instance.level = name
+  instance[name]({ err })
+})