From f62472f9bf730b7745ea40a256d8b110af027253 Mon Sep 17 00:00:00 2001 From: Matteo Collina Date: Thu, 4 Oct 2018 18:20:29 +0200 Subject: [PATCH 1/2] Makes final warn that is not supported instead of throwing --- lib/tools.js | 11 ++++++++- test/final.test.js | 35 ++++++++++++++++++++-------- test/fixtures/pretty/final-return.js | 7 ++++++ test/fixtures/pretty/final.js | 9 +++++++ test/pretty.test.js | 26 +++++++++++++++++++++ 5 files changed, 77 insertions(+), 11 deletions(-) create mode 100644 test/fixtures/pretty/final-return.js create mode 100644 test/fixtures/pretty/final.js diff --git a/lib/tools.js b/lib/tools.js index 069d12a9c..609980e35 100644 --- a/lib/tools.js +++ b/lib/tools.js @@ -26,6 +26,8 @@ const { // there, as data might get lost during freeze const isAWSLambda = !!process.env.LAMBDA_TASK_ROOT +const finalWarn = 'final only works with pino.destination() or pino.extreme()' + function noop () {} function genLog (z) { @@ -288,7 +290,14 @@ function final (logger, handler) { } const stream = logger[streamSym] if (!(stream instanceof SonicBoom)) { - throw Error('only compatible with loggers with pino.destination and pino.extreme targets') + logger.warn(finalWarn) + if (hasHandler) { + return (err, ...args) => { + return handler(err, logger, ...args) + } + } else { + return logger + } } const finalLogger = new Proxy(logger, { diff --git a/test/final.test.js b/test/final.test.js index 9af04cfef..be2df0848 100644 --- a/test/final.test.js +++ b/test/final.test.js @@ -24,18 +24,33 @@ test('throws if the supplied handler is not a function', async ({ throws }) => { }, Error('if supplied, the handler parameter should be a function')) }) -test('throws if not supplied logger with pino.destination or pino.extreme instance', async ({ throws, doesNotThrow }) => { - throws(() => { - pino.final(pino(fs.createWriteStream('/dev/null')), () => {}) - }, Error('only compatible with loggers with pino.destination and pino.extreme')) +test('logs as warn if not supplied logger with pino.destination or pino.extreme instance', async ({ plan, is }) => { + plan(2) - doesNotThrow(() => { - pino.final(pino(pino.destination()), () => {}) - }) + const logger = pino(fs.createWriteStream('/dev/null')) + logger.warn = (msg) => { + is(msg, 'final only works with pino.destination() or pino.extreme()') + } - doesNotThrow(() => { - pino.final(pino(pino.extreme()), () => {}) - }) + pino.final(logger, () => {})() + pino.final(logger) +}) + +test('does not logs as warn if supplied logger with pino.destination or pino.extreme instance', async ({ fail }) => { + const logger = pino(pino.destination()) + logger.warn = () => { + fail('warn should not be called') + } + + pino.final(logger, () => {})() + pino.final(logger) + + const extreme = pino(pino.extreme()) + extreme.warn = () => { + fail('warn should not be called') + } + pino.final(extreme, () => {})() + pino.final(extreme) }) test('returns an exit listener function', async ({ is }) => { diff --git a/test/fixtures/pretty/final-return.js b/test/fixtures/pretty/final-return.js new file mode 100644 index 000000000..d2146ea2b --- /dev/null +++ b/test/fixtures/pretty/final-return.js @@ -0,0 +1,7 @@ +global.process = { __proto__: process, pid: 123456 } +Date.now = function () { return 1459875739796 } +require('os').hostname = function () { return 'abcdefghijklmnopqr' } +var pino = require(require.resolve('./../../../')) +var log = pino({ prettyPrint: true }) +log.info('h') +pino.final(log).info('after') diff --git a/test/fixtures/pretty/final.js b/test/fixtures/pretty/final.js new file mode 100644 index 000000000..1bf07c13b --- /dev/null +++ b/test/fixtures/pretty/final.js @@ -0,0 +1,9 @@ +global.process = { __proto__: process, pid: 123456 } +Date.now = function () { return 1459875739796 } +require('os').hostname = function () { return 'abcdefghijklmnopqr' } +var pino = require(require.resolve('./../../../')) +var log = pino({ prettyPrint: true }) +log.info('h') +process.once('beforeExit', pino.final(log, (_, logger) => { + logger.info('beforeExit') +})) diff --git a/test/pretty.test.js b/test/pretty.test.js index 8905fc222..01485187b 100644 --- a/test/pretty.test.js +++ b/test/pretty.test.js @@ -202,3 +202,29 @@ test('errors with props', async ({ isNot }) => { isNot(actual.match(/errno: 1/), null) isNot(actual.match(/.*error-props\.js.*/), null) }) + +test('final works with pretty', async ({ isNot }) => { + var actual = '' + const child = fork(join(__dirname, 'fixtures', 'pretty', 'final.js'), { silent: true }) + + child.stdout.pipe(writer((s, enc, cb) => { + actual += s + cb() + })) + await once(child, 'close') + isNot(actual.match(/WARN \(123456 on abcdefghijklmnopqr\): final only works with pino.destination\(\) or pino.extreme\(\)/), null) + isNot(actual.match(/INFO \(123456 on abcdefghijklmnopqr\): beforeExit/), null) +}) + +test('returning ', async ({ isNot }) => { + var actual = '' + const child = fork(join(__dirname, 'fixtures', 'pretty', 'final-return.js'), { silent: true }) + + child.stdout.pipe(writer((s, enc, cb) => { + actual += s + cb() + })) + await once(child, 'close') + isNot(actual.match(/WARN \(123456 on abcdefghijklmnopqr\): final only works with pino.destination\(\) or pino.extreme\(\)/), null) + isNot(actual.match(/INFO \(123456 on abcdefghijklmnopqr\): after/), null) +}) From 01db9a666bfb89d28710fc91c1266abe242c10fb Mon Sep 17 00:00:00 2001 From: Matteo Collina Date: Fri, 5 Oct 2018 12:47:38 +0200 Subject: [PATCH 2/2] Warn inside pretty, not in final. --- lib/tools.js | 49 +++++++++++++++++++++++++++++---------------- test/final.test.js | 35 +++++++++----------------------- test/pretty.test.js | 4 ++-- 3 files changed, 44 insertions(+), 44 deletions(-) diff --git a/lib/tools.js b/lib/tools.js index 609980e35..9398257c1 100644 --- a/lib/tools.js +++ b/lib/tools.js @@ -26,8 +26,6 @@ const { // there, as data might get lost during freeze const isAWSLambda = !!process.env.LAMBDA_TASK_ROOT -const finalWarn = 'final only works with pino.destination() or pino.extreme()' - function noop () {} function genLog (z) { @@ -181,23 +179,47 @@ function getPrettyStream (opts, prettifier, dest) { } function prettifierMetaWrapper (pretty, dest) { + var warned = false return { [needsMetadataGsym]: true, lastLevel: 0, lastMsg: null, lastObj: null, lastLogger: null, - write (chunk) { + flushSync () { + if (warned) { + return + } + warned = true + dest.write(pretty(Object.assign({ + level: 40, // warn + msg: 'pino.final with prettyPrint does not support flushing', + time: Date.now() + }, this.chindings()))) + }, + chindings () { const lastLogger = this.lastLogger var chindings = null + // protection against flushSync being called before logging + // anything + if (!lastLogger) { + return null + } + if (lastLogger.hasOwnProperty(parsedChindingsSym)) { - chindings = this.lastLogger[parsedChindingsSym] + chindings = lastLogger[parsedChindingsSym] } else { - chindings = JSON.parse('{"v":1' + this.lastLogger[chindingsSym] + '}') - this.lastLogger[parsedChindingsSym] = chindings + chindings = JSON.parse('{"v":1' + lastLogger[chindingsSym] + '}') + lastLogger[parsedChindingsSym] = chindings } + return chindings + }, + write (chunk) { + const lastLogger = this.lastLogger + const chindings = this.chindings() + var time = this.lastTime if (time.match(/^\d+/)) { @@ -222,7 +244,7 @@ function prettifierMetaWrapper (pretty, dest) { time }, chindings, lastObj, errorProps) - const serializers = this.lastLogger[serializersSym] + const serializers = lastLogger[serializersSym] const keys = Object.keys(serializers) var key @@ -233,7 +255,7 @@ function prettifierMetaWrapper (pretty, dest) { } } - const stringifiers = this.lastLogger[stringifiersSym] + const stringifiers = lastLogger[stringifiersSym] const redact = stringifiers[redactFmtSym] const formatted = pretty(typeof redact === 'function' ? redact(obj) : obj) @@ -289,15 +311,8 @@ function final (logger, handler) { throw Error('if supplied, the handler parameter should be a function') } const stream = logger[streamSym] - if (!(stream instanceof SonicBoom)) { - logger.warn(finalWarn) - if (hasHandler) { - return (err, ...args) => { - return handler(err, logger, ...args) - } - } else { - return logger - } + if (typeof stream.flushSync !== 'function') { + throw Error('final requires a stream that has a flushSync method, such as pino.destination and pino.extreme') } const finalLogger = new Proxy(logger, { diff --git a/test/final.test.js b/test/final.test.js index be2df0848..cb0ec016a 100644 --- a/test/final.test.js +++ b/test/final.test.js @@ -24,33 +24,18 @@ test('throws if the supplied handler is not a function', async ({ throws }) => { }, Error('if supplied, the handler parameter should be a function')) }) -test('logs as warn if not supplied logger with pino.destination or pino.extreme instance', async ({ plan, is }) => { - plan(2) - - const logger = pino(fs.createWriteStream('/dev/null')) - logger.warn = (msg) => { - is(msg, 'final only works with pino.destination() or pino.extreme()') - } - - pino.final(logger, () => {})() - pino.final(logger) -}) - -test('does not logs as warn if supplied logger with pino.destination or pino.extreme instance', async ({ fail }) => { - const logger = pino(pino.destination()) - logger.warn = () => { - fail('warn should not be called') - } +test('throws if not supplied logger with pino.destination or pino.extreme instance', async ({ throws, doesNotThrow }) => { + throws(() => { + pino.final(pino(fs.createWriteStream('/dev/null')), () => {}) + }, Error('inal requires a stream that has a flushSync method, such as pino.destination and pino.extreme')) - pino.final(logger, () => {})() - pino.final(logger) + doesNotThrow(() => { + pino.final(pino(pino.destination()), () => {}) + }) - const extreme = pino(pino.extreme()) - extreme.warn = () => { - fail('warn should not be called') - } - pino.final(extreme, () => {})() - pino.final(extreme) + doesNotThrow(() => { + pino.final(pino(pino.extreme()), () => {}) + }) }) test('returns an exit listener function', async ({ is }) => { diff --git a/test/pretty.test.js b/test/pretty.test.js index 01485187b..6c888dd04 100644 --- a/test/pretty.test.js +++ b/test/pretty.test.js @@ -212,7 +212,7 @@ test('final works with pretty', async ({ isNot }) => { cb() })) await once(child, 'close') - isNot(actual.match(/WARN \(123456 on abcdefghijklmnopqr\): final only works with pino.destination\(\) or pino.extreme\(\)/), null) + isNot(actual.match(/WARN \(123456 on abcdefghijklmnopqr\): pino.final with prettyPrint does not support flushing/), null) isNot(actual.match(/INFO \(123456 on abcdefghijklmnopqr\): beforeExit/), null) }) @@ -225,6 +225,6 @@ test('returning ', async ({ isNot }) => { cb() })) await once(child, 'close') - isNot(actual.match(/WARN \(123456 on abcdefghijklmnopqr\): final only works with pino.destination\(\) or pino.extreme\(\)/), null) + isNot(actual.match(/WARN \(123456 on abcdefghijklmnopqr\): pino.final with prettyPrint does not support flushing/), null) isNot(actual.match(/INFO \(123456 on abcdefghijklmnopqr\): after/), null) })