From d4ce32ae24d1bbf8fda1d443b502686ff03ab9d4 Mon Sep 17 00:00:00 2001
From: Raz Luvaton <16746759+rluvaton@users.noreply.github.com>
Date: Thu, 5 Oct 2023 17:32:49 +0300
Subject: [PATCH 1/4] allow passing callback to flush
---
docs/api.md | 7 ++-
lib/proto.js | 11 ++++-
package.json | 2 +-
pino.d.ts | 3 +-
test/syncfalse.test.js | 79 ++++++++++++++++++++++++++++++--
test/transport/syncfalse.test.js | 35 ++++++++++++++
test/types/pino.test-d.ts | 1 +
7 files changed, 127 insertions(+), 11 deletions(-)
diff --git a/docs/api.md b/docs/api.md
index b594d74e7..ee071ea88 100644
--- a/docs/api.md
+++ b/docs/api.md
@@ -964,12 +964,12 @@ console.log(anotherChild.bindings())
```
-### `logger.flush()`
+### `logger.flush([cb])`
Flushes the content of the buffer when using `pino.destination({
sync: false })`.
-This is an asynchronous, fire and forget, operation.
+This is an asynchronous, best used as fire and forget, operation.
The use case is primarily for asynchronous logging, which may buffer
log lines while others are being written. The `logger.flush` method can be
@@ -978,6 +978,9 @@ on a long interval, say ten seconds. Such a strategy can provide an
optimum balance between extremely efficient logging at high demand periods
and safer logging at low demand periods.
+if needed to wait for the logs to be flushed, the callback can be used.
+(when using a custom `WritableStream` in destination that has the `flush` function, you should call the callback after finish flushing)
+
* See [`destination` parameter](#destination)
* See [Asynchronous Logging ⇗](/docs/asynchronous.md)
diff --git a/lib/proto.js b/lib/proto.js
index 43a3b7b8b..624f809ab 100644
--- a/lib/proto.js
+++ b/lib/proto.js
@@ -219,7 +219,14 @@ function write (_obj, msg, num) {
function noop () {}
-function flush () {
+function flush (cb) {
+ if (cb != null && typeof cb !== 'function') {
+ throw Error('callback must be a function')
+ }
+
const stream = this[streamSym]
- if ('flush' in stream) stream.flush(noop)
+
+ if ('flush' in stream) {
+ stream.flush(cb || noop)
+ } else if (cb) cb()
}
diff --git a/package.json b/package.json
index 0c6c4a3af..2c633294d 100644
--- a/package.json
+++ b/package.json
@@ -110,7 +110,7 @@
"quick-format-unescaped": "^4.0.3",
"real-require": "^0.2.0",
"safe-stable-stringify": "^2.3.1",
- "sonic-boom": "^3.1.0",
+ "sonic-boom": "https://github.com/pinojs/sonic-boom.git",
"thread-stream": "^2.0.0"
},
"tsd": {
diff --git a/pino.d.ts b/pino.d.ts
index 1227dcfcd..91c577078 100644
--- a/pino.d.ts
+++ b/pino.d.ts
@@ -122,8 +122,9 @@ export interface LoggerExtras extends EventEmitter {
/**
* Flushes the content of the buffer when using pino.destination({ sync: false }).
+ * call the callback when finished
*/
- flush(): void;
+ flush(cb?: (err?: Error) => void): void;
}
diff --git a/test/syncfalse.test.js b/test/syncfalse.test.js
index b118ed9da..d830921fa 100644
--- a/test/syncfalse.test.js
+++ b/test/syncfalse.test.js
@@ -1,14 +1,26 @@
'use strict'
const os = require('os')
-const { createWriteStream } = require('fs')
+const {
+ createWriteStream
+} = require('fs')
+const { readFile } = require('fs').promises
const { join } = require('path')
const { test } = require('tap')
const { fork } = require('child_process')
const writer = require('flush-write-stream')
-const { once, getPathToNull } = require('./helper')
+const {
+ once,
+ getPathToNull,
+ file,
+ watchFileCreated
+} = require('./helper')
+const { promisify } = require('util')
-test('asynchronous logging', async ({ equal, teardown }) => {
+test('asynchronous logging', async ({
+ equal,
+ teardown
+}) => {
const now = Date.now
const hostname = os.hostname
const proc = process
@@ -58,7 +70,10 @@ test('asynchronous logging', async ({ equal, teardown }) => {
})
})
-test('sync false with child', async ({ equal, teardown }) => {
+test('sync false with child', async ({
+ equal,
+ teardown
+}) => {
const now = Date.now
const hostname = os.hostname
const proc = process
@@ -82,7 +97,9 @@ test('sync false with child', async ({ equal, teardown }) => {
})).child({ hello: 'world' })
const dest = createWriteStream(getPathToNull())
- dest.write = function (s) { actual += s }
+ dest.write = function (s) {
+ actual += s
+ }
const asyncLogger = pino(dest).child({ hello: 'world' })
let i = 500
@@ -116,3 +133,55 @@ test('flush does nothing with sync true (default)', async ({ equal }) => {
const instance = require('..')()
equal(instance.flush(), undefined)
})
+
+test('should still call flush callback even when does nothing with sync true (default)', (t) => {
+ t.plan(3)
+ const instance = require('..')()
+ instance.flush((...args) => {
+ t.ok('flush called')
+ t.same(args, [])
+
+ // next tick to make flush not called more than once
+ process.nextTick(() => {
+ t.ok('flush next tick called')
+ })
+ })
+})
+
+test('should call the flush callback when flushed the data for async logger', async (t) => {
+ const outputPath = file()
+ async function getOutputLogLines () {
+ return (await readFile(outputPath)).toString().trim().split('\n').map(JSON.parse)
+ }
+
+ const pino = require('../')
+
+ const instance = pino({}, pino.destination({
+ dest: outputPath,
+
+ // to make sure it does not flush on its own
+ minLength: 4096
+ }))
+ const flushPromise = promisify(instance.flush).bind(instance)
+
+ instance.info('hello')
+ await flushPromise()
+ await watchFileCreated(outputPath)
+
+ const [firstFlushData] = await getOutputLogLines()
+
+ t.equal(firstFlushData.msg, 'hello')
+
+ // should not flush this as no data accumulated that's bigger than min length
+ instance.info('world')
+
+ // Making sure data is not flushed yet
+ const afterLogData = await getOutputLogLines()
+ t.equal(afterLogData.length, 1)
+
+ await flushPromise()
+
+ // Making sure data is not flushed yet
+ const afterSecondFlush = (await getOutputLogLines())[1]
+ t.equal(afterSecondFlush.msg, 'world')
+})
diff --git a/test/transport/syncfalse.test.js b/test/transport/syncfalse.test.js
index 81111b532..4b9f682cd 100644
--- a/test/transport/syncfalse.test.js
+++ b/test/transport/syncfalse.test.js
@@ -6,6 +6,7 @@ const { join } = require('path')
const { test } = require('tap')
const { readFile } = require('fs').promises
const { watchFileCreated, file } = require('../helper')
+const { promisify } = require('util')
const { pid } = process
const hostname = os.hostname()
@@ -31,3 +32,37 @@ test('thread-stream async flush', async ({ equal, same }) => {
msg: 'hello'
})
})
+
+test('thread-stream async flush should call the passed callback', async (t) => {
+ const outputPath = file()
+ async function getOutputLogLines () {
+ return (await readFile(outputPath)).toString().trim().split('\n').map(JSON.parse)
+ }
+ const transport = pino.transport({
+ target: join(__dirname, '..', 'fixtures', 'to-file-transport.js'),
+ options: { destination: outputPath }
+ })
+ const instance = pino(transport)
+ const flushPromise = promisify(instance.flush).bind(instance)
+
+ instance.info('hello')
+ await flushPromise()
+ await watchFileCreated(outputPath)
+
+ const [firstFlushData] = await getOutputLogLines()
+
+ t.equal(firstFlushData.msg, 'hello')
+
+ // should not flush this as no data accumulated that's bigger than min length
+ instance.info('world')
+
+ // Making sure data is not flushed yet
+ const afterLogData = await getOutputLogLines()
+ t.equal(afterLogData.length, 1)
+
+ await flushPromise()
+
+ // Making sure data is not flushed yet
+ const afterSecondFlush = (await getOutputLogLines())[1]
+ t.equal(afterSecondFlush.msg, 'world')
+})
diff --git a/test/types/pino.test-d.ts b/test/types/pino.test-d.ts
index 9e4786de6..0641ad0cc 100644
--- a/test/types/pino.test-d.ts
+++ b/test/types/pino.test-d.ts
@@ -112,6 +112,7 @@ pino({ base: null });
if ("pino" in log) console.log(`pino version: ${log.pino}`);
expectType(log.flush());
+log.flush((err?: Error) => undefined);
log.child({ a: "property" }).info("hello child!");
log.level = "error";
log.info("nope");
From 15686987732e2bd3d6bf5d4b64c9bc72f08907f3 Mon Sep 17 00:00:00 2001
From: Raz Luvaton <16746759+rluvaton@users.noreply.github.com>
Date: Fri, 6 Oct 2023 02:20:24 +0300
Subject: [PATCH 2/4] Update api.md
---
docs/api.md | 1 -
1 file changed, 1 deletion(-)
diff --git a/docs/api.md b/docs/api.md
index ee071ea88..9a60a7b41 100644
--- a/docs/api.md
+++ b/docs/api.md
@@ -979,7 +979,6 @@ optimum balance between extremely efficient logging at high demand periods
and safer logging at low demand periods.
if needed to wait for the logs to be flushed, the callback can be used.
-(when using a custom `WritableStream` in destination that has the `flush` function, you should call the callback after finish flushing)
* See [`destination` parameter](#destination)
* See [Asynchronous Logging ⇗](/docs/asynchronous.md)
From b33932f5652673b9e6ba94b1a1fc64e9b618c6e3 Mon Sep 17 00:00:00 2001
From: Raz Luvaton <16746759+rluvaton@users.noreply.github.com>
Date: Fri, 6 Oct 2023 02:24:01 +0300
Subject: [PATCH 3/4] Update docs/api.md
Co-authored-by: James Sumners <321201+jsumners@users.noreply.github.com>
---
docs/api.md | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/docs/api.md b/docs/api.md
index 9a60a7b41..1c30deb3b 100644
--- a/docs/api.md
+++ b/docs/api.md
@@ -978,7 +978,7 @@ on a long interval, say ten seconds. Such a strategy can provide an
optimum balance between extremely efficient logging at high demand periods
and safer logging at low demand periods.
-if needed to wait for the logs to be flushed, the callback can be used.
+If there is a need to wait for the logs to be flushed, a callback should be used.
* See [`destination` parameter](#destination)
* See [Asynchronous Logging ⇗](/docs/asynchronous.md)
From fd341411c77a4a6bd1f1570e239f47f8ccac835c Mon Sep 17 00:00:00 2001
From: Raz Luvaton <16746759+rluvaton@users.noreply.github.com>
Date: Mon, 9 Oct 2023 21:15:12 +0300
Subject: [PATCH 4/4] update sonic boom with the latest fix
---
package.json | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/package.json b/package.json
index b5ee03ca6..566d57069 100644
--- a/package.json
+++ b/package.json
@@ -110,7 +110,7 @@
"quick-format-unescaped": "^4.0.3",
"real-require": "^0.2.0",
"safe-stable-stringify": "^2.3.1",
- "sonic-boom": "https://github.com/pinojs/sonic-boom.git",
+ "sonic-boom": "^3.7.0",
"thread-stream": "^2.0.0"
},
"tsd": {