Repository: pinojs/pino (js)

Issue:
default destination does not flush logs on error
(The following tests were performed on pino 6.3.0.)

The following test case does not write the `second` log entry before the process terminates.
```js
const log = require('pino')()

log.info('first')
log.info('second')

throw new Error()
```
OUTPUT:
```
{"level":30,"time":1590765315557,"pid":21297,"hostname":"redacted","msg":"first"}
/home/mpareja/projects/pino-test/pino-throw.js:7
throw new Error()
^

Error
    at Object.<anonymous> (/home/mpareja/projects/pino-test/pino-throw.js:7:7)
```

---
Interestingly, if I configure the destination explicitly based on the [documented default](http://getpino.io/#/docs/api?id=destination-sonicboom-writablestream-string-object), it does write the `second` log entry.

```js
const pino = require('pino')
const log = pino(pino.destination(1))

log.info('first')
log.info('second')

throw new Error()
```
OUTPUT:
```
{"level":30,"time":1590765396289,"pid":21438,"hostname":"redacted","msg":"first"}
{"level":30,"time":1590765396289,"pid":21438,"hostname":"redacted","msg":"second"}
/home/mpareja/projects/pino-test/pino-throw.js:7
throw new Error()
^

Error
    at Object.<anonymous> (/home/mpareja/projects/pino-test/pino-throw.js:7:7)
```

Can you shed some light on the intended behaviour?

Pull request:
Set sync: true when passing in no defaults
In the migration to the sync flag, we have changed the default of pino
making it async by default. This resolves the problem.

Fixes #849.

Patch:
diff --git a/lib/tools.js b/lib/tools.js
index 92236eb..50decf1 100644
--- a/lib/tools.js
+++ b/lib/tools.js
@@ -314,10 +314,10 @@ function createArgsNormalizer (defaultOptions) {
   return function normalizeArgs (instance, opts = {}, stream) {
     // support stream as a string
     if (typeof opts === 'string') {
-      stream = buildSafeSonicBoom({ dest: opts })
+      stream = buildSafeSonicBoom({ dest: opts, sync: true })
       opts = {}
     } else if (typeof stream === 'string') {
-      stream = buildSafeSonicBoom({ dest: stream })
+      stream = buildSafeSonicBoom({ dest: stream, sync: true })
     } else if (opts instanceof SonicBoom || opts.writable || opts._writableState) {
       stream = opts
       opts = null
@@ -341,7 +341,7 @@ function createArgsNormalizer (defaultOptions) {
     if (enabled === false) opts.level = 'silent'
     stream = stream || process.stdout
     if (stream === process.stdout && stream.fd >= 0 && !hasBeenTampered(stream)) {
-      stream = buildSafeSonicBoom({ fd: stream.fd })
+      stream = buildSafeSonicBoom({ fd: stream.fd, sync: true })
     }
     if (prettyPrint) {
       const prettyOpts = Object.assign({ messageKey }, prettyPrint)


Test patch:
diff --git a/test/exit.test.js b/test/exit.test.js
index b4279f2..de0caa1 100644
--- a/test/exit.test.js
+++ b/test/exit.test.js
@@ -22,6 +22,21 @@ test('pino.destination log everything when calling process.exit(0)', async ({ is
   isNot(actual.match(/world/), null)
 })
 
+test('pino with no args log everything when calling process.exit(0)', async ({ isNot }) => {
+  var actual = ''
+  const child = execa(process.argv[0], [join(__dirname, 'fixtures', 'default-exit.js')])
+
+  child.stdout.pipe(writer((s, enc, cb) => {
+    actual += s
+    cb()
+  }))
+
+  await once(child, 'close')
+
+  isNot(actual.match(/hello/), null)
+  isNot(actual.match(/world/), null)
+})
+
 test('sync false does not log everything when calling process.exit(0)', async ({ is }) => {
   var actual = ''
   const child = execa(process.argv[0], [join(__dirname, 'fixtures', 'syncfalse-exit.js')])
diff --git a/test/fixtures/default-exit.js b/test/fixtures/default-exit.js
new file mode 100644
index 0000000..99b740d
--- /dev/null
+++ b/test/fixtures/default-exit.js
@@ -0,0 +1,8 @@
+global.process = { __proto__: process, pid: 123456 }
+Date.now = function () { return 1459875739796 }
+require('os').hostname = function () { return 'abcdefghijklmnopqr' }
+var pino = require(require.resolve('./../../'))
+var logger = pino()
+logger.info('hello')
+logger.info('world')
+process.exit(0)