Repository: pinojs/pino
Pull request #540 (2018-11-06 00:15:10)

do not crash on broken pipe, just redirect to /dev/null
Fixes https://github.com/pinojs/pino/issues/539
Fixes https://github.com/pinojs/pino/issues/535

jsumners: Question: I was just looking into the issue myself. When I modify the provided example service to use `process.stdout` (`pino({ destination: process.stdout })`), the error still occurs. This PR seems to imply the error only happens if the destination is a SonicBoom destination. Is this accurate?

Patch:
diff --git a/lib/tools.js b/lib/tools.js
index 9398257..c9c16f6 100644
--- a/lib/tools.js
+++ b/lib/tools.js
@@ -269,14 +269,36 @@ function hasBeenTampered (stream) {
   return stream.write !== stream.constructor.prototype.write
 }
 
+function buildSafeSonicBoom (dest, buffer = 0) {
+  const stream = new SonicBoom(dest, buffer)
+  stream.on('error', filterBrokenPipe)
+  return stream
+
+  function filterBrokenPipe (err) {
+    // TODO verify on Windows
+    if (err.code === 'EPIPE') {
+      // If we get EPIPE, we should stop logging here
+      // however we have no control to the consumer of
+      // SonicBoom, so we just overwrite the write method
+      stream.write = noop
+      stream.end = noop
+      stream.flushSync = noop
+      stream.destroy = noop
+      return
+    }
+    stream.removeListener('error', filterBrokenPipe)
+    stream.emit('error', err)
+  }
+}
+
 function createArgsNormalizer (defaultOptions) {
   return function normalizeArgs (opts = {}, stream) {
     // support stream as a string
     if (typeof opts === 'string') {
-      stream = new SonicBoom(opts)
+      stream = buildSafeSonicBoom(opts)
       opts = {}
     } else if (typeof stream === 'string') {
-      stream = new SonicBoom(stream)
+      stream = buildSafeSonicBoom(stream)
     } else if (opts instanceof SonicBoom || opts.writable || opts._writableState) {
       stream = opts
       opts = null
@@ -292,7 +314,7 @@ function createArgsNormalizer (defaultOptions) {
     if (enabled === false) opts.level = 'silent'
     stream = stream || process.stdout
     if (stream === process.stdout && stream.fd >= 0 && !isAWSLambda && !hasBeenTampered(stream)) {
-      stream = new SonicBoom(stream.fd)
+      stream = buildSafeSonicBoom(stream.fd)
     }
     if (prettyPrint) {
       const prettyOpts = Object.assign({ messageKey }, prettyPrint)
@@ -354,6 +376,7 @@ function stringify (obj) {
 
 module.exports = {
   noop,
+  buildSafeSonicBoom,
   getPrettyStream,
   asChindings,
   asJson,
diff --git a/pino.js b/pino.js
index 427c3d6..0600ca1 100644
--- a/pino.js
+++ b/pino.js
@@ -1,7 +1,6 @@
 'use strict'
 const os = require('os')
 const stdSerializers = require('pino-std-serializers')
-const SonicBoom = require('sonic-boom')
 const redaction = require('./lib/redaction')
 const time = require('./lib/time')
 const proto = require('./lib/proto')
@@ -11,7 +10,8 @@ const {
   createArgsNormalizer,
   asChindings,
   final,
-  stringify
+  stringify,
+  buildSafeSonicBoom
 } = require('./lib/tools')
 const { version, LOG_VERSION } = require('./lib/meta')
 const {
@@ -119,8 +119,9 @@ function pino (...args) {
   return instance
 }
 
-pino.extreme = (dest = process.stdout.fd) => new SonicBoom(dest, 4096)
-pino.destination = (dest = process.stdout.fd) => new SonicBoom(dest)
+pino.extreme = (dest = process.stdout.fd) => buildSafeSonicBoom(dest, 4096)
+pino.destination = (dest = process.stdout.fd) => buildSafeSonicBoom(dest)
+
 pino.final = final
 pino.levels = mappings()
 pino.stdSerializers = serializers


Test patch:
diff --git a/test/broken-pipe.test.js b/test/broken-pipe.test.js
new file mode 100644
index 0000000..0454cee
--- /dev/null
+++ b/test/broken-pipe.test.js
@@ -0,0 +1,42 @@
+'use strict'
+
+const t = require('tap')
+const { join } = require('path')
+const { fork } = require('child_process')
+const { once } = require('./helper')
+const pino = require('..')
+
+function test (file) {
+  file = join('fixtures', 'broken-pipe', file)
+  t.test(file, { parallel: true }, async ({ is }) => {
+    const child = fork(join(__dirname, file), { silent: true })
+    child.stdout.destroy()
+
+    child.stderr.pipe(process.stdout)
+
+    const res = await once(child, 'close')
+    is(res, 0) // process exits successfully
+  })
+}
+
+t.jobs = 42
+
+test('basic.js')
+test('destination.js')
+test('extreme.js')
+
+t.test('let error pass through', ({ is, plan }) => {
+  plan(3)
+  const stream = pino.destination()
+
+  // side effect of the pino constructor is that it will set an
+  // event handler for error
+  pino(stream)
+
+  process.nextTick(() => stream.emit('error', new Error('kaboom')))
+  process.nextTick(() => stream.emit('error', new Error('kaboom')))
+
+  stream.on('error', (err) => {
+    is(err.message, 'kaboom')
+  })
+})
diff --git a/test/fixtures/broken-pipe/basic.js b/test/fixtures/broken-pipe/basic.js
new file mode 100644
index 0000000..def7cd0
--- /dev/null
+++ b/test/fixtures/broken-pipe/basic.js
@@ -0,0 +1,9 @@
+'use strict'
+
+global.process = { __proto__: process, pid: 123456 }
+Date.now = function () { return 1459875739796 }
+require('os').hostname = function () { return 'abcdefghijklmnopqr' }
+
+const pino = require('../../..')()
+
+pino.info('hello world')
diff --git a/test/fixtures/broken-pipe/destination.js b/test/fixtures/broken-pipe/destination.js
new file mode 100644
index 0000000..15a8102
--- /dev/null
+++ b/test/fixtures/broken-pipe/destination.js
@@ -0,0 +1,10 @@
+'use strict'
+
+global.process = { __proto__: process, pid: 123456 }
+Date.now = function () { return 1459875739796 }
+require('os').hostname = function () { return 'abcdefghijklmnopqr' }
+
+const pino = require('../../..')
+const logger = pino(pino.destination())
+
+logger.info('hello world')
diff --git a/test/fixtures/broken-pipe/extreme.js b/test/fixtures/broken-pipe/extreme.js
new file mode 100644
index 0000000..27a624b
--- /dev/null
+++ b/test/fixtures/broken-pipe/extreme.js
@@ -0,0 +1,12 @@
+'use strict'
+
+global.process = { __proto__: process, pid: 123456 }
+Date.now = function () { return 1459875739796 }
+require('os').hostname = function () { return 'abcdefghijklmnopqr' }
+
+const pino = require('../../..')
+const logger = pino(pino.extreme())
+
+for (let i = 0; i < 1000; i++) {
+  logger.info('hello world')
+}