diff --git a/.eslintrc b/.eslintrc new file mode 100644 index 00000000..f8c9986b --- /dev/null +++ b/.eslintrc @@ -0,0 +1,8 @@ +{ + "extends": [ + "standard" + ], + "rules": { + "no-var": "off" + } +} diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 90d04b89..e96c63c7 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -24,7 +24,7 @@ jobs: contents: read steps: - name: Check out repo - uses: actions/checkout@v3 + uses: actions/checkout@v4 with: persist-credentials: false @@ -44,7 +44,7 @@ jobs: os: [ubuntu-latest] steps: - name: Check out repo - uses: actions/checkout@v3 + uses: actions/checkout@v4 with: persist-credentials: false @@ -65,34 +65,6 @@ jobs: - name: Run tests run: npm run ci - - name: Coveralls Parallel - id: coveralls-parallel - uses: coverallsapp/github-action@v2.2.0 - continue-on-error: true - with: - github-token: ${{ secrets.GITHUB_TOKEN }} - parallel: true - flag-name: run-${{ matrix.node-version }}-${{ matrix.os }} - - - name: Should Trigger coverallsapp/github-action@master - id: coveralls-trigger - # https://docs.github.com/en/actions/reference/context-and-expression-syntax-for-github-actions#steps-context - # when continue-on-error failed, outcome is failure and conclusion is success - if: steps.coveralls-parallel.conclusion == 'success' && steps.coveralls-parallel.outcome != 'success' - run: | - echo "::set-output name=COVERALLS_TRIGGER::failure" - - coverage: - needs: test - runs-on: ubuntu-latest - if: needs.test.outputs.COVERALLS != 'failure' - steps: - - name: Coveralls Finished - uses: coverallsapp/github-action@v2.2.0 - with: - github-token: ${{ secrets.GITHUB_TOKEN }} - parallel-finished: true - automerge: name: Automerge Dependabot PRs if: > diff --git a/.taprc b/.taprc deleted file mode 100644 index 112c65be..00000000 --- a/.taprc +++ /dev/null @@ -1,5 +0,0 @@ -ts: false -jsx: false -flow: false -files: - - 'test/**/*.test.js' diff --git a/.taprc.yaml b/.taprc.yaml new file mode 100644 index 00000000..07652a14 --- /dev/null +++ b/.taprc.yaml @@ -0,0 +1,8 @@ +coverage: true +coverage-map: 'coverage-map.js' + +reporter: terse + +files: + - 'lib/**/*.test.js' + - 'test/**/*.test.js' diff --git a/Readme.md b/Readme.md index d39082ba..988615c9 100644 --- a/Readme.md +++ b/Readme.md @@ -298,8 +298,8 @@ const prettifyQuery = value => { } ``` -Additionally, `customPrettifiers` can be used to format the `time`, `hostname`, `pid`, `name`, `caller` and `level` -outputs: +Additionally, `customPrettifiers` can be used to format the `time`, `hostname`, +`pid`, `name`, `caller` and `level` outputs: ```js { @@ -335,7 +335,8 @@ const levelPrettifier = logLevel => `LEVEL: ${levelColorize(logLevel)}` } ``` -`messageFormat` option allows you to customize the message output. A template `string` like this can define the format: +`messageFormat` option allows you to customize the message output. +A template `string` like this can define the format: ```js { @@ -343,6 +344,15 @@ const levelPrettifier = logLevel => `LEVEL: ${levelColorize(logLevel)}` } ``` +In addition to this, if / end statement blocks can also be specified. +Else statements and nested conditions are not supported. + +```js +{ + messageFormat: '{levelLabel} - {if pid}{pid} - {end}url:{req.url}' +} +``` + This option can also be defined as a `function` with this prototype: ```js diff --git a/benchmark.js b/benchmark.js new file mode 100644 index 00000000..aaf7412e --- /dev/null +++ b/benchmark.js @@ -0,0 +1,105 @@ +'use strict' + +// We do not expect amazing numbers from `pino-pretty` as the whole purpose +// of the module is a very slow operation. However, this benchmark should give +// us some guidance on how features, or code changes, will affect the +// performance of the module. + +const bench = require('fastbench') +const { + prettyFactory +} = require('./index') + +const max = 10 +const tstampMillis = 1693401358754 + +/* eslint-disable no-var */ +const run = bench([ + function basicLog (cb) { + const pretty = prettyFactory({}) + const input = `{"time":${tstampMillis},"pid":1,"hostname":"foo","msg":"benchmark","foo":"foo","bar":{"bar":"bar"}}\n` + for (var i = 0; i < max; i += 1) { + pretty(input) + } + setImmediate(cb) + }, + + function objectLog (cb) { + const pretty = prettyFactory({}) + const input = { + time: tstampMillis, + pid: 1, + hostname: 'foo', + msg: 'benchmark', + foo: 'foo', + bar: { bar: 'bar' } + } + for (var i = 0; i < max; i += 1) { + pretty(input) + } + setImmediate(cb) + }, + + function coloredLog (cb) { + const pretty = prettyFactory({ colorize: true }) + const input = `{"time":${tstampMillis},"pid":1,"hostname":"foo","msg":"benchmark","foo":"foo","bar":{"bar":"bar"}}\n` + for (var i = 0; i < max; i += 1) { + pretty(input) + } + setImmediate(cb) + }, + + function customPrettifiers (cb) { + const pretty = prettyFactory({ + customPrettifiers: { + time (tstamp) { + return tstamp + }, + pid () { + return '' + } + } + }) + const input = `{"time":${tstampMillis},"pid":1,"hostname":"foo","msg":"benchmark","foo":"foo","bar":{"bar":"bar"}}\n` + for (var i = 0; i < max; i += 1) { + pretty(input) + } + setImmediate(cb) + }, + + function logWithErrorObject (cb) { + const pretty = prettyFactory({}) + const err = Error('boom') + const input = `{"time":${tstampMillis},"pid":1,"hostname":"foo","msg":"benchmark","foo":"foo","bar":{"bar":"bar"},"err":{"message":"${err.message}","stack":"${err.stack}"}}\n` + for (var i = 0; i < max; i += 1) { + pretty(input) + } + setImmediate(cb) + }, + + function logRemappedMsgErrKeys (cb) { + const pretty = prettyFactory({ + messageKey: 'message', + errorLikeObjectKeys: ['myError'] + }) + const err = Error('boom') + const input = `{"time":${tstampMillis},"pid":1,"hostname":"foo","message":"benchmark","foo":"foo","bar":{"bar":"bar"},"myError":{"message":"${err.message}","stack":"${err.stack}"}}\n` + for (var i = 0; i < max; i += 1) { + pretty(input) + } + setImmediate(cb) + }, + + function messageFormatString (cb) { + const pretty = prettyFactory({ + messageFormat: '{levelLabel}{if pid} {pid} - {end}{msg}' + }) + const input = `{"time":${tstampMillis},"pid":1,"hostname":"foo","msg":"benchmark","foo":"foo","bar":{"bar":"bar"}}\n` + for (var i = 0; i < max; i += 1) { + pretty(input) + } + setImmediate(cb) + } +], 10000) + +run(run) diff --git a/coverage-map.js b/coverage-map.js new file mode 100644 index 00000000..ca58935a --- /dev/null +++ b/coverage-map.js @@ -0,0 +1,9 @@ +'use strict' + +module.exports = testFile => { + // Ignore coverage on files that do not have a direct corollary. + if (testFile.startsWith('test/')) return false + + // Indicate the matching name, sans '.test.js', should be checked for coverage. + return testFile.replace(/\.test\.js$/, '.js') +} diff --git a/index.js b/index.js index 41eb7602..141fc8f2 100644 --- a/index.js +++ b/index.js @@ -4,211 +4,132 @@ const { isColorSupported } = require('colorette') const pump = require('pump') const { Transform } = require('readable-stream') const abstractTransport = require('pino-abstract-transport') -const sjs = require('secure-json-parse') const colors = require('./lib/colors') -const { ERROR_LIKE_KEYS, MESSAGE_KEY, TIMESTAMP_KEY, LEVEL_KEY, LEVEL_NAMES } = require('./lib/constants') const { - isObject, - prettifyErrorLog, - prettifyLevel, - prettifyMessage, - prettifyMetadata, - prettifyObject, - prettifyTime, + ERROR_LIKE_KEYS, + LEVEL_KEY, + LEVEL_LABEL, + MESSAGE_KEY, + TIMESTAMP_KEY +} = require('./lib/constants') +const { buildSafeSonicBoom, - filterLog, - handleCustomlevelsOpts, - handleCustomlevelNamesOpts + parseFactoryOptions } = require('./lib/utils') - -const jsonParser = input => { - try { - return { value: sjs.parse(input, { protoAction: 'remove' }) } - } catch (err) { - return { err } - } -} - +const pretty = require('./lib/pretty') + +/** + * @typedef {object} PinoPrettyOptions + * @property {boolean} [colorize] Indicates if colors should be used when + * prettifying. The default will be determined by the terminal capabilities at + * run time. + * @property {boolean} [colorizeObjects=true] Apply coloring to rendered objects + * when coloring is enabled. + * @property {boolean} [crlf=false] End lines with `\r\n` instead of `\n`. + * @property {string|null} [customColors=null] A comma separated list of colors + * to use for specific level labels, e.g. `err:red,info:blue`. + * @property {string|null} [customLevels=null] A comma separated list of user + * defined level names and numbers, e.g. `err:99,info:1`. + * @property {CustomPrettifiers} [customPrettifiers={}] A set of prettifier + * functions to apply to keys defined in this object. + * @property {K_ERROR_LIKE_KEYS} [errorLikeObjectKeys] A list of string property + * names to consider as error objects. + * @property {string} [errorProps=''] A comma separated list of properties on + * error objects to include in the output. + * @property {boolean} [hideObject=false] When `true`, data objects will be + * omitted from the output (except for error objects). + * @property {string} [ignore='hostname'] A comma separated list of log keys + * to omit when outputting the prettified log information. + * @property {undefined|string} [include=undefined] A comma separated list of + * log keys to include in the prettified log information. Only the keys in this + * list will be included in the output. + * @property {boolean} [levelFirst=false] When true, the log level will be the + * first field in the prettified output. + * @property {string} [levelKey='level'] The key name in the log data that + * contains the level value for the log. + * @property {string} [levelLabel='levelLabel'] Token name to use in + * `messageFormat` to represent the name of the logged level. + * @property {null|MessageFormatString|MessageFormatFunction} [messageFormat=null] + * When a string, defines how the prettified line should be formatted according + * to defined tokens. When a function, a synchronous function that returns a + * formatted string. + * @property {string} [messageKey='msg'] Defines the key in incoming logs that + * contains the message of the log, if present. + * @property {undefined|string|number} [minimumLevel=undefined] The minimum + * level for logs that should be processed. Any logs below this level will + * be omitted. + * @property {object} [outputStream=process.stdout] The stream to write + * prettified log lines to. + * @property {boolean} [singleLine=false] When `true` any objects, except error + * objects, in the log data will be printed as a single line instead as multiple + * lines. + * @property {string} [timestampKey='time'] Defines the key in incoming logs + * that contains the timestamp of the log, if present. + * @property {boolean|string} [translateTime=true] When true, will translate a + * JavaScript date integer into a human-readable string. If set to a string, + * it must be a format string. + * @property {boolean} [useOnlyCustomProps=true] When true, only custom levels + * and colors will be used if they have been provided. + */ + +/** + * The default options that will be used when prettifying log lines. + * + * @type {PinoPrettyOptions} + */ const defaultOptions = { colorize: isColorSupported, colorizeObjects: true, crlf: false, + customColors: null, + customLevels: null, + customPrettifiers: {}, errorLikeObjectKeys: ERROR_LIKE_KEYS, errorProps: '', - customLevels: null, - customColors: null, - useOnlyCustomProps: true, + hideObject: false, + ignore: 'hostname', + include: undefined, levelFirst: false, + levelKey: LEVEL_KEY, + levelLabel: LEVEL_LABEL, + messageFormat: null, messageKey: MESSAGE_KEY, - messageFormat: false, + minimumLevel: undefined, + outputStream: process.stdout, + singleLine: false, timestampKey: TIMESTAMP_KEY, translateTime: true, - useMetadata: false, - outputStream: process.stdout, - customPrettifiers: {}, - hideObject: false, - ignore: 'hostname', - include: undefined, - singleLine: false + useOnlyCustomProps: true } +/** + * Processes the supplied options and returns a function that accepts log data + * and produces a prettified log string. + * + * @param {PinoPrettyOptions} options Configuration for the prettifier. + * @returns {LogPrettifierFunc} + */ function prettyFactory (options) { - const opts = Object.assign({}, defaultOptions, options) - const EOL = opts.crlf ? '\r\n' : '\n' - const IDENT = ' ' - const messageKey = opts.messageKey - const levelKey = opts.levelKey - const levelLabel = opts.levelLabel - const minimumLevel = opts.minimumLevel - const messageFormat = opts.messageFormat - const timestampKey = opts.timestampKey - const errorLikeObjectKeys = opts.errorLikeObjectKeys - const errorProps = opts.errorProps.split(',') - const useOnlyCustomProps = typeof opts.useOnlyCustomProps === 'boolean' ? opts.useOnlyCustomProps : opts.useOnlyCustomProps === 'true' - const customLevels = handleCustomlevelsOpts(opts.customLevels) - const customLevelNames = handleCustomlevelNamesOpts(opts.customLevels) - - const customColors = opts.customColors - ? opts.customColors - .split(',') - .reduce((agg, value) => { - const [level, color] = value.split(':') - - const condition = useOnlyCustomProps ? opts.customLevels : customLevelNames[level] !== undefined - const levelNum = condition ? customLevelNames[level] : LEVEL_NAMES[level] - const colorIdx = levelNum !== undefined ? levelNum : level - - agg.push([colorIdx, color]) - - return agg - }, []) - : undefined - const customProps = { - customLevels, - customLevelNames - } - if (useOnlyCustomProps && !opts.customLevels) { - customProps.customLevels = undefined - customProps.customLevelNames = undefined - } - const customPrettifiers = opts.customPrettifiers - const includeKeys = opts.include !== undefined ? new Set(opts.include.split(',')) : undefined - const ignoreKeys = (!includeKeys && opts.ignore) ? new Set(opts.ignore.split(',')) : undefined - const hideObject = opts.hideObject - const singleLine = opts.singleLine - const colorizer = colors(opts.colorize, customColors, useOnlyCustomProps) - const objectColorizer = opts.colorizeObjects ? colorizer : colors(false, [], false) - - return pretty - - function pretty (inputData) { - let log - if (!isObject(inputData)) { - const parsed = jsonParser(inputData) - if (parsed.err || !isObject(parsed.value)) { - // pass through - return inputData + EOL - } - log = parsed.value - } else { - log = inputData - } - - if (minimumLevel) { - const condition = useOnlyCustomProps ? opts.customLevels : customLevelNames[minimumLevel] !== undefined - const minimum = (condition ? customLevelNames[minimumLevel] : LEVEL_NAMES[minimumLevel]) || Number(minimumLevel) - const level = log[levelKey === undefined ? LEVEL_KEY : levelKey] - if (level < minimum) return - } - - const prettifiedMessage = prettifyMessage({ log, messageKey, colorizer, messageFormat, levelLabel, ...customProps, useOnlyCustomProps }) - - if (ignoreKeys || includeKeys) { - log = filterLog({ log, ignoreKeys, includeKeys }) - } - - const prettifiedLevel = prettifyLevel({ log, colorizer, levelKey, prettifier: customPrettifiers.level, ...customProps }) - const prettifiedMetadata = prettifyMetadata({ log, prettifiers: customPrettifiers }) - const prettifiedTime = prettifyTime({ log, translateFormat: opts.translateTime, timestampKey, prettifier: customPrettifiers.time }) - - let line = '' - if (opts.levelFirst && prettifiedLevel) { - line = `${prettifiedLevel}` - } - - if (prettifiedTime && line === '') { - line = `${prettifiedTime}` - } else if (prettifiedTime) { - line = `${line} ${prettifiedTime}` - } - - if (!opts.levelFirst && prettifiedLevel) { - if (line.length > 0) { - line = `${line} ${prettifiedLevel}` - } else { - line = prettifiedLevel - } - } - - if (prettifiedMetadata) { - if (line.length > 0) { - line = `${line} ${prettifiedMetadata}:` - } else { - line = prettifiedMetadata - } - } - - if (line.endsWith(':') === false && line !== '') { - line += ':' - } - - if (prettifiedMessage !== undefined) { - if (line.length > 0) { - line = `${line} ${prettifiedMessage}` - } else { - line = prettifiedMessage - } - } - - if (line.length > 0 && !singleLine) { - line += EOL - } - - // pino@7+ does not log this anymore - if (log.type === 'Error' && log.stack) { - const prettifiedErrorLog = prettifyErrorLog({ - log, - errorLikeKeys: errorLikeObjectKeys, - errorProperties: errorProps, - ident: IDENT, - eol: EOL - }) - if (singleLine) line += EOL - line += prettifiedErrorLog - } else if (!hideObject) { - const skipKeys = [messageKey, levelKey, timestampKey].filter(key => typeof log[key] === 'string' || typeof log[key] === 'number' || typeof log[key] === 'boolean') - const prettifiedObject = prettifyObject({ - input: log, - skipKeys, - customPrettifiers, - errorLikeKeys: errorLikeObjectKeys, - eol: EOL, - ident: IDENT, - singleLine, - colorizer: objectColorizer - }) - - // In single line mode, include a space only if prettified version isn't empty - if (singleLine && !/^\s$/.test(prettifiedObject)) { - line += ' ' - } - line += prettifiedObject - } - - return line - } + const context = parseFactoryOptions(Object.assign({}, defaultOptions, options)) + return pretty.bind({ ...context, context }) } +/** + * @typedef {PinoPrettyOptions} BuildStreamOpts + * @property {object|number|string} [destination] A destination stream, file + * descriptor, or target path to a file. + * @property {boolean} [append] + * @property {boolean} [mkdir] + * @property {boolean} [sync=false] + */ + +/** + * Constructs a {@link LogPrettifierFunc} and a stream to which the produced + * prettified log data will be written. + * + * @param {BuildStreamOpts} opts + * @returns {Transform | (Transform & OnUnknown)} + */ function build (opts = {}) { const pretty = prettyFactory(opts) return abstractTransport(function (source) { diff --git a/lib/colors.js b/lib/colors.js index f6a20b15..5bb38042 100644 --- a/lib/colors.js +++ b/lib/colors.js @@ -94,16 +94,31 @@ function customColoredColorizerFactory (customColors, useOnlyCustomProps) { return customColoredColorizer } +/** + * Applies colorization, if possible, to a string representing the passed in + * `level`. For example, the default colorizer will return a "green" colored + * string for the "info" level. + * + * @typedef {function} ColorizerFunc + * @param {string|number} level In either case, the input will map to a color + * for the specified level or to the color for `USERLVL` if the level is not + * recognized. + * @property {function} message Accepts one string parameter that will be + * colorized to a predefined color. + */ + /** * Factory function get a function to colorized levels. The returned function * also includes a `.message(str)` method to colorize strings. * * @param {boolean} [useColors=false] When `true` a function that applies standard * terminal colors is returned. - * @param {array[]} [customColors] Touple where first item of each array is the level index and the second item is the color - * @param {boolean} [useOnlyCustomProps] When `true`, only use the provided custom colors provided and not fallback to default + * @param {array[]} [customColors] Tuple where first item of each array is the + * level index and the second item is the color + * @param {boolean} [useOnlyCustomProps] When `true`, only use the provided + * custom colors provided and not fallback to default * - * @returns {function} `function (level) {}` has a `.message(str)` method to + * @returns {ColorizerFunc} `function (level) {}` has a `.message(str)` method to * apply colorization to a string. The core function accepts either an integer * `level` or a `string` level. The integer level will map to a known level * string or to `USERLVL` if not known. The string `level` will map to the same diff --git a/test/lib/colors.test.js b/lib/colors.test.js similarity index 85% rename from test/lib/colors.test.js rename to lib/colors.test.js index 2a4d3b12..8bad5a1a 100644 --- a/test/lib/colors.test.js +++ b/lib/colors.test.js @@ -1,8 +1,7 @@ 'use strict' const { test } = require('tap') -const getColorizerPrivate = require('../../lib/colors') -const { colorizerFactory: getColorizerPublic } = require('../../index') +const getColorizer = require('./colors') const testDefaultColorizer = getColorizer => async t => { const colorizer = getColorizer() @@ -122,9 +121,12 @@ const testCustomColoringColorizer = getColorizer => async t => { t.equal(colorized, '\u001B[37mUSERLVL\u001B[39m') } -test('returns default colorizer - private export', testDefaultColorizer(getColorizerPrivate)) -test('returns default colorizer - public export', testDefaultColorizer(getColorizerPublic)) -test('returns colorizing colorizer - private export', testColoringColorizer(getColorizerPrivate)) -test('returns colorizing colorizer - public export', testColoringColorizer(getColorizerPublic)) -test('returns custom colorizing colorizer - private export', testCustomColoringColorizer(getColorizerPrivate)) -test('returns custom colorizing colorizer - public export', testCustomColoringColorizer(getColorizerPublic)) +test('returns default colorizer - private export', testDefaultColorizer(getColorizer)) +test('returns colorizing colorizer - private export', testColoringColorizer(getColorizer)) +test('returns custom colorizing colorizer - private export', testCustomColoringColorizer(getColorizer)) + +test('custom props defaults to standard levels', async t => { + const colorizer = getColorizer(true, [], true) + const colorized = colorizer('info') + t.equal(colorized, '\u001B[37mINFO\u001B[39m') +}) diff --git a/lib/constants.js b/lib/constants.js index 78e0dd18..43221665 100644 --- a/lib/constants.js +++ b/lib/constants.js @@ -1,9 +1,18 @@ 'use strict' +/** + * A set of property names that indicate the value represents an error object. + * + * @typedef {string[]} K_ERROR_LIKE_KEYS + */ + module.exports = { DATE_FORMAT: 'yyyy-mm-dd HH:MM:ss.l o', DATE_FORMAT_SIMPLE: 'HH:MM:ss.l', + /** + * @type {K_ERROR_LIKE_KEYS} + */ ERROR_LIKE_KEYS: ['err', 'error'], MESSAGE_KEY: 'msg', diff --git a/lib/pretty.js b/lib/pretty.js new file mode 100644 index 00000000..ebb43800 --- /dev/null +++ b/lib/pretty.js @@ -0,0 +1,169 @@ +'use strict' + +module.exports = pretty + +const sjs = require('secure-json-parse') + +const isObject = require('./utils/is-object') +const prettifyErrorLog = require('./utils/prettify-error-log') +const prettifyLevel = require('./utils/prettify-level') +const prettifyMessage = require('./utils/prettify-message') +const prettifyMetadata = require('./utils/prettify-metadata') +const prettifyObject = require('./utils/prettify-object') +const prettifyTime = require('./utils/prettify-time') +const filterLog = require('./utils/filter-log') + +const { + LEVELS, + LEVEL_KEY, + LEVEL_NAMES +} = require('./constants') + +const jsonParser = input => { + try { + return { value: sjs.parse(input, { protoAction: 'remove' }) } + } catch (err) { + return { err } + } +} + +/** + * Orchestrates processing the received log data according to the provided + * configuration and returns a prettified log string. + * + * @typedef {function} LogPrettifierFunc + * @param {string|object} inputData A log string or a log-like object. + * @returns {string} A string that represents the prettified log data. + */ +function pretty (inputData) { + let log + if (!isObject(inputData)) { + const parsed = jsonParser(inputData) + if (parsed.err || !isObject(parsed.value)) { + // pass through + return inputData + this.EOL + } + log = parsed.value + } else { + log = inputData + } + + if (this.minimumLevel) { + // We need to figure out if the custom levels has the desired minimum + // level & use that one if found. If not, determine if the level exists + // in the standard levels. In both cases, make sure we have the level + // number instead of the level name. + let condition + if (this.useOnlyCustomProps) { + condition = this.customLevels + } else { + condition = this.customLevelNames[this.minimumLevel] !== undefined + } + let minimum + if (condition) { + minimum = this.customLevelNames[this.minimumLevel] + } else { + minimum = LEVEL_NAMES[this.minimumLevel] + } + if (!minimum) { + minimum = typeof this.minimumLevel === 'string' + ? LEVEL_NAMES[this.minimumLevel] + : LEVEL_NAMES[LEVELS[this.minimumLevel].toLowerCase()] + } + + const level = log[this.levelKey === undefined ? LEVEL_KEY : this.levelKey] + if (level < minimum) return + } + + const prettifiedMessage = prettifyMessage({ log, context: this.context }) + + if (this.ignoreKeys || this.includeKeys) { + log = filterLog({ log, context: this.context }) + } + + const prettifiedLevel = prettifyLevel({ + log, + context: { + ...this.context, + // This is odd. The colorizer ends up relying on the value of + // `customProperties` instead of the original `customLevels` and + // `customLevelNames`. + ...this.context.customProperties + } + }) + const prettifiedMetadata = prettifyMetadata({ log, context: this.context }) + const prettifiedTime = prettifyTime({ log, context: this.context }) + + let line = '' + if (this.levelFirst && prettifiedLevel) { + line = `${prettifiedLevel}` + } + + if (prettifiedTime && line === '') { + line = `${prettifiedTime}` + } else if (prettifiedTime) { + line = `${line} ${prettifiedTime}` + } + + if (!this.levelFirst && prettifiedLevel) { + if (line.length > 0) { + line = `${line} ${prettifiedLevel}` + } else { + line = prettifiedLevel + } + } + + if (prettifiedMetadata) { + if (line.length > 0) { + line = `${line} ${prettifiedMetadata}:` + } else { + line = prettifiedMetadata + } + } + + if (line.endsWith(':') === false && line !== '') { + line += ':' + } + + if (prettifiedMessage !== undefined) { + if (line.length > 0) { + line = `${line} ${prettifiedMessage}` + } else { + line = prettifiedMessage + } + } + + if (line.length > 0 && !this.singleLine) { + line += this.EOL + } + + // pino@7+ does not log this anymore + if (log.type === 'Error' && log.stack) { + const prettifiedErrorLog = prettifyErrorLog({ log, context: this.context }) + if (this.singleLine) line += this.EOL + line += prettifiedErrorLog + } else if (this.hideObject === false) { + const skipKeys = [ + this.messageKey, + this.levelKey, + this.timestampKey + ].filter(key => { + return typeof log[key] === 'string' || + typeof log[key] === 'number' || + typeof log[key] === 'boolean' + }) + const prettifiedObject = prettifyObject({ + log, + skipKeys, + context: this.context + }) + + // In single line mode, include a space only if prettified version isn't empty + if (this.singleLine && !/^\s$/.test(prettifiedObject)) { + line += ' ' + } + line += prettifiedObject + } + + return line +} diff --git a/lib/utils.js b/lib/utils.js deleted file mode 100644 index 9f687f7f..00000000 --- a/lib/utils.js +++ /dev/null @@ -1,770 +0,0 @@ -'use strict' - -const { createCopier } = require('fast-copy') -const dateformat = require('dateformat') -const SonicBoom = require('sonic-boom') -const stringifySafe = require('fast-safe-stringify') -const { isMainThread } = require('worker_threads') -const defaultColorizer = require('./colors')() -const { - DATE_FORMAT, - ERROR_LIKE_KEYS, - MESSAGE_KEY, - LEVEL_KEY, - LEVEL_LABEL, - TIMESTAMP_KEY, - LOGGER_KEYS, - LEVELS, - DATE_FORMAT_SIMPLE -} = require('./constants') - -const fastCopy = createCopier({}) - -module.exports = { - isObject, - prettifyErrorLog, - prettifyLevel, - prettifyMessage, - prettifyMetadata, - prettifyObject, - prettifyTime, - buildSafeSonicBoom, - filterLog, - handleCustomlevelsOpts, - handleCustomlevelNamesOpts -} - -module.exports.internals = { - formatTime, - joinLinesWithIndentation, - prettifyError, - getPropertyValue, - deleteLogProperty, - splitPropertyKey, - createDate, - isValidDate -} - -/** - * Converts a given `epoch` to a desired display format. - * - * @param {number|string} epoch The time to convert. May be any value that is - * valid for `new Date()`. - * @param {boolean|string} [translateTime=false] When `false`, the given `epoch` - * will simply be returned. When `true`, the given `epoch` will be converted - * to a string at UTC using the `DATE_FORMAT` constant. If `translateTime` is - * a string, the following rules are available: - * - * - ``: The string is a literal format string. This format - * string will be used to interpret the `epoch` and return a display string - * at UTC. - * - `SYS:STANDARD`: The returned display string will follow the `DATE_FORMAT` - * constant at the system's local timezone. - * - `SYS:`: The returned display string will follow the given - * `` at the system's local timezone. - * - `UTC:`: The returned display string will follow the given - * `` at UTC. - * - * @returns {number|string} The formatted time. - */ -function formatTime (epoch, translateTime = false) { - if (translateTime === false) { - return epoch - } - - const instant = createDate(epoch) - - // If the Date is invalid, do not attempt to format - if (!isValidDate(instant)) { - return epoch - } - - if (translateTime === true) { - return dateformat(instant, DATE_FORMAT_SIMPLE) - } - - const upperFormat = translateTime.toUpperCase() - if (upperFormat === 'SYS:STANDARD') { - return dateformat(instant, DATE_FORMAT) - } - - const prefix = upperFormat.substr(0, 4) - if (prefix === 'SYS:' || prefix === 'UTC:') { - if (prefix === 'UTC:') { - return dateformat(instant, translateTime) - } - return dateformat(instant, translateTime.slice(4)) - } - - return dateformat(instant, `UTC:${translateTime}`) -} - -/** - * Constructs a JS Date from a number or string. Accepts any single number - * or single string argument that is valid for the Date() constructor, - * or an epoch as a string. - * - * @param {string|number} epoch The representation of the Date. - * - * @returns {Date} The constructed Date. - */ -function createDate (epoch) { - // If epoch is already a valid argument, return the valid Date - let date = new Date(epoch) - if (isValidDate(date)) { - return date - } - - // Convert to a number to permit epoch as a string - date = new Date(+epoch) - return date -} - -/** - * Checks if the argument is a JS Date and not 'Invalid Date'. - * - * @param {Date} date The date to check. - * - * @returns {boolean} true if the argument is a JS Date and not 'Invalid Date'. - */ -function isValidDate (date) { - return date instanceof Date && !Number.isNaN(date.getTime()) -} - -function isObject (input) { - return Object.prototype.toString.apply(input) === '[object Object]' -} - -/** - * Given a string with line separators, either `\r\n` or `\n`, add indentation - * to all lines subsequent to the first line and rejoin the lines using an - * end of line sequence. - * - * @param {object} input - * @param {string} input.input The string to split and reformat. - * @param {string} [input.ident] The indentation string. Default: ` ` (4 spaces). - * @param {string} [input.eol] The end of line sequence to use when rejoining - * the lines. Default: `'\n'`. - * - * @returns {string} A string with lines subsequent to the first indented - * with the given indentation sequence. - */ -function joinLinesWithIndentation ({ input, ident = ' ', eol = '\n' }) { - const lines = input.split(/\r?\n/) - for (let i = 1; i < lines.length; i += 1) { - lines[i] = ident + lines[i] - } - return lines.join(eol) -} - -/** - * Given a log object that has a `type: 'Error'` key, prettify the object and - * return the result. In other - * - * @param {object} input - * @param {object} input.log The error log to prettify. - * @param {string} [input.messageKey] The name of the key that contains a - * general log message. This is not the error's message property but the logger - * messsage property. Default: `MESSAGE_KEY` constant. - * @param {string} [input.ident] The sequence to use for indentation. Default: `' '`. - * @param {string} [input.eol] The sequence to use for EOL. Default: `'\n'`. - * @param {string[]} [input.errorLikeKeys] A set of keys that should be considered - * to have error objects as values. Default: `ERROR_LIKE_KEYS` constant. - * @param {string[]} [input.errorProperties] A set of specific error object - * properties, that are not the value of `messageKey`, `type`, or `stack`, to - * include in the prettified result. The first entry in the list may be `'*'` - * to indicate that all sibiling properties should be prettified. Default: `[]`. - * - * @returns {string} A sring that represents the prettified error log. - */ -function prettifyErrorLog ({ - log, - messageKey = MESSAGE_KEY, - ident = ' ', - eol = '\n', - errorLikeKeys = ERROR_LIKE_KEYS, - errorProperties = [] -}) { - const stack = log.stack - const joinedLines = joinLinesWithIndentation({ input: stack, ident, eol }) - let result = `${ident}${joinedLines}${eol}` - - if (errorProperties.length > 0) { - const excludeProperties = LOGGER_KEYS.concat(messageKey, 'type', 'stack') - let propertiesToPrint - if (errorProperties[0] === '*') { - // Print all sibling properties except for the standard exclusions. - propertiesToPrint = Object.keys(log).filter(k => excludeProperties.includes(k) === false) - } else { - // Print only specified properties unless the property is a standard exclusion. - propertiesToPrint = errorProperties.filter(k => excludeProperties.includes(k) === false) - } - - for (let i = 0; i < propertiesToPrint.length; i += 1) { - const key = propertiesToPrint[i] - if (key in log === false) continue - if (isObject(log[key])) { - // The nested object may have "logger" type keys but since they are not - // at the root level of the object being processed, we want to print them. - // Thus, we invoke with `excludeLoggerKeys: false`. - const prettifiedObject = prettifyObject({ input: log[key], errorLikeKeys, excludeLoggerKeys: false, eol, ident: ident + ident }) - result = `${result}${ident}${key}: {${eol}${prettifiedObject}${ident}}${eol}` - continue - } - result = `${result}${ident}${key}: ${log[key]}${eol}` - } - } - - return result -} - -/** - * Checks if the passed in log has a `level` value and returns a prettified - * string for that level if so. - * - * @param {object} input - * @param {object} input.log The log object. - * @param {function} [input.colorizer] A colorizer function that accepts a level - * value and returns a colorized string. Default: a no-op colorizer. - * @param {string} [input.levelKey='level'] The key to find the level under. - * @param {function} [input.prettifier] A user-supplied formatter to be called instead of colorizer. - * @param {object} [input.customLevels] The custom levels where key as the level index and value as the level name. - * @param {object} [input.customLevelNames] The custom level names where key is the level name and value is the level index. - * - * @returns {undefined|string} If `log` does not have a `level` property then - * `undefined` will be returned. Otherwise, a string from the specified - * `colorizer` is returned. - */ -function prettifyLevel ({ log, colorizer = defaultColorizer, levelKey = LEVEL_KEY, prettifier, customLevels, customLevelNames }) { - const output = getPropertyValue(log, levelKey) - if (output === undefined) return undefined - return prettifier ? prettifier(output) : colorizer(output, { customLevels, customLevelNames }) -} - -/** - * Prettifies a message string if the given `log` has a message property. - * - * @param {object} input - * @param {object} input.log The log object with the message to colorize. - * @param {string} [input.messageKey='msg'] The property of the `log` that is the - * message to be prettified. - * @param {string|function} [input.messageFormat=undefined] A format string or function that defines how the - * logged message should be formatted, e.g. `'{level} - {pid}'`. - * @param {function} [input.colorizer] A colorizer function that has a - * `.message(str)` method attached to it. This function should return a colorized - * string which will be the "prettified" message. Default: a no-op colorizer. - * @param {string} [input.levelLabel='levelLabel'] The label used to output the log level - * @param {string} [input.levelKey='level'] The key to find the level under. - * @param {object} [input.customLevels] The custom levels where key as the level index and value as the level name. - * - * @returns {undefined|string} If the message key is not found, or the message - * key is not a string, then `undefined` will be returned. Otherwise, a string - * that is the prettified message. - */ -function prettifyMessage ({ log, messageFormat, messageKey = MESSAGE_KEY, colorizer = defaultColorizer, levelLabel = LEVEL_LABEL, levelKey = LEVEL_KEY, customLevels, useOnlyCustomProps }) { - if (messageFormat && typeof messageFormat === 'string') { - const message = String(messageFormat).replace(/{([^{}]+)}/g, function (match, p1) { - // return log level as string instead of int - let level - if (p1 === levelLabel && (level = getPropertyValue(log, levelKey)) !== undefined) { - const condition = useOnlyCustomProps ? customLevels === undefined : customLevels[level] === undefined - return condition ? LEVELS[level] : customLevels[level] - } - // Parse nested key access, e.g. `{keyA.subKeyB}`. - return getPropertyValue(log, p1) || '' - }) - return colorizer.message(message) - } - if (messageFormat && typeof messageFormat === 'function') { - const msg = messageFormat(log, messageKey, levelLabel) - return colorizer.message(msg) - } - if (messageKey in log === false) return undefined - if (typeof log[messageKey] !== 'string' && typeof log[messageKey] !== 'number' && typeof log[messageKey] !== 'boolean') return undefined - return colorizer.message(log[messageKey]) -} - -/** - * Prettifies metadata that is usually present in a Pino log line. It looks for - * fields `name`, `pid`, `hostname`, and `caller` and returns a formatted string using - * the fields it finds. - * - * @param {object} input - * @param {object} input.log The log that may or may not contain metadata to - * be prettified. - * @param {object} input.prettifiers A set of functions used to prettify each - * key of the input log's metadata. The keys are the keys of the metadata (like - * `hostname`, `pid`, `name`, etc), and the values are functions which take the - * metadata value and return a string. Each key is optional. - * - * @returns {undefined|string} If no metadata is found then `undefined` is - * returned. Otherwise, a string of prettified metadata is returned. - */ -function prettifyMetadata ({ log, prettifiers = {} }) { - let line = '' - - if (log.name || log.pid || log.hostname) { - line += '(' - - if (log.name) { - line += prettifiers.name ? prettifiers.name(log.name) : log.name - } - - if (log.pid) { - const prettyPid = prettifiers.pid ? prettifiers.pid(log.pid) : log.pid - if (log.name && log.pid) { - line += '/' + prettyPid - } else { - line += prettyPid - } - } - - if (log.hostname) { - // If `pid` and `name` were in the ignore keys list then we don't need - // the leading space. - line += `${line === '(' ? 'on' : ' on'} ${prettifiers.hostname ? prettifiers.hostname(log.hostname) : log.hostname}` - } - - line += ')' - } - - if (log.caller) { - line += `${line === '' ? '' : ' '}<${prettifiers.caller ? prettifiers.caller(log.caller) : log.caller}>` - } - - if (line === '') { - return undefined - } else { - return line - } -} - -/** - * Prettifies a standard object. Special care is taken when processing the object - * to handle child objects that are attached to keys known to contain error - * objects. - * - * @param {object} input - * @param {object} input.input The object to prettify. - * @param {string} [input.ident] The identation sequence to use. Default: `' '`. - * @param {string} [input.eol] The EOL sequence to use. Default: `'\n'`. - * @param {string[]} [input.skipKeys] A set of object keys to exclude from the - * prettified result. Default: `[]`. - * @param {Object} [input.customPrettifiers] Dictionary of - * custom prettifiers. Default: `{}`. - * @param {string[]} [input.errorLikeKeys] A set of object keys that contain - * error objects. Default: `ERROR_LIKE_KEYS` constant. - * @param {boolean} [input.excludeLoggerKeys] Indicates if known logger specific - * keys should be excluded from prettification. Default: `true`. - * @param {boolean} [input.singleLine] Should non-error keys all be formatted - * on a single line? This does NOT apply to errors, which will still be - * multi-line. Default: `false` - * - * @returns {string} The prettified string. This can be as little as `''` if - * there was nothing to prettify. - */ -function prettifyObject ({ - input, - ident = ' ', - eol = '\n', - skipKeys = [], - customPrettifiers = {}, - errorLikeKeys = ERROR_LIKE_KEYS, - excludeLoggerKeys = true, - singleLine = false, - colorizer = defaultColorizer -}) { - const keysToIgnore = [].concat(skipKeys) - - if (excludeLoggerKeys === true) Array.prototype.push.apply(keysToIgnore, LOGGER_KEYS) - - let result = '' - - // Split object keys into two categories: error and non-error - const { plain, errors } = Object.entries(input).reduce(({ plain, errors }, [k, v]) => { - if (keysToIgnore.includes(k) === false) { - // Pre-apply custom prettifiers, because all 3 cases below will need this - const pretty = typeof customPrettifiers[k] === 'function' - ? customPrettifiers[k](v, k, input) - : v - if (errorLikeKeys.includes(k)) { - errors[k] = pretty - } else { - plain[k] = pretty - } - } - return { plain, errors } - }, { plain: {}, errors: {} }) - - if (singleLine) { - // Stringify the entire object as a single JSON line - if (Object.keys(plain).length > 0) { - result += colorizer.greyMessage(stringifySafe(plain)) - } - result += eol - // Avoid printing the escape character on escaped backslashes. - result = result.replace(/\\\\/gi, '\\') - } else { - // Put each object entry on its own line - Object.entries(plain).forEach(([keyName, keyValue]) => { - // custom prettifiers are already applied above, so we can skip it now - let lines = typeof customPrettifiers[keyName] === 'function' - ? keyValue - : stringifySafe(keyValue, null, 2) - - if (lines === undefined) return - - // Avoid printing the escape character on escaped backslashes. - lines = lines.replace(/\\\\/gi, '\\') - - const joinedLines = joinLinesWithIndentation({ input: lines, ident, eol }) - result += `${ident}${keyName}:${joinedLines.startsWith(eol) ? '' : ' '}${joinedLines}${eol}` - }) - } - - // Errors - Object.entries(errors).forEach(([keyName, keyValue]) => { - // custom prettifiers are already applied above, so we can skip it now - const lines = typeof customPrettifiers[keyName] === 'function' - ? keyValue - : stringifySafe(keyValue, null, 2) - - if (lines === undefined) return - - result += prettifyError({ keyName, lines, eol, ident }) - }) - - return result -} - -/** - * Prettifies a timestamp if the given `log` has either `time`, `timestamp` or custom specified timestamp - * property. - * - * @param {object} input - * @param {object} input.log The log object with the timestamp to be prettified. - * @param {string} [input.timestampKey='time'] The log property that should be used to resolve timestamp value - * @param {boolean|string} [input.translateFormat=undefined] When `true` the - * timestamp will be prettified into a string at UTC using the default - * `DATE_FORMAT`. If a string, then `translateFormat` will be used as the format - * string to determine the output; see the `formatTime` function for details. - * @param {function} [input.prettifier] A user-supplied formatter for altering output. - * - * @returns {undefined|string} If a timestamp property cannot be found then - * `undefined` is returned. Otherwise, the prettified time is returned as a - * string. - */ -function prettifyTime ({ log, timestampKey = TIMESTAMP_KEY, translateFormat = undefined, prettifier }) { - let time = null - - if (timestampKey in log) { - time = log[timestampKey] - } else if ('timestamp' in log) { - time = log.timestamp - } - - if (time === null) return undefined - const output = translateFormat ? formatTime(time, translateFormat) : time - - return prettifier ? prettifier(output) : `[${output}]` -} - -/** - * Prettifies an error string into a multi-line format. - * @param {object} input - * @param {string} input.keyName The key assigned to this error in the log object - * @param {string} input.lines The STRINGIFIED error. If the error field has a - * custom prettifier, that should be pre-applied as well - * @param {string} input.ident The indentation sequence to use - * @param {string} input.eol The EOL sequence to use - */ -function prettifyError ({ keyName, lines, eol, ident }) { - let result = '' - const joinedLines = joinLinesWithIndentation({ input: lines, ident, eol }) - const splitLines = `${ident}${keyName}: ${joinedLines}${eol}`.split(eol) - - for (let j = 0; j < splitLines.length; j += 1) { - if (j !== 0) result += eol - - const line = splitLines[j] - if (/^\s*"stack"/.test(line)) { - const matches = /^(\s*"stack":)\s*(".*"),?$/.exec(line) - /* istanbul ignore else */ - if (matches && matches.length === 3) { - const indentSize = /^\s*/.exec(line)[0].length + 4 - const indentation = ' '.repeat(indentSize) - const stackMessage = matches[2] - result += matches[1] + eol + indentation + JSON.parse(stackMessage).replace(/\n/g, eol + indentation) - } else { - result += line - } - } else { - result += line - } - } - - return result -} - -/** - * Splits the property key delimited by a dot character but not when it is preceded - * by a backslash. - * - * @param {string} key A string identifying the property. - * - * @returns {string[]} Returns a list of string containing each delimited property. - * e.g. `'prop2\.domain\.corp.prop2'` should return [ 'prop2.domain.com', 'prop2' ] - */ -function splitPropertyKey (key) { - const result = [] - let backslash = false - let segment = '' - - for (let i = 0; i < key.length; i++) { - const c = key.charAt(i) - - if (c === '\\') { - backslash = true - continue - } - - if (backslash) { - backslash = false - segment += c - continue - } - - /* Non-escaped dot, push to result */ - if (c === '.') { - result.push(segment) - segment = '' - continue - } - - segment += c - } - - /* Push last entry to result */ - if (segment.length) { - result.push(segment) - } - - return result -} - -/** - * Gets a specified property from an object if it exists. - * - * @param {object} obj The object to be searched. - * @param {string|string[]} property A string, or an array of strings, identifying - * the property to be retrieved from the object. - * Accepts nested properties delimited by a `.`. - * Delimiter can be escaped to preserve property names that contain the delimiter. - * e.g. `'prop1.prop2'` or `'prop2\.domain\.corp.prop2'`. - * - * @returns {*} - */ -function getPropertyValue (obj, property) { - const props = Array.isArray(property) ? property : splitPropertyKey(property) - - for (const prop of props) { - if (!Object.prototype.hasOwnProperty.call(obj, prop)) { - return - } - obj = obj[prop] - } - - return obj -} - -/** - * Deletes a specified property from a log object if it exists. - * This function mutates the passed in `log` object. - * - * @param {object} log The log object to be modified. - * @param {string} property A string identifying the property to be deleted from - * the log object. Accepts nested properties delimited by a `.` - * Delimiter can be escaped to preserve property names that contain the delimiter. - * e.g. `'prop1.prop2'` or `'prop2\.domain\.corp.prop2'` - */ -function deleteLogProperty (log, property) { - const props = splitPropertyKey(property) - const propToDelete = props.pop() - - log = getPropertyValue(log, props) - - if (log !== null && typeof log === 'object' && Object.prototype.hasOwnProperty.call(log, propToDelete)) { - delete log[propToDelete] - } -} - -/** - * Filter a log object by removing or including keys accordingly. - * When `includeKeys` is passed, `ignoredKeys` will be ignored. - * One of ignoreKeys or includeKeys must be pass in. - * - * @param {object} input - * @param {object} input.log The log object to be modified. - * @param {Set | Array | undefined} input.ignoreKeys - * An array of strings identifying the properties to be removed. - * @param {Set | Array | undefined} input.includeKeys - * An array of strings identifying the properties to be included. - * - * @returns {object} A new `log` object instance that - * either only includes the keys in ignoreKeys - * or does not include those in ignoredKeys. - */ -function filterLog ({ log, ignoreKeys, includeKeys }) { - const logCopy = fastCopy(log) - - if (includeKeys) { - const logIncluded = {} - - includeKeys.forEach((key) => { - logIncluded[key] = logCopy[key] - }) - return logIncluded - } - - ignoreKeys.forEach((ignoreKey) => { - deleteLogProperty(logCopy, ignoreKey) - }) - return logCopy -} - -function noop () {} - -/** - * Creates a safe SonicBoom instance - * - * @param {object} opts Options for SonicBoom - * - * @returns {object} A new SonicBoom stream - */ -function buildSafeSonicBoom (opts) { - const stream = new SonicBoom(opts) - stream.on('error', filterBrokenPipe) - // if we are sync: false, we must flush on exit - // NODE_V8_COVERAGE must breaks everything - // https://github.com/nodejs/node/issues/49344 - if (!process.env.NODE_V8_COVERAGE && !opts.sync && isMainThread) { - setupOnExit(stream) - } - return stream - - function filterBrokenPipe (err) { - if (err.code === 'EPIPE') { - stream.write = noop - stream.end = noop - stream.flushSync = noop - stream.destroy = noop - return - } - stream.removeListener('error', filterBrokenPipe) - } -} - -function setupOnExit (stream) { - /* istanbul ignore next */ - if (global.WeakRef && global.WeakMap && global.FinalizationRegistry) { - // This is leak free, it does not leave event handlers - const onExit = require('on-exit-leak-free') - - onExit.register(stream, autoEnd) - - stream.on('close', function () { - onExit.unregister(stream) - }) - } -} - -/* istanbul ignore next */ -function autoEnd (stream, eventName) { - // This check is needed only on some platforms - - if (stream.destroyed) { - return - } - - if (eventName === 'beforeExit') { - // We still have an event loop, let's use it - stream.flush() - stream.on('drain', function () { - stream.end() - }) - } else { - // We do not have an event loop, so flush synchronously - stream.flushSync() - } -} - -/** - * Parse a CSV string or options object that specifies - * configuration for custom levels. - * - * @param {string|object} cLevels An object mapping level - * names to values, e.g. `{ info: 30, debug: 65 }`, or a - * CSV string in the format `level_name:level_value`, e.g. - * `info:30,debug:65`. - * - * @returns {object} An object mapping levels to labels that - * appear in logs, e.g. `{ '30': 'INFO', '65': 'DEBUG' }`. - */ -function handleCustomlevelsOpts (cLevels) { - if (!cLevels) return {} - - if (typeof cLevels === 'string') { - return cLevels - .split(',') - .reduce((agg, value, idx) => { - const [levelName, levelIdx = idx] = value.split(':') - agg[levelIdx] = levelName.toUpperCase() - return agg - }, - { default: 'USERLVL' }) - } else if (Object.prototype.toString.call(cLevels) === '[object Object]') { - return Object - .keys(cLevels) - .reduce((agg, levelName, idx) => { - agg[cLevels[levelName]] = levelName.toUpperCase() - return agg - }, { default: 'USERLVL' }) - } else { - return {} - } -} - -/** - * Parse a CSV string or options object that maps level - * labels to level values. - * - * @param {string|object} cLevels An object mapping level - * names to level values, e.g. `{ info: 30, debug: 65 }`, or a - * CSV string in the format `level_name:level_value`, e.g. - * `info:30,debug:65`. - * - * @returns {object} An object mapping levels names to level values - * e.g. `{ info: 30, debug: 65 }`. - */ -function handleCustomlevelNamesOpts (cLevels) { - if (!cLevels) return {} - - if (typeof cLevels === 'string') { - return cLevels - .split(',') - .reduce((agg, value, idx) => { - const [levelName, levelIdx = idx] = value.split(':') - agg[levelName.toLowerCase()] = levelIdx - return agg - }, {}) - } else if (Object.prototype.toString.call(cLevels) === '[object Object]') { - return Object - .keys(cLevels) - .reduce((agg, levelName, idx) => { - agg[levelName.toLowerCase()] = cLevels[levelName] - return agg - }, {}) - } else { - return {} - } -} diff --git a/lib/utils/build-safe-sonic-boom.js b/lib/utils/build-safe-sonic-boom.js new file mode 100644 index 00000000..fadfe290 --- /dev/null +++ b/lib/utils/build-safe-sonic-boom.js @@ -0,0 +1,74 @@ +'use strict' + +module.exports = buildSafeSonicBoom + +const { isMainThread } = require('worker_threads') +const SonicBoom = require('sonic-boom') +const noop = require('./noop') + +/** + * Creates a safe SonicBoom instance + * + * @param {object} opts Options for SonicBoom + * + * @returns {object} A new SonicBoom stream + */ +function buildSafeSonicBoom (opts) { + const stream = new SonicBoom(opts) + stream.on('error', filterBrokenPipe) + // if we are sync: false, we must flush on exit + // NODE_V8_COVERAGE must breaks everything + // https://github.com/nodejs/node/issues/49344 + if (!process.env.NODE_V8_COVERAGE && !opts.sync && isMainThread) { + setupOnExit(stream) + } + if (!opts.sync && isMainThread) { + setupOnExit(stream) + } + return stream + + function filterBrokenPipe (err) { + if (err.code === 'EPIPE') { + stream.write = noop + stream.end = noop + stream.flushSync = noop + stream.destroy = noop + return + } + stream.removeListener('error', filterBrokenPipe) + } +} + +function setupOnExit (stream) { + /* istanbul ignore next */ + if (global.WeakRef && global.WeakMap && global.FinalizationRegistry) { + // This is leak free, it does not leave event handlers + const onExit = require('on-exit-leak-free') + + onExit.register(stream, autoEnd) + + stream.on('close', function () { + onExit.unregister(stream) + }) + } +} + +/* istanbul ignore next */ +function autoEnd (stream, eventName) { + // This check is needed only on some platforms + + if (stream.destroyed) { + return + } + + if (eventName === 'beforeExit') { + // We still have an event loop, let's use it + stream.flush() + stream.on('drain', function () { + stream.end() + }) + } else { + // We do not have an event loop, so flush synchronously + stream.flushSync() + } +} diff --git a/lib/utils/build-safe-sonic-boom.test.js b/lib/utils/build-safe-sonic-boom.test.js new file mode 100644 index 00000000..235393af --- /dev/null +++ b/lib/utils/build-safe-sonic-boom.test.js @@ -0,0 +1,86 @@ +'use strict' + +const tap = require('tap') +const rimraf = require('rimraf') +const fs = require('fs') +const { join } = require('path') + +const buildSafeSonicBoom = require('./build-safe-sonic-boom') + +function noop () {} + +const file = () => { + const dest = join(__dirname, `${process.pid}-${process.hrtime().toString()}`) + const fd = fs.openSync(dest, 'w') + return { dest, fd } +} + +tap.test('should not write when error emitted and code is "EPIPE"', async t => { + t.plan(1) + + const { fd, dest } = file() + const stream = buildSafeSonicBoom({ sync: true, fd, mkdir: true }) + t.teardown(() => rimraf(dest, noop)) + + stream.emit('error', { code: 'EPIPE' }) + stream.write('will not work') + + const dataFile = fs.readFileSync(dest) + t.equal(dataFile.length, 0) +}) + +tap.test('should stream.write works when error code is not "EPIPE"', async t => { + t.plan(3) + const { fd, dest } = file() + const stream = buildSafeSonicBoom({ sync: true, fd, mkdir: true }) + + t.teardown(() => rimraf(dest, noop)) + + stream.on('error', () => t.pass('error emitted')) + + stream.emit('error', 'fake error description') + + t.ok(stream.write('will work')) + + const dataFile = fs.readFileSync(dest) + t.equal(dataFile.toString(), 'will work') +}) + +tap.test('cover setupOnExit', async t => { + t.plan(3) + const { fd, dest } = file() + const stream = buildSafeSonicBoom({ sync: false, fd, mkdir: true }) + + t.teardown(() => rimraf(dest, noop)) + + stream.on('error', () => t.pass('error emitted')) + stream.emit('error', 'fake error description') + + t.ok(stream.write('will work')) + + await watchFileCreated(dest) + + const dataFile = fs.readFileSync(dest) + t.equal(dataFile.toString(), 'will work') +}) + +function watchFileCreated (filename) { + return new Promise((resolve, reject) => { + const TIMEOUT = 2000 + const INTERVAL = 100 + const threshold = TIMEOUT / INTERVAL + let counter = 0 + const interval = setInterval(() => { + // On some CI runs file is created but not filled + if (fs.existsSync(filename) && fs.statSync(filename).size !== 0) { + clearInterval(interval) + resolve() + } else if (counter <= threshold) { + counter++ + } else { + clearInterval(interval) + reject(new Error(`${filename} was not created.`)) + } + }, INTERVAL) + }) +} diff --git a/lib/utils/create-date.js b/lib/utils/create-date.js new file mode 100644 index 00000000..dc849916 --- /dev/null +++ b/lib/utils/create-date.js @@ -0,0 +1,26 @@ +'use strict' + +module.exports = createDate + +const isValidDate = require('./is-valid-date') + +/** + * Constructs a JS Date from a number or string. Accepts any single number + * or single string argument that is valid for the Date() constructor, + * or an epoch as a string. + * + * @param {string|number} epoch The representation of the Date. + * + * @returns {Date} The constructed Date. + */ +function createDate (epoch) { + // If epoch is already a valid argument, return the valid Date + let date = new Date(epoch) + if (isValidDate(date)) { + return date + } + + // Convert to a number to permit epoch as a string + date = new Date(+epoch) + return date +} diff --git a/lib/utils/create-date.test.js b/lib/utils/create-date.test.js new file mode 100644 index 00000000..8ab36da2 --- /dev/null +++ b/lib/utils/create-date.test.js @@ -0,0 +1,20 @@ +'use strict' + +const tap = require('tap') +const createDate = require('./create-date') + +const wanted = 1624450038567 + +tap.test('accepts arguments the Date constructor would accept', async t => { + t.plan(2) + t.same(createDate(1624450038567).getTime(), wanted) + t.same(createDate('2021-06-23T12:07:18.567Z').getTime(), wanted) +}) + +tap.test('accepts epoch as a string', async t => { + // If Date() accepts this argument, the createDate function is not needed + // and can be replaced with Date() + t.plan(2) + t.notSame(new Date('16244500385-67').getTime(), wanted) + t.same(createDate('1624450038567').getTime(), wanted) +}) diff --git a/lib/utils/delete-log-property.js b/lib/utils/delete-log-property.js new file mode 100644 index 00000000..502fcee4 --- /dev/null +++ b/lib/utils/delete-log-property.js @@ -0,0 +1,28 @@ +'use strict' + +module.exports = deleteLogProperty + +const getPropertyValue = require('./get-property-value') +const splitPropertyKey = require('./split-property-key') + +/** + * Deletes a specified property from a log object if it exists. + * This function mutates the passed in `log` object. + * + * @param {object} log The log object to be modified. + * @param {string} property A string identifying the property to be deleted from + * the log object. Accepts nested properties delimited by a `.` + * Delimiter can be escaped to preserve property names that contain the delimiter. + * e.g. `'prop1.prop2'` or `'prop2\.domain\.corp.prop2'` + */ +function deleteLogProperty (log, property) { + const props = splitPropertyKey(property) + const propToDelete = props.pop() + + log = getPropertyValue(log, props) + + /* istanbul ignore else */ + if (log !== null && typeof log === 'object' && Object.prototype.hasOwnProperty.call(log, propToDelete)) { + delete log[propToDelete] + } +} diff --git a/lib/utils/delete-log-property.test.js b/lib/utils/delete-log-property.test.js new file mode 100644 index 00000000..580eb918 --- /dev/null +++ b/lib/utils/delete-log-property.test.js @@ -0,0 +1,31 @@ +'use strict' + +const tap = require('tap') +const { createCopier } = require('fast-copy') +const fastCopy = createCopier({}) +const deleteLogProperty = require('./delete-log-property') + +const logData = { + level: 30, + data1: { + data2: { 'data-3': 'bar' } + } +} + +tap.test('deleteLogProperty deletes property of depth 1', async t => { + const log = fastCopy(logData) + deleteLogProperty(log, 'data1') + t.same(log, { level: 30 }) +}) + +tap.test('deleteLogProperty deletes property of depth 2', async t => { + const log = fastCopy(logData) + deleteLogProperty(log, 'data1.data2') + t.same(log, { level: 30, data1: { } }) +}) + +tap.test('deleteLogProperty deletes property of depth 3', async t => { + const log = fastCopy(logData) + deleteLogProperty(log, 'data1.data2.data-3') + t.same(log, { level: 30, data1: { data2: { } } }) +}) diff --git a/lib/utils/filter-log.js b/lib/utils/filter-log.js new file mode 100644 index 00000000..66c1b354 --- /dev/null +++ b/lib/utils/filter-log.js @@ -0,0 +1,45 @@ +'use strict' + +module.exports = filterLog + +const { createCopier } = require('fast-copy') +const fastCopy = createCopier({}) + +const deleteLogProperty = require('./delete-log-property') + +/** + * @typedef {object} FilterLogParams + * @property {object} log The log object to be modified. + * @property {PrettyContext} context The context object built from parsing + * the options. + */ + +/** + * Filter a log object by removing or including keys accordingly. + * When `includeKeys` is passed, `ignoredKeys` will be ignored. + * One of ignoreKeys or includeKeys must be pass in. + * + * @param {FilterLogParams} input + * + * @returns {object} A new `log` object instance that + * either only includes the keys in ignoreKeys + * or does not include those in ignoredKeys. + */ +function filterLog ({ log, context }) { + const { ignoreKeys, includeKeys } = context + const logCopy = fastCopy(log) + + if (includeKeys) { + const logIncluded = {} + + includeKeys.forEach((key) => { + logIncluded[key] = logCopy[key] + }) + return logIncluded + } + + ignoreKeys.forEach((ignoreKey) => { + deleteLogProperty(logCopy, ignoreKey) + }) + return logCopy +} diff --git a/lib/utils/filter-log.test.js b/lib/utils/filter-log.test.js new file mode 100644 index 00000000..2099661a --- /dev/null +++ b/lib/utils/filter-log.test.js @@ -0,0 +1,190 @@ +'use strict' + +const tap = require('tap') +const filterLog = require('./filter-log') + +const context = { + includeKeys: undefined, + ignoreKeys: undefined +} +const logData = { + level: 30, + time: 1522431328992, + data1: { + data2: { 'data-3': 'bar' }, + error: new Error('test') + } +} +const logData2 = Object.assign({ + 'logging.domain.corp/operation': { + id: 'foo', + producer: 'bar' + } +}, logData) + +tap.test('#filterLog with an ignoreKeys option', t => { + t.test('filterLog removes single entry', async t => { + const result = filterLog({ + log: logData, + context: { + ...context, + ignoreKeys: ['data1.data2.data-3'] + } + }) + t.same(result, { level: 30, time: 1522431328992, data1: { data2: { }, error: new Error('test') } }) + }) + + t.test('filterLog removes multiple entries', async t => { + const result = filterLog({ + log: logData, + context: { + ...context, + ignoreKeys: ['time', 'data1'] + } + }) + t.same(result, { level: 30 }) + }) + + t.test('filterLog keeps error instance', async t => { + const result = filterLog({ + log: logData, + context: { + ...context, + ignoreKeys: [] + } + }) + t.equal(logData.data1.error, result.data1.error) + }) + + t.test('filterLog removes entry with escape sequence', async t => { + const result = filterLog({ + log: logData2, + context: { + ...context, + ignoreKeys: ['data1', 'logging\\.domain\\.corp/operation'] + } + }) + t.same(result, { level: 30, time: 1522431328992 }) + }) + + t.test('filterLog removes entry with escape sequence nested', async t => { + const result = filterLog({ + log: logData2, + context: { + ...context, + ignoreKeys: ['data1', 'logging\\.domain\\.corp/operation.producer'] + } + }) + t.same(result, { level: 30, time: 1522431328992, 'logging.domain.corp/operation': { id: 'foo' } }) + }) + + t.end() +}) + +const ignoreKeysArray = [ + undefined, + ['level'], + ['level', 'data1.data2.data-3'] +] +ignoreKeysArray.forEach(ignoreKeys => { + tap.test(`#filterLog with an includeKeys option when the ignoreKeys being ${ignoreKeys}`, t => { + t.test('filterLog include nothing', async t => { + const result = filterLog({ + log: logData, + context: { + ...context, + ignoreKeys, + includeKeys: [] + } + }) + t.same(result, {}) + }) + + t.test('filterLog include single entry', async t => { + const result = filterLog({ + log: logData, + context: { + ...context, + ignoreKeys, + includeKeys: ['time'] + } + }) + t.same(result, { time: 1522431328992 }) + }) + + t.test('filterLog include multiple entries', async t => { + const result = filterLog({ + log: logData, + context: { + ...context, + ignoreKeys, + includeKeys: ['time', 'data1'] + } + }) + t.same(result, { + time: 1522431328992, + data1: { + data2: { 'data-3': 'bar' }, + error: new Error('test') + } + }) + }) + + t.end() + }) +}) + +tap.test('#filterLog with circular references', t => { + const logData = { + level: 30, + time: 1522431328992, + data1: 'test' + } + logData.circular = logData + + t.test('filterLog removes single entry', async t => { + const result = filterLog({ + log: logData, + context: { + ...context, + ignoreKeys: ['data1'] + } + }) + + t.same(result.circular.level, result.level) + t.same(result.circular.time, result.time) + + delete result.circular + t.same(result, { level: 30, time: 1522431328992 }) + }) + + t.test('filterLog includes single entry', async t => { + const result = filterLog({ + log: logData, + context: { + ...context, + includeKeys: ['data1'] + } + }) + + t.same(result, { data1: 'test' }) + }) + + t.test('filterLog includes circular keys', async t => { + const result = filterLog({ + log: logData, + context: { + ...context, + includeKeys: ['level', 'circular'] + } + }) + + t.same(result.circular.level, logData.level) + t.same(result.circular.time, logData.time) + + delete result.circular + t.same(result, { level: 30 }) + }) + + t.end() +}) diff --git a/lib/utils/format-time.js b/lib/utils/format-time.js new file mode 100644 index 00000000..0e147382 --- /dev/null +++ b/lib/utils/format-time.js @@ -0,0 +1,66 @@ +'use strict' + +module.exports = formatTime + +const { + DATE_FORMAT, + DATE_FORMAT_SIMPLE +} = require('../constants') + +const dateformat = require('dateformat') +const createDate = require('./create-date') +const isValidDate = require('./is-valid-date') + +/** + * Converts a given `epoch` to a desired display format. + * + * @param {number|string} epoch The time to convert. May be any value that is + * valid for `new Date()`. + * @param {boolean|string} [translateTime=false] When `false`, the given `epoch` + * will simply be returned. When `true`, the given `epoch` will be converted + * to a string at UTC using the `DATE_FORMAT` constant. If `translateTime` is + * a string, the following rules are available: + * + * - ``: The string is a literal format string. This format + * string will be used to interpret the `epoch` and return a display string + * at UTC. + * - `SYS:STANDARD`: The returned display string will follow the `DATE_FORMAT` + * constant at the system's local timezone. + * - `SYS:`: The returned display string will follow the given + * `` at the system's local timezone. + * - `UTC:`: The returned display string will follow the given + * `` at UTC. + * + * @returns {number|string} The formatted time. + */ +function formatTime (epoch, translateTime = false) { + if (translateTime === false) { + return epoch + } + + const instant = createDate(epoch) + + // If the Date is invalid, do not attempt to format + if (!isValidDate(instant)) { + return epoch + } + + if (translateTime === true) { + return dateformat(instant, DATE_FORMAT_SIMPLE) + } + + const upperFormat = translateTime.toUpperCase() + if (upperFormat === 'SYS:STANDARD') { + return dateformat(instant, DATE_FORMAT) + } + + const prefix = upperFormat.substr(0, 4) + if (prefix === 'SYS:' || prefix === 'UTC:') { + if (prefix === 'UTC:') { + return dateformat(instant, translateTime) + } + return dateformat(instant, translateTime.slice(4)) + } + + return dateformat(instant, `UTC:${translateTime}`) +} diff --git a/lib/utils/format-time.test.js b/lib/utils/format-time.test.js new file mode 100644 index 00000000..be7399a9 --- /dev/null +++ b/lib/utils/format-time.test.js @@ -0,0 +1,71 @@ +'use strict' + +process.env.TZ = 'UTC' + +const tap = require('tap') +const formatTime = require('./format-time') + +const dateStr = '2019-04-06T13:30:00.000-04:00' +const epoch = new Date(dateStr) +const epochMS = epoch.getTime() + +tap.test('passes through epoch if `translateTime` is `false`', async t => { + const formattedTime = formatTime(epochMS) + t.equal(formattedTime, epochMS) +}) + +tap.test('passes through epoch if date is invalid', async t => { + const input = 'this is not a date' + const formattedTime = formatTime(input, true) + t.equal(formattedTime, input) +}) + +tap.test('translates epoch milliseconds if `translateTime` is `true`', async t => { + const formattedTime = formatTime(epochMS, true) + t.equal(formattedTime, '17:30:00.000') +}) + +tap.test('translates epoch milliseconds to UTC string given format', async t => { + const formattedTime = formatTime(epochMS, 'd mmm yyyy H:MM') + t.equal(formattedTime, '6 Apr 2019 17:30') +}) + +tap.test('translates epoch milliseconds to SYS:STANDARD', async t => { + const formattedTime = formatTime(epochMS, 'SYS:STANDARD') + t.match(formattedTime, /\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}\.\d{3} [-+]?\d{4}/) +}) + +tap.test('translates epoch milliseconds to SYS:', async t => { + const formattedTime = formatTime(epochMS, 'SYS:d mmm yyyy H:MM') + t.match(formattedTime, /\d{1} \w{3} \d{4} \d{1,2}:\d{2}/) +}) + +tap.test('passes through date string if `translateTime` is `false`', async t => { + const formattedTime = formatTime(dateStr) + t.equal(formattedTime, dateStr) +}) + +tap.test('translates date string if `translateTime` is `true`', async t => { + const formattedTime = formatTime(dateStr, true) + t.equal(formattedTime, '17:30:00.000') +}) + +tap.test('translates date string to UTC string given format', async t => { + const formattedTime = formatTime(dateStr, 'd mmm yyyy H:MM') + t.equal(formattedTime, '6 Apr 2019 17:30') +}) + +tap.test('translates date string to SYS:STANDARD', async t => { + const formattedTime = formatTime(dateStr, 'SYS:STANDARD') + t.match(formattedTime, /\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}\.\d{3} [-+]?\d{4}/) +}) + +tap.test('translates date string to UTC:', async t => { + const formattedTime = formatTime(dateStr, 'UTC:d mmm yyyy H:MM') + t.equal(formattedTime, '6 Apr 2019 17:30') +}) + +tap.test('translates date string to SYS:', async t => { + const formattedTime = formatTime(dateStr, 'SYS:d mmm yyyy H:MM') + t.match(formattedTime, /\d{1} \w{3} \d{4} \d{1,2}:\d{2}/) +}) diff --git a/lib/utils/get-property-value.js b/lib/utils/get-property-value.js new file mode 100644 index 00000000..8305a9f9 --- /dev/null +++ b/lib/utils/get-property-value.js @@ -0,0 +1,30 @@ +'use strict' + +module.exports = getPropertyValue + +const splitPropertyKey = require('./split-property-key') + +/** + * Gets a specified property from an object if it exists. + * + * @param {object} obj The object to be searched. + * @param {string|string[]} property A string, or an array of strings, identifying + * the property to be retrieved from the object. + * Accepts nested properties delimited by a `.`. + * Delimiter can be escaped to preserve property names that contain the delimiter. + * e.g. `'prop1.prop2'` or `'prop2\.domain\.corp.prop2'`. + * + * @returns {*} + */ +function getPropertyValue (obj, property) { + const props = Array.isArray(property) ? property : splitPropertyKey(property) + + for (const prop of props) { + if (!Object.prototype.hasOwnProperty.call(obj, prop)) { + return + } + obj = obj[prop] + } + + return obj +} diff --git a/lib/utils/get-property-value.test.js b/lib/utils/get-property-value.test.js new file mode 100644 index 00000000..1aa804b3 --- /dev/null +++ b/lib/utils/get-property-value.test.js @@ -0,0 +1,31 @@ +'use strict' + +const tap = require('tap') +const getPropertyValue = require('./get-property-value') + +tap.test('getPropertyValue returns the value of the property', async t => { + const result = getPropertyValue({ + foo: 'bar' + }, 'foo') + t.same(result, 'bar') +}) + +tap.test('getPropertyValue returns the value of the nested property', async t => { + const result = getPropertyValue({ extra: { foo: { value: 'bar' } } }, 'extra.foo.value') + t.same(result, 'bar') +}) + +tap.test('getPropertyValue returns the value of the nested property using the array of nested property keys', async t => { + const result = getPropertyValue({ extra: { foo: { value: 'bar' } } }, ['extra', 'foo', 'value']) + t.same(result, 'bar') +}) + +tap.test('getPropertyValue returns undefined for non-existing properties', async t => { + const result = getPropertyValue({ extra: { foo: { value: 'bar' } } }, 'extra.foo.value-2') + t.same(result, undefined) +}) + +tap.test('getPropertyValue returns undefined for non-existing properties using the array of nested property keys', async t => { + const result = getPropertyValue({ extra: { foo: { value: 'bar' } } }, ['extra', 'foo', 'value-2']) + t.same(result, undefined) +}) diff --git a/lib/utils/handle-custom-levels-names-opts.js b/lib/utils/handle-custom-levels-names-opts.js new file mode 100644 index 00000000..0c0257e2 --- /dev/null +++ b/lib/utils/handle-custom-levels-names-opts.js @@ -0,0 +1,38 @@ +'use strict' + +module.exports = handleCustomLevelsNamesOpts + +/** + * Parse a CSV string or options object that maps level + * labels to level values. + * + * @param {string|object} cLevels An object mapping level + * names to level values, e.g. `{ info: 30, debug: 65 }`, or a + * CSV string in the format `level_name:level_value`, e.g. + * `info:30,debug:65`. + * + * @returns {object} An object mapping levels names to level values + * e.g. `{ info: 30, debug: 65 }`. + */ +function handleCustomLevelsNamesOpts (cLevels) { + if (!cLevels) return {} + + if (typeof cLevels === 'string') { + return cLevels + .split(',') + .reduce((agg, value, idx) => { + const [levelName, levelNum = idx] = value.split(':') + agg[levelName.toLowerCase()] = levelNum + return agg + }, {}) + } else if (Object.prototype.toString.call(cLevels) === '[object Object]') { + return Object + .keys(cLevels) + .reduce((agg, levelName) => { + agg[levelName.toLowerCase()] = cLevels[levelName] + return agg + }, {}) + } else { + return {} + } +} diff --git a/lib/utils/handle-custom-levels-names-opts.test.js b/lib/utils/handle-custom-levels-names-opts.test.js new file mode 100644 index 00000000..cdc89103 --- /dev/null +++ b/lib/utils/handle-custom-levels-names-opts.test.js @@ -0,0 +1,44 @@ +'use strict' + +const tap = require('tap') +const handleCustomLevelsNamesOpts = require('./handle-custom-levels-names-opts') + +tap.test('returns a empty object `{}` for undefined parameter', async t => { + const handledCustomLevelNames = handleCustomLevelsNamesOpts() + t.same(handledCustomLevelNames, {}) +}) + +tap.test('returns a empty object `{}` for unknown parameter', async t => { + const handledCustomLevelNames = handleCustomLevelsNamesOpts(123) + t.same(handledCustomLevelNames, {}) +}) + +tap.test('returns a filled object for string parameter', async t => { + const handledCustomLevelNames = handleCustomLevelsNamesOpts('ok:10,warn:20,error:35') + t.same(handledCustomLevelNames, { + ok: 10, + warn: 20, + error: 35 + }) +}) + +tap.test('returns a filled object for object parameter', async t => { + const handledCustomLevelNames = handleCustomLevelsNamesOpts({ + ok: 10, + warn: 20, + error: 35 + }) + t.same(handledCustomLevelNames, { + ok: 10, + warn: 20, + error: 35 + }) +}) + +tap.test('defaults missing level num to first index', async t => { + const result = handleCustomLevelsNamesOpts('ok:10,info') + t.same(result, { + ok: 10, + info: 1 + }) +}) diff --git a/lib/utils/handle-custom-levels-opts.js b/lib/utils/handle-custom-levels-opts.js new file mode 100644 index 00000000..33931da1 --- /dev/null +++ b/lib/utils/handle-custom-levels-opts.js @@ -0,0 +1,39 @@ +'use strict' + +module.exports = handleCustomLevelsOpts + +/** + * Parse a CSV string or options object that specifies + * configuration for custom levels. + * + * @param {string|object} cLevels An object mapping level + * names to values, e.g. `{ info: 30, debug: 65 }`, or a + * CSV string in the format `level_name:level_value`, e.g. + * `info:30,debug:65`. + * + * @returns {object} An object mapping levels to labels that + * appear in logs, e.g. `{ '30': 'INFO', '65': 'DEBUG' }`. + */ +function handleCustomLevelsOpts (cLevels) { + if (!cLevels) return {} + + if (typeof cLevels === 'string') { + return cLevels + .split(',') + .reduce((agg, value, idx) => { + const [levelName, levelNum = idx] = value.split(':') + agg[levelNum] = levelName.toUpperCase() + return agg + }, + { default: 'USERLVL' }) + } else if (Object.prototype.toString.call(cLevels) === '[object Object]') { + return Object + .keys(cLevels) + .reduce((agg, levelName) => { + agg[cLevels[levelName]] = levelName.toUpperCase() + return agg + }, { default: 'USERLVL' }) + } else { + return {} + } +} diff --git a/lib/utils/handle-custom-levels-opts.test.js b/lib/utils/handle-custom-levels-opts.test.js new file mode 100644 index 00000000..3f4f8f19 --- /dev/null +++ b/lib/utils/handle-custom-levels-opts.test.js @@ -0,0 +1,47 @@ +'use strict' + +const tap = require('tap') +const handleCustomLevelsOpts = require('./handle-custom-levels-opts') + +tap.test('returns a empty object `{}` for undefined parameter', async t => { + const handledCustomLevel = handleCustomLevelsOpts() + t.same(handledCustomLevel, {}) +}) + +tap.test('returns a empty object `{}` for unknown parameter', async t => { + const handledCustomLevel = handleCustomLevelsOpts(123) + t.same(handledCustomLevel, {}) +}) + +tap.test('returns a filled object for string parameter', async t => { + const handledCustomLevel = handleCustomLevelsOpts('ok:10,warn:20,error:35') + t.same(handledCustomLevel, { + 10: 'OK', + 20: 'WARN', + 35: 'ERROR', + default: 'USERLVL' + }) +}) + +tap.test('returns a filled object for object parameter', async t => { + const handledCustomLevel = handleCustomLevelsOpts({ + ok: 10, + warn: 20, + error: 35 + }) + t.same(handledCustomLevel, { + 10: 'OK', + 20: 'WARN', + 35: 'ERROR', + default: 'USERLVL' + }) +}) + +tap.test('defaults missing level num to first index', async t => { + const result = handleCustomLevelsOpts('ok:10,info') + t.same(result, { + 10: 'OK', + 1: 'INFO', + default: 'USERLVL' + }) +}) diff --git a/lib/utils/index.js b/lib/utils/index.js new file mode 100644 index 00000000..c4ff4c15 --- /dev/null +++ b/lib/utils/index.js @@ -0,0 +1,90 @@ +'use strict' + +const { readdirSync } = require('fs') +const { basename } = require('path') + +const files = readdirSync(__dirname).filter(f => f.endsWith('.test.js') === false) +for (const file of files) { + if (file === 'index.js') continue + + const kebabName = basename(file, '.js') + const snakeName = kebabName.split('-').map((part, idx) => { + if (idx === 0) return part + return part[0].toUpperCase() + part.slice(1) + }).join('') + + module.exports[snakeName] = require(`./${kebabName}.js`) +} + +// The remainder of this file consists of jsdoc blocks that are difficult to +// determine a more appropriate "home" for. As an example, the blocks associated +// with custom prettifiers could live in either the `prettify-level`, +// `prettify-metadata`, or `prettify-time` files since they are the primary +// files where such code is used. But we want a central place to define common +// doc blocks, so we are picking this file as the answer. + +/** + * A hash of log property names mapped to prettifier functions. When the + * incoming log data is being processed for prettification, any key on the log + * that matches a key in a custom prettifiers hash will be prettified using + * that matching custom prettifier. The value passed to the custom prettifier + * will the value associated with the corresponding log key. + * + * The hash may contain any arbitrary keys for arbitrary log properties, but it + * may also contain a set of predefined key names that map to well-known log + * properties. These keys are: + * + * + `time` (for the timestamp field) + * + `level` (for the level label field; value may be a level number instead + * of a level label) + * + `hostname` + * + `pid` + * + `name` + * + `caller` + * + * @typedef {Object.} CustomPrettifiers + */ + +/** + * A synchronous function to be used for prettifying a log property. It must + * return a string. + * + * @typedef {function} CustomPrettifierFunc + * @param {any} value The value to be prettified for the key associated with + * the prettifier. + * @returns {string} + */ + +/** + * A tokenized string that indicates how the prettified log line should be + * formatted. Tokens are either log properties enclosed in curly braces, e.g. + * `{levelLabel}`, `{pid}`, or `{req.url}`, or conditional directives in curly + * braces. The only conditional directives supported are `if` and `end`, e.g. + * `{if pid}{pid}{end}`; every `if` must have a matching `end`. Nested + * conditions are not supported. + * + * @typedef {string} MessageFormatString + * + * @example + * `{levelLabel} - {if pid}{pid} - {end}url:{req.url}` + */ + +/** + * A function that accepts a log object, name of the message key, and name of + * the level label key and returns a formatted log line. + * + * Note: this function must be synchronous. + * + * @typedef {function} MessageFormatFunction + * @param {object} log The log object to be processed. + * @param {string} messageKey The name of the key in the `log` object that + * contains the log message. + * @param {string} levelLabel The name of the key in the `log` object that + * contains the log level name. + * @returns {string} + * + * @example + * function (log, messageKey, levelLabel) { + * return `${log[levelLabel]} - ${log[messageKey]}` + * } + */ diff --git a/lib/utils/interpret-conditionals.js b/lib/utils/interpret-conditionals.js new file mode 100644 index 00000000..cc30de8d --- /dev/null +++ b/lib/utils/interpret-conditionals.js @@ -0,0 +1,37 @@ +'use strict' + +module.exports = interpretConditionals + +const getPropertyValue = require('./get-property-value') + +/** + * Translates all conditional blocks from within the messageFormat. Translates + * any matching {if key}{key}{end} statements and returns everything between + * if and else blocks if the key provided was found in log. + * + * @param {MessageFormatString|MessageFormatFunction} messageFormat A format + * string or function that defines how the logged message should be + * conditionally formatted. + * @param {object} log The log object to be modified. + * + * @returns {string} The parsed messageFormat. + */ +function interpretConditionals (messageFormat, log) { + messageFormat = messageFormat.replace(/{if (.*?)}(.*?){end}/g, replacer) + + // Remove non-terminated if blocks + messageFormat = messageFormat.replace(/{if (.*?)}/g, '') + // Remove floating end blocks + messageFormat = messageFormat.replace(/{end}/g, '') + + return messageFormat.replace(/\s+/g, ' ').trim() + + function replacer (_, key, value) { + const propertyValue = getPropertyValue(log, key) + if (propertyValue && value.includes(key)) { + return value.replace(new RegExp('{' + key + '}', 'g'), propertyValue) + } else { + return '' + } + } +} diff --git a/lib/utils/interpret-conditionals.test.js b/lib/utils/interpret-conditionals.test.js new file mode 100644 index 00000000..6615552a --- /dev/null +++ b/lib/utils/interpret-conditionals.test.js @@ -0,0 +1,69 @@ +'use strict' + +const tap = require('tap') +const { createCopier } = require('fast-copy') +const fastCopy = createCopier({}) +const interpretConditionals = require('./interpret-conditionals') + +const logData = { + level: 30, + data1: { + data2: 'bar' + }, + msg: 'foo' +} + +tap.test('interpretConditionals translates if / else statement to found property value', async t => { + const log = fastCopy(logData) + t.equal(interpretConditionals('{level} - {if data1.data2}{data1.data2}{end}', log), '{level} - bar') +}) + +tap.test('interpretConditionals translates if / else statement to found property value and leave unmatched property key untouched', async t => { + const log = fastCopy(logData) + t.equal(interpretConditionals('{level} - {if data1.data2}{data1.data2} ({msg}){end}', log), '{level} - bar ({msg})') +}) + +tap.test('interpretConditionals removes non-terminated if statements', async t => { + const log = fastCopy(logData) + t.equal(interpretConditionals('{level} - {if data1.data2}{data1.data2}', log), '{level} - {data1.data2}') +}) + +tap.test('interpretConditionals removes floating end statements', async t => { + const log = fastCopy(logData) + t.equal(interpretConditionals('{level} - {data1.data2}{end}', log), '{level} - {data1.data2}') +}) + +tap.test('interpretConditionals removes floating end statements within translated if / end statements', async t => { + const log = fastCopy(logData) + t.equal(interpretConditionals('{level} - {if msg}({msg}){end}{end}', log), '{level} - (foo)') +}) + +tap.test('interpretConditionals removes if / end blocks if existent condition key does not match existent property key', async t => { + const log = fastCopy(logData) + t.equal(interpretConditionals('{level}{if msg}{data1.data2}{end}', log), '{level}') +}) + +tap.test('interpretConditionals removes if / end blocks if non-existent condition key does not match existent property key', async t => { + const log = fastCopy(logData) + t.equal(interpretConditionals('{level}{if foo}{msg}{end}', log), '{level}') +}) + +tap.test('interpretConditionals removes if / end blocks if existent condition key does not match non-existent property key', async t => { + const log = fastCopy(logData) + t.equal(interpretConditionals('{level}{if msg}{foo}{end}', log), '{level}') +}) + +tap.test('interpretConditionals removes if / end blocks if non-existent condition key does not match non-existent property key', async t => { + const log = fastCopy(logData) + t.equal(interpretConditionals('{level}{if foo}{bar}{end}', log), '{level}') +}) + +tap.test('interpretConditionals removes if / end blocks if nested condition key does not match property key', async t => { + const log = fastCopy(logData) + t.equal(interpretConditionals('{level}{if data1.msg}{data1.data2}{end}', log), '{level}') +}) + +tap.test('interpretConditionals removes nested if / end statement blocks', async t => { + const log = fastCopy(logData) + t.equal(interpretConditionals('{if msg}{if data1.data2}{msg}{data1.data2}{end}{end}', log), 'foo{data1.data2}') +}) diff --git a/lib/utils/is-object.js b/lib/utils/is-object.js new file mode 100644 index 00000000..8dd822ba --- /dev/null +++ b/lib/utils/is-object.js @@ -0,0 +1,7 @@ +'use strict' + +module.exports = isObject + +function isObject (input) { + return Object.prototype.toString.apply(input) === '[object Object]' +} diff --git a/lib/utils/is-object.test.js b/lib/utils/is-object.test.js new file mode 100644 index 00000000..85ab6029 --- /dev/null +++ b/lib/utils/is-object.test.js @@ -0,0 +1,10 @@ +'use strict' + +const tap = require('tap') +const isObject = require('./is-object') + +tap.test('returns correct answer', async t => { + t.equal(isObject({}), true) + t.equal(isObject([]), false) + t.equal(isObject(42), false) +}) diff --git a/lib/utils/is-valid-date.js b/lib/utils/is-valid-date.js new file mode 100644 index 00000000..1fc821b8 --- /dev/null +++ b/lib/utils/is-valid-date.js @@ -0,0 +1,14 @@ +'use strict' + +module.exports = isValidDate + +/** + * Checks if the argument is a JS Date and not 'Invalid Date'. + * + * @param {Date} date The date to check. + * + * @returns {boolean} true if the argument is a JS Date and not 'Invalid Date'. + */ +function isValidDate (date) { + return date instanceof Date && !Number.isNaN(date.getTime()) +} diff --git a/lib/utils/is-valid-date.test.js b/lib/utils/is-valid-date.test.js new file mode 100644 index 00000000..bb9e0d1c --- /dev/null +++ b/lib/utils/is-valid-date.test.js @@ -0,0 +1,16 @@ +'use strict' + +process.env.TZ = 'UTC' + +const tap = require('tap') +const isValidDate = require('./is-valid-date') + +tap.test('returns true for valid dates', async t => { + t.same(isValidDate(new Date()), true) +}) + +tap.test('returns false for non-dates and invalid dates', async t => { + t.plan(2) + t.same(isValidDate('20210621'), false) + t.same(isValidDate(new Date('2021-41-99')), false) +}) diff --git a/lib/utils/join-lines-with-indentation.js b/lib/utils/join-lines-with-indentation.js new file mode 100644 index 00000000..7761ae61 --- /dev/null +++ b/lib/utils/join-lines-with-indentation.js @@ -0,0 +1,29 @@ +'use strict' + +module.exports = joinLinesWithIndentation + +/** + * @typedef {object} JoinLinesWithIndentationParams + * @property {string} input The string to split and reformat. + * @property {string} [ident] The indentation string. Default: ` ` (4 spaces). + * @property {string} [eol] The end of line sequence to use when rejoining + * the lines. Default: `'\n'`. + */ + +/** + * Given a string with line separators, either `\r\n` or `\n`, add indentation + * to all lines subsequent to the first line and rejoin the lines using an + * end of line sequence. + * + * @param {JoinLinesWithIndentationParams} input + * + * @returns {string} A string with lines subsequent to the first indented + * with the given indentation sequence. + */ +function joinLinesWithIndentation ({ input, ident = ' ', eol = '\n' }) { + const lines = input.split(/\r?\n/) + for (let i = 1; i < lines.length; i += 1) { + lines[i] = ident + lines[i] + } + return lines.join(eol) +} diff --git a/lib/utils/join-lines-with-indentation.test.js b/lib/utils/join-lines-with-indentation.test.js new file mode 100644 index 00000000..7cf60b24 --- /dev/null +++ b/lib/utils/join-lines-with-indentation.test.js @@ -0,0 +1,16 @@ +'use strict' + +const tap = require('tap') +const joinLinesWithIndentation = require('./join-lines-with-indentation') + +tap.test('joinLinesWithIndentation adds indentation to beginning of subsequent lines', async t => { + const input = 'foo\nbar\nbaz' + const result = joinLinesWithIndentation({ input }) + t.equal(result, 'foo\n bar\n baz') +}) + +tap.test('joinLinesWithIndentation accepts custom indentation, line breaks, and eol', async t => { + const input = 'foo\nbar\r\nbaz' + const result = joinLinesWithIndentation({ input, ident: ' ', eol: '^' }) + t.equal(result, 'foo^ bar^ baz') +}) diff --git a/lib/utils/noop.js b/lib/utils/noop.js new file mode 100644 index 00000000..a77986c3 --- /dev/null +++ b/lib/utils/noop.js @@ -0,0 +1,3 @@ +'use strict' + +module.exports = function noop () {} diff --git a/lib/utils/noop.test.js b/lib/utils/noop.test.js new file mode 100644 index 00000000..5acfd7c1 --- /dev/null +++ b/lib/utils/noop.test.js @@ -0,0 +1,12 @@ +'use strict' + +const tap = require('tap') +const noop = require('./noop') + +tap.test('is a function', async t => { + t.type(noop, Function) +}) + +tap.test('does nothing', async t => { + t.equal(noop('stuff'), undefined) +}) diff --git a/lib/utils/parse-factory-options.js b/lib/utils/parse-factory-options.js new file mode 100644 index 00000000..33ffb374 --- /dev/null +++ b/lib/utils/parse-factory-options.js @@ -0,0 +1,153 @@ +'use strict' + +module.exports = parseFactoryOptions + +const { + LEVEL_NAMES +} = require('../constants') +const colors = require('../colors') +const handleCustomLevelsOpts = require('./handle-custom-levels-opts') +const handleCustomLevelsNamesOpts = require('./handle-custom-levels-names-opts') + +/** + * A `PrettyContext` is an object to be used by the various functions that + * process log data. It is derived from the provided {@link PinoPrettyOptions}. + * It may be used as a `this` context. + * + * @typedef {object} PrettyContext + * @property {string} EOL The escape sequence chosen as the line terminator. + * @property {string} IDENT The string to use as the indentation sequence. + * @property {ColorizerFunc} colorizer A configured colorizer function. + * @property {Array[Array]} customColors A set of custom color + * names associated with level numbers. + * @property {object} customLevelNames A hash of level numbers to level names, + * e.g. `{ 30: "info" }`. + * @property {object} customLevels A hash of level names to level numbers, + * e.g. `{ info: 30 }`. + * @property {CustomPrettifiers} customPrettifiers A hash of custom prettifier + * functions. + * @property {object} customProperties Comprised of `customLevels` and + * `customLevelNames` if such options are provided. + * @property {string[]} errorLikeObjectKeys The key names in the log data that + * should be considered as holding error objects. + * @property {string[]} errorProps A list of error object keys that should be + * included in the output. + * @property {boolean} hideObject Indicates the prettifier should omit objects + * in the output. + * @property {string[]} ignoreKeys Set of log data keys to omit. + * @property {string[]} includeKeys Opposite of `ignoreKeys`. + * @property {boolean} levelFirst Indicates the level should be printed first. + * @property {string} levelKey Name of the key in the log data that contains + * the message. + * @property {string} levelLabel Format token to represent the position of the + * level name in the output string. + * @property {MessageFormatString|MessageFormatFunction} messageFormat + * @property {string} messageKey Name of the key in the log data that contains + * the message. + * @property {string|number} minimumLevel The minimum log level to process + * and output. + * @property {ColorizerFunc} objectColorizer + * @property {boolean} singleLine Indicates objects should be printed on a + * single output line. + * @property {string} timestampKey The name of the key in the log data that + * contains the log timestamp. + * @property {boolean} translateTime Indicates if timestamps should be + * translated to a human-readable string. + * @property {boolean} useOnlyCustomProps + */ + +/** + * @param {PinoPrettyOptions} options The user supplied object of options. + * + * @returns {PrettyContext} + */ +function parseFactoryOptions (options) { + const EOL = options.crlf ? '\r\n' : '\n' + const IDENT = ' ' + const { + customPrettifiers, + errorLikeObjectKeys, + hideObject, + levelFirst, + levelKey, + levelLabel, + messageFormat, + messageKey, + minimumLevel, + singleLine, + timestampKey, + translateTime + } = options + const errorProps = options.errorProps.split(',') + const useOnlyCustomProps = typeof options.useOnlyCustomProps === 'boolean' + ? options.useOnlyCustomProps + : (options.useOnlyCustomProps === 'true') + const customLevels = handleCustomLevelsOpts(options.customLevels) + const customLevelNames = handleCustomLevelsNamesOpts(options.customLevels) + + let customColors + if (options.customColors) { + customColors = options.customColors.split(',').reduce((agg, value) => { + const [level, color] = value.split(':') + + const condition = useOnlyCustomProps + ? options.customLevels + : customLevelNames[level] !== undefined + const levelNum = condition + ? customLevelNames[level] + : LEVEL_NAMES[level] + const colorIdx = levelNum !== undefined + ? levelNum + : level + + agg.push([colorIdx, color]) + + return agg + }, []) + } + + const customProperties = { customLevels, customLevelNames } + if (useOnlyCustomProps === true && !options.customLevels) { + customProperties.customLevels = undefined + customProperties.customLevelNames = undefined + } + + const includeKeys = options.include !== undefined + ? new Set(options.include.split(',')) + : undefined + const ignoreKeys = (!includeKeys && options.ignore) + ? new Set(options.ignore.split(',')) + : undefined + + const colorizer = colors(options.colorize, customColors, useOnlyCustomProps) + const objectColorizer = options.colorizeObjects + ? colorizer + : colors(false, [], false) + + return { + EOL, + IDENT, + colorizer, + customColors, + customLevelNames, + customLevels, + customPrettifiers, + customProperties, + errorLikeObjectKeys, + errorProps, + hideObject, + ignoreKeys, + includeKeys, + levelFirst, + levelKey, + levelLabel, + messageFormat, + messageKey, + minimumLevel, + objectColorizer, + singleLine, + timestampKey, + translateTime, + useOnlyCustomProps + } +} diff --git a/lib/utils/prettify-error-log.js b/lib/utils/prettify-error-log.js new file mode 100644 index 00000000..2410c650 --- /dev/null +++ b/lib/utils/prettify-error-log.js @@ -0,0 +1,73 @@ +'use strict' + +module.exports = prettifyErrorLog + +const { + LOGGER_KEYS +} = require('../constants') + +const isObject = require('./is-object') +const joinLinesWithIndentation = require('./join-lines-with-indentation') +const prettifyObject = require('./prettify-object') + +/** + * @typedef {object} PrettifyErrorLogParams + * @property {object} log The error log to prettify. + * @property {PrettyContext} context The context object built from parsing + * the options. + */ + +/** + * Given a log object that has a `type: 'Error'` key, prettify the object and + * return the result. In other + * + * @param {PrettifyErrorLogParams} input + * + * @returns {string} A string that represents the prettified error log. + */ +function prettifyErrorLog ({ log, context }) { + const { + EOL: eol, + IDENT: ident, + errorProps: errorProperties, + messageKey + } = context + const stack = log.stack + const joinedLines = joinLinesWithIndentation({ input: stack, ident, eol }) + let result = `${ident}${joinedLines}${eol}` + + if (errorProperties.length > 0) { + const excludeProperties = LOGGER_KEYS.concat(messageKey, 'type', 'stack') + let propertiesToPrint + if (errorProperties[0] === '*') { + // Print all sibling properties except for the standard exclusions. + propertiesToPrint = Object.keys(log).filter(k => excludeProperties.includes(k) === false) + } else { + // Print only specified properties unless the property is a standard exclusion. + propertiesToPrint = errorProperties.filter(k => excludeProperties.includes(k) === false) + } + + for (let i = 0; i < propertiesToPrint.length; i += 1) { + const key = propertiesToPrint[i] + if (key in log === false) continue + if (isObject(log[key])) { + // The nested object may have "logger" type keys but since they are not + // at the root level of the object being processed, we want to print them. + // Thus, we invoke with `excludeLoggerKeys: false`. + const prettifiedObject = prettifyObject({ + log: log[key], + excludeLoggerKeys: false, + context: { + ...context, + IDENT: ident + ident + } + }) + result = `${result}${ident}${key}: {${eol}${prettifiedObject}${ident}}${eol}` + continue + } + result = `${result}${ident}${key}: ${log[key]}${eol}` + } + } + + return result +} diff --git a/lib/utils/prettify-error-log.test.js b/lib/utils/prettify-error-log.test.js new file mode 100644 index 00000000..04e10f82 --- /dev/null +++ b/lib/utils/prettify-error-log.test.js @@ -0,0 +1,110 @@ +'use strict' + +const tap = require('tap') +const prettifyErrorLog = require('./prettify-error-log') +const { + ERROR_LIKE_KEYS, + MESSAGE_KEY +} = require('../constants') + +const context = { + EOL: '\n', + IDENT: ' ', + customPrettifiers: {}, + errorLikeObjectKeys: ERROR_LIKE_KEYS, + errorProps: [], + messageKey: MESSAGE_KEY +} + +tap.test('returns string with default settings', async t => { + const err = Error('Something went wrong') + const str = prettifyErrorLog({ log: err, context }) + t.ok(str.startsWith(' Error: Something went wrong')) +}) + +tap.test('returns string with custom ident', async t => { + const err = Error('Something went wrong') + const str = prettifyErrorLog({ + log: err, + context: { + ...context, + IDENT: ' ' + } + }) + t.ok(str.startsWith(' Error: Something went wrong')) +}) + +tap.test('returns string with custom eol', async t => { + const err = Error('Something went wrong') + const str = prettifyErrorLog({ + log: err, + context: { + ...context, + EOL: '\r\n' + } + }) + t.ok(str.startsWith(' Error: Something went wrong\r\n')) +}) + +tap.test('errorProperties', t => { + t.test('excludes all for wildcard', async t => { + const err = Error('boom') + err.foo = 'foo' + const str = prettifyErrorLog({ + log: err, + context: { + ...context, + errorProps: ['*'] + } + }) + t.ok(str.startsWith(' Error: boom')) + t.equal(str.includes('foo: "foo"'), false) + }) + + t.test('excludes only selected properties', async t => { + const err = Error('boom') + err.foo = 'foo' + const str = prettifyErrorLog({ + log: err, + context: { + ...context, + errorProps: ['foo'] + } + }) + t.ok(str.startsWith(' Error: boom')) + t.equal(str.includes('foo: foo'), true) + }) + + t.test('ignores specified properties if not present', async t => { + const err = Error('boom') + err.foo = 'foo' + const str = prettifyErrorLog({ + log: err, + context: { + ...context, + errorProps: ['foo', 'bar'] + } + }) + t.ok(str.startsWith(' Error: boom')) + t.equal(str.includes('foo: foo'), true) + t.equal(str.includes('bar'), false) + }) + + t.test('processes nested objects', async t => { + const err = Error('boom') + err.foo = { bar: 'bar', message: 'included' } + const str = prettifyErrorLog({ + log: err, + context: { + ...context, + errorProps: ['foo'] + } + }) + t.ok(str.startsWith(' Error: boom')) + t.equal(str.includes('foo: {'), true) + t.equal(str.includes('bar: "bar"'), true) + t.equal(str.includes('message: "included"'), true) + }) + + t.end() +}) diff --git a/lib/utils/prettify-error.js b/lib/utils/prettify-error.js new file mode 100644 index 00000000..ac99826a --- /dev/null +++ b/lib/utils/prettify-error.js @@ -0,0 +1,49 @@ +'use strict' + +module.exports = prettifyError + +const joinLinesWithIndentation = require('./join-lines-with-indentation') + +/** + * @typedef {object} PrettifyErrorParams + * @property {string} keyName The key assigned to this error in the log object. + * @property {string} lines The STRINGIFIED error. If the error field has a + * custom prettifier, that should be pre-applied as well. + * @property {string} ident The indentation sequence to use. + * @property {string} eol The EOL sequence to use. + */ + +/** + * Prettifies an error string into a multi-line format. + * + * @param {PrettifyErrorParams} input + * + * @returns {string} + */ +function prettifyError ({ keyName, lines, eol, ident }) { + let result = '' + const joinedLines = joinLinesWithIndentation({ input: lines, ident, eol }) + const splitLines = `${ident}${keyName}: ${joinedLines}${eol}`.split(eol) + + for (let j = 0; j < splitLines.length; j += 1) { + if (j !== 0) result += eol + + const line = splitLines[j] + if (/^\s*"stack"/.test(line)) { + const matches = /^(\s*"stack":)\s*(".*"),?$/.exec(line) + /* istanbul ignore else */ + if (matches && matches.length === 3) { + const indentSize = /^\s*/.exec(line)[0].length + 4 + const indentation = ' '.repeat(indentSize) + const stackMessage = matches[2] + result += matches[1] + eol + indentation + JSON.parse(stackMessage).replace(/\n/g, eol + indentation) + } else { + result += line + } + } else { + result += line + } + } + + return result +} diff --git a/lib/utils/prettify-error.test.js b/lib/utils/prettify-error.test.js new file mode 100644 index 00000000..ba26944a --- /dev/null +++ b/lib/utils/prettify-error.test.js @@ -0,0 +1,14 @@ +'use strict' + +const tap = require('tap') +const stringifySafe = require('fast-safe-stringify') +const prettifyError = require('./prettify-error') + +tap.test('prettifies error', t => { + const error = Error('Bad error!') + const lines = stringifySafe(error, Object.getOwnPropertyNames(error), 2) + + const prettyError = prettifyError({ keyName: 'errorKey', lines, ident: ' ', eol: '\n' }) + t.match(prettyError, /\s*errorKey: {\n\s*"stack":[\s\S]*"message": "Bad error!"/) + t.end() +}) diff --git a/lib/utils/prettify-level.js b/lib/utils/prettify-level.js new file mode 100644 index 00000000..213ba06c --- /dev/null +++ b/lib/utils/prettify-level.js @@ -0,0 +1,35 @@ +'use strict' + +module.exports = prettifyLevel + +const getPropertyValue = require('./get-property-value') + +/** + * @typedef {object} PrettifyLevelParams + * @property {object} log The log object. + * @property {PrettyContext} context The context object built from parsing + * the options. + */ + +/** + * Checks if the passed in log has a `level` value and returns a prettified + * string for that level if so. + * + * @param {PrettifyLevelParams} input + * + * @returns {undefined|string} If `log` does not have a `level` property then + * `undefined` will be returned. Otherwise, a string from the specified + * `colorizer` is returned. + */ +function prettifyLevel ({ log, context }) { + const { + colorizer, + customLevels, + customLevelNames, + levelKey + } = context + const prettifier = context.customPrettifiers?.level + const output = getPropertyValue(log, levelKey) + if (output === undefined) return undefined + return prettifier ? prettifier(output) : colorizer(output, { customLevels, customLevelNames }) +} diff --git a/lib/utils/prettify-level.test.js b/lib/utils/prettify-level.test.js new file mode 100644 index 00000000..e735b0a9 --- /dev/null +++ b/lib/utils/prettify-level.test.js @@ -0,0 +1,68 @@ +'use strict' + +const tap = require('tap') +const prettifyLevel = require('./prettify-level') +const getColorizer = require('../colors') +const { + LEVEL_KEY +} = require('../constants') + +const context = { + colorizer: getColorizer(), + customLevelNames: undefined, + customLevels: undefined, + levelKey: LEVEL_KEY, + customPrettifiers: undefined +} + +tap.test('returns `undefined` for unknown level', async t => { + const colorized = prettifyLevel({ + log: {}, + context: { + ...context + } + }) + t.equal(colorized, undefined) +}) + +tap.test('returns non-colorized value for default colorizer', async t => { + const log = { + level: 30 + } + const colorized = prettifyLevel({ + log, + context: { + ...context + } + }) + t.equal(colorized, 'INFO') +}) + +tap.test('returns colorized value for color colorizer', async t => { + const log = { + level: 30 + } + const colorizer = getColorizer(true) + const colorized = prettifyLevel({ + log, + context: { + ...context, + colorizer + } + }) + t.equal(colorized, '\u001B[32mINFO\u001B[39m') +}) + +tap.test('passes output through provided prettifier', async t => { + const log = { + level: 30 + } + const colorized = prettifyLevel({ + log, + context: { + ...context, + customPrettifiers: { level () { return 'modified' } } + } + }) + t.equal(colorized, 'modified') +}) diff --git a/lib/utils/prettify-message.js b/lib/utils/prettify-message.js new file mode 100644 index 00000000..7758f1d8 --- /dev/null +++ b/lib/utils/prettify-message.js @@ -0,0 +1,63 @@ +'use strict' + +module.exports = prettifyMessage + +const { + LEVELS +} = require('../constants') + +const getPropertyValue = require('./get-property-value') +const interpretConditionals = require('./interpret-conditionals') + +/** + * @typedef {object} PrettifyMessageParams + * @property {object} log The log object with the message to colorize. + * @property {PrettyContext} context The context object built from parsing + * the options. + */ + +/** + * Prettifies a message string if the given `log` has a message property. + * + * @param {PrettifyMessageParams} input + * + * @returns {undefined|string} If the message key is not found, or the message + * key is not a string, then `undefined` will be returned. Otherwise, a string + * that is the prettified message. + */ +function prettifyMessage ({ log, context }) { + const { + colorizer, + customLevels, + levelKey, + levelLabel, + messageFormat, + messageKey, + useOnlyCustomProps + } = context + if (messageFormat && typeof messageFormat === 'string') { + const parsedMessageFormat = interpretConditionals(messageFormat, log) + + const message = String(parsedMessageFormat).replace( + /{([^{}]+)}/g, + function (match, p1) { + // return log level as string instead of int + let level + if (p1 === levelLabel && (level = getPropertyValue(log, levelKey)) !== undefined) { + const condition = useOnlyCustomProps ? customLevels === undefined : customLevels[level] === undefined + return condition ? LEVELS[level] : customLevels[level] + } + + // Parse nested key access, e.g. `{keyA.subKeyB}`. + return getPropertyValue(log, p1) || '' + }) + return colorizer.message(message) + } + if (messageFormat && typeof messageFormat === 'function') { + const msg = messageFormat(log, messageKey, levelLabel) + return colorizer.message(msg) + } + if (messageKey in log === false) return undefined + if (typeof log[messageKey] !== 'string' && typeof log[messageKey] !== 'number' && typeof log[messageKey] !== 'boolean') return undefined + return colorizer.message(log[messageKey]) +} diff --git a/lib/utils/prettify-message.test.js b/lib/utils/prettify-message.test.js new file mode 100644 index 00000000..8faf4b12 --- /dev/null +++ b/lib/utils/prettify-message.test.js @@ -0,0 +1,187 @@ +'use strict' + +const tap = require('tap') +const prettifyMessage = require('./prettify-message') +const getColorizer = require('../colors') +const { + LEVEL_KEY, + LEVEL_LABEL +} = require('../constants') +const context = { + colorizer: getColorizer(), + levelKey: LEVEL_KEY, + levelLabel: LEVEL_LABEL, + messageKey: 'msg' +} + +tap.test('returns `undefined` if `messageKey` not found', async t => { + const str = prettifyMessage({ log: {}, context }) + t.equal(str, undefined) +}) + +tap.test('returns `undefined` if `messageKey` not string', async t => { + const str = prettifyMessage({ log: { msg: {} }, context }) + t.equal(str, undefined) +}) + +tap.test('returns non-colorized value for default colorizer', async t => { + const colorizer = getColorizer() + const str = prettifyMessage({ + log: { msg: 'foo' }, + context: { ...context, colorizer } + }) + t.equal(str, 'foo') +}) + +tap.test('returns non-colorized value for alternate `messageKey`', async t => { + const str = prettifyMessage({ + log: { message: 'foo' }, + context: { ...context, messageKey: 'message' } + }) + t.equal(str, 'foo') +}) + +tap.test('returns colorized value for color colorizer', async t => { + const colorizer = getColorizer(true) + const str = prettifyMessage({ + log: { msg: 'foo' }, + context: { ...context, colorizer } + }) + t.equal(str, '\u001B[36mfoo\u001B[39m') +}) + +tap.test('returns colorized value for color colorizer for alternate `messageKey`', async t => { + const colorizer = getColorizer(true) + const str = prettifyMessage({ + log: { message: 'foo' }, + context: { ...context, messageKey: 'message', colorizer } + }) + t.equal(str, '\u001B[36mfoo\u001B[39m') +}) + +tap.test('returns message formatted by `messageFormat` option', async t => { + const str = prettifyMessage({ + log: { msg: 'foo', context: 'appModule' }, + context: { ...context, messageFormat: '{context} - {msg}' } + }) + t.equal(str, 'appModule - foo') +}) + +tap.test('returns message formatted by `messageFormat` option - missing prop', async t => { + const str = prettifyMessage({ + log: { context: 'appModule' }, + context: { ...context, messageFormat: '{context} - {msg}' } + }) + t.equal(str, 'appModule - ') +}) + +tap.test('returns message formatted by `messageFormat` option - levelLabel & useOnlyCustomProps false', async t => { + const str = prettifyMessage({ + log: { msg: 'foo', context: 'appModule', level: 30 }, + context: { + ...context, + messageFormat: '[{level}] {levelLabel} {context} - {msg}', + customLevels: {} + } + }) + t.equal(str, '[30] INFO appModule - foo') +}) + +tap.test('returns message formatted by `messageFormat` option - levelLabel & useOnlyCustomProps true', async t => { + const str = prettifyMessage({ + log: { msg: 'foo', context: 'appModule', level: 30 }, + context: { + ...context, + messageFormat: '[{level}] {levelLabel} {context} - {msg}', + customLevels: { 30: 'CHECK' }, + useOnlyCustomProps: true + } + }) + t.equal(str, '[30] CHECK appModule - foo') +}) + +tap.test('returns message formatted by `messageFormat` option - levelLabel & customLevels', async t => { + const str = prettifyMessage({ + log: { msg: 'foo', context: 'appModule', level: 123 }, + context: { + ...context, + messageFormat: '[{level}] {levelLabel} {context} - {msg}', + customLevels: { 123: 'CUSTOM' } + } + }) + t.equal(str, '[123] CUSTOM appModule - foo') +}) + +tap.test('returns message formatted by `messageFormat` option - levelLabel, customLevels & useOnlyCustomProps', async t => { + const str = prettifyMessage({ + log: { msg: 'foo', context: 'appModule', level: 123 }, + context: { + ...context, + messageFormat: '[{level}] {levelLabel} {context} - {msg}', + customLevels: { 123: 'CUSTOM' }, + useOnlyCustomProps: true + } + }) + t.equal(str, '[123] CUSTOM appModule - foo') +}) + +tap.test('returns message formatted by `messageFormat` option - levelLabel, customLevels & useOnlyCustomProps false', async t => { + const str = prettifyMessage({ + log: { msg: 'foo', context: 'appModule', level: 40 }, + context: { + ...context, + messageFormat: '[{level}] {levelLabel} {context} - {msg}', + customLevels: { 123: 'CUSTOM' }, + useOnlyCustomProps: false + } + }) + t.equal(str, '[40] WARN appModule - foo') +}) + +tap.test('`messageFormat` supports nested curly brackets', async t => { + const str = prettifyMessage({ + log: { level: 30 }, + context: { + ...context, + messageFormat: '{{level}}-{level}-{{level}-{level}}' + } + }) + t.equal(str, '{30}-30-{30-30}') +}) + +tap.test('`messageFormat` supports nested object', async t => { + const str = prettifyMessage({ + log: { level: 30, request: { url: 'localhost/test' }, msg: 'foo' }, + context: { + ...context, + messageFormat: '{request.url} - param: {request.params.process} - {msg}' + } + }) + t.equal(str, 'localhost/test - param: - foo') +}) + +tap.test('`messageFormat` supports conditional blocks', async t => { + const str = prettifyMessage({ + log: { level: 30, req: { id: 'foo' } }, + context: { + ...context, + messageFormat: '{level} | {if req.id}({req.id}){end}{if msg}{msg}{end}' + } + }) + t.equal(str, '30 | (foo)') +}) + +tap.test('`messageFormat` supports function definition', async t => { + const str = prettifyMessage({ + log: { level: 30, request: { url: 'localhost/test' }, msg: 'incoming request' }, + context: { + ...context, + messageFormat: (log, messageKey, levelLabel) => { + let msg = log[messageKey] + if (msg === 'incoming request') msg = `--> ${log.request.url}` + return msg + } + } + }) + t.equal(str, '--> localhost/test') +}) diff --git a/lib/utils/prettify-metadata.js b/lib/utils/prettify-metadata.js new file mode 100644 index 00000000..5fb4a3b0 --- /dev/null +++ b/lib/utils/prettify-metadata.js @@ -0,0 +1,61 @@ +'use strict' + +module.exports = prettifyMetadata + +/** + * @typedef {object} PrettifyMetadataParams + * @property {object} log The log that may or may not contain metadata to + * be prettified. + * @property {PrettyContext} context The context object built from parsing + * the options. + */ + +/** + * Prettifies metadata that is usually present in a Pino log line. It looks for + * fields `name`, `pid`, `hostname`, and `caller` and returns a formatted string using + * the fields it finds. + * + * @param {PrettifyMetadataParams} input + * + * @returns {undefined|string} If no metadata is found then `undefined` is + * returned. Otherwise, a string of prettified metadata is returned. + */ +function prettifyMetadata ({ log, context }) { + const prettifiers = context.customPrettifiers + let line = '' + + if (log.name || log.pid || log.hostname) { + line += '(' + + if (log.name) { + line += prettifiers.name ? prettifiers.name(log.name) : log.name + } + + if (log.pid) { + const prettyPid = prettifiers.pid ? prettifiers.pid(log.pid) : log.pid + if (log.name && log.pid) { + line += '/' + prettyPid + } else { + line += prettyPid + } + } + + if (log.hostname) { + // If `pid` and `name` were in the ignore keys list then we don't need + // the leading space. + line += `${line === '(' ? 'on' : ' on'} ${prettifiers.hostname ? prettifiers.hostname(log.hostname) : log.hostname}` + } + + line += ')' + } + + if (log.caller) { + line += `${line === '' ? '' : ' '}<${prettifiers.caller ? prettifiers.caller(log.caller) : log.caller}>` + } + + if (line === '') { + return undefined + } else { + return line + } +} diff --git a/lib/utils/prettify-metadata.test.js b/lib/utils/prettify-metadata.test.js new file mode 100644 index 00000000..91281a96 --- /dev/null +++ b/lib/utils/prettify-metadata.test.js @@ -0,0 +1,111 @@ +'use strict' + +const tap = require('tap') +const prettifyMetadata = require('./prettify-metadata') +const context = { + customPrettifiers: {} +} + +tap.test('returns `undefined` if no metadata present', async t => { + const str = prettifyMetadata({ log: {}, context }) + t.equal(str, undefined) +}) + +tap.test('works with only `name` present', async t => { + const str = prettifyMetadata({ log: { name: 'foo' }, context }) + t.equal(str, '(foo)') +}) + +tap.test('works with only `pid` present', async t => { + const str = prettifyMetadata({ log: { pid: '1234' }, context }) + t.equal(str, '(1234)') +}) + +tap.test('works with only `hostname` present', async t => { + const str = prettifyMetadata({ log: { hostname: 'bar' }, context }) + t.equal(str, '(on bar)') +}) + +tap.test('works with only `name` & `pid` present', async t => { + const str = prettifyMetadata({ log: { name: 'foo', pid: '1234' }, context }) + t.equal(str, '(foo/1234)') +}) + +tap.test('works with only `name` & `hostname` present', async t => { + const str = prettifyMetadata({ log: { name: 'foo', hostname: 'bar' }, context }) + t.equal(str, '(foo on bar)') +}) + +tap.test('works with only `pid` & `hostname` present', async t => { + const str = prettifyMetadata({ log: { pid: '1234', hostname: 'bar' }, context }) + t.equal(str, '(1234 on bar)') +}) + +tap.test('works with only `name`, `pid`, & `hostname` present', async t => { + const str = prettifyMetadata({ log: { name: 'foo', pid: '1234', hostname: 'bar' }, context }) + t.equal(str, '(foo/1234 on bar)') +}) + +tap.test('works with only `name` & `caller` present', async t => { + const str = prettifyMetadata({ log: { name: 'foo', caller: 'baz' }, context }) + t.equal(str, '(foo) ') +}) + +tap.test('works with only `pid` & `caller` present', async t => { + const str = prettifyMetadata({ log: { pid: '1234', caller: 'baz' }, context }) + t.equal(str, '(1234) ') +}) + +tap.test('works with only `hostname` & `caller` present', async t => { + const str = prettifyMetadata({ log: { hostname: 'bar', caller: 'baz' }, context }) + t.equal(str, '(on bar) ') +}) + +tap.test('works with only `name`, `pid`, & `caller` present', async t => { + const str = prettifyMetadata({ log: { name: 'foo', pid: '1234', caller: 'baz' }, context }) + t.equal(str, '(foo/1234) ') +}) + +tap.test('works with only `name`, `hostname`, & `caller` present', async t => { + const str = prettifyMetadata({ log: { name: 'foo', hostname: 'bar', caller: 'baz' }, context }) + t.equal(str, '(foo on bar) ') +}) + +tap.test('works with only `caller` present', async t => { + const str = prettifyMetadata({ log: { caller: 'baz' }, context }) + t.equal(str, '') +}) + +tap.test('works with only `pid`, `hostname`, & `caller` present', async t => { + const str = prettifyMetadata({ log: { pid: '1234', hostname: 'bar', caller: 'baz' }, context }) + t.equal(str, '(1234 on bar) ') +}) + +tap.test('works with all four present', async t => { + const str = prettifyMetadata({ log: { name: 'foo', pid: '1234', hostname: 'bar', caller: 'baz' }, context }) + t.equal(str, '(foo/1234 on bar) ') +}) + +tap.test('uses prettifiers from passed prettifiers object', async t => { + const prettifiers = { + name (input) { + return input.toUpperCase() + }, + pid (input) { + return input + '__' + }, + hostname (input) { + return input.toUpperCase() + }, + caller (input) { + return input.toUpperCase() + } + } + const str = prettifyMetadata({ + log: { pid: '1234', hostname: 'bar', caller: 'baz', name: 'joe' }, + context: { + customPrettifiers: prettifiers + } + }) + t.equal(str, '(JOE/1234__ on BAR) ') +}) diff --git a/lib/utils/prettify-object.js b/lib/utils/prettify-object.js new file mode 100644 index 00000000..e4bbec1c --- /dev/null +++ b/lib/utils/prettify-object.js @@ -0,0 +1,111 @@ +'use strict' + +module.exports = prettifyObject + +const { + LOGGER_KEYS +} = require('../constants') + +const stringifySafe = require('fast-safe-stringify') +const joinLinesWithIndentation = require('./join-lines-with-indentation') +const prettifyError = require('./prettify-error') + +/** + * @typedef {object} PrettifyObjectParams + * @property {object} log The object to prettify. + * @property {boolean} [excludeLoggerKeys] Indicates if known logger specific + * keys should be excluded from prettification. Default: `true`. + * @property {string[]} [skipKeys] A set of object keys to exclude from the + * * prettified result. Default: `[]`. + * @property {PrettyContext} context The context object built from parsing + * the options. + */ + +/** + * Prettifies a standard object. Special care is taken when processing the object + * to handle child objects that are attached to keys known to contain error + * objects. + * + * @param {PrettifyObjectParams} input + * + * @returns {string} The prettified string. This can be as little as `''` if + * there was nothing to prettify. + */ +function prettifyObject ({ + log, + excludeLoggerKeys = true, + skipKeys = [], + context +}) { + const { + EOL: eol, + IDENT: ident, + customPrettifiers, + errorLikeObjectKeys: errorLikeKeys, + objectColorizer, + singleLine + } = context + const keysToIgnore = [].concat(skipKeys) + + /* istanbul ignore else */ + if (excludeLoggerKeys === true) Array.prototype.push.apply(keysToIgnore, LOGGER_KEYS) + + let result = '' + + // Split object keys into two categories: error and non-error + const { plain, errors } = Object.entries(log).reduce(({ plain, errors }, [k, v]) => { + if (keysToIgnore.includes(k) === false) { + // Pre-apply custom prettifiers, because all 3 cases below will need this + const pretty = typeof customPrettifiers[k] === 'function' + ? customPrettifiers[k](v, k, log) + : v + if (errorLikeKeys.includes(k)) { + errors[k] = pretty + } else { + plain[k] = pretty + } + } + return { plain, errors } + }, { plain: {}, errors: {} }) + + if (singleLine) { + // Stringify the entire object as a single JSON line + /* istanbul ignore else */ + if (Object.keys(plain).length > 0) { + result += objectColorizer.greyMessage(stringifySafe(plain)) + } + result += eol + // Avoid printing the escape character on escaped backslashes. + result = result.replace(/\\\\/gi, '\\') + } else { + // Put each object entry on its own line + Object.entries(plain).forEach(([keyName, keyValue]) => { + // custom prettifiers are already applied above, so we can skip it now + let lines = typeof customPrettifiers[keyName] === 'function' + ? keyValue + : stringifySafe(keyValue, null, 2) + + if (lines === undefined) return + + // Avoid printing the escape character on escaped backslashes. + lines = lines.replace(/\\\\/gi, '\\') + + const joinedLines = joinLinesWithIndentation({ input: lines, ident, eol }) + result += `${ident}${keyName}:${joinedLines.startsWith(eol) ? '' : ' '}${joinedLines}${eol}` + }) + } + + // Errors + Object.entries(errors).forEach(([keyName, keyValue]) => { + // custom prettifiers are already applied above, so we can skip it now + const lines = typeof customPrettifiers[keyName] === 'function' + ? keyValue + : stringifySafe(keyValue, null, 2) + + if (lines === undefined) return + + result += prettifyError({ keyName, lines, eol, ident }) + }) + + return result +} diff --git a/lib/utils/prettify-object.test.js b/lib/utils/prettify-object.test.js new file mode 100644 index 00000000..61f64244 --- /dev/null +++ b/lib/utils/prettify-object.test.js @@ -0,0 +1,152 @@ +'use strict' + +const tap = require('tap') +const colors = require('../colors') +const prettifyObject = require('./prettify-object') +const { + ERROR_LIKE_KEYS +} = require('../constants') + +const context = { + EOL: '\n', + IDENT: ' ', + customPrettifiers: {}, + errorLikeObjectKeys: ERROR_LIKE_KEYS, + objectColorizer: colors(), + singleLine: false +} + +tap.test('returns empty string if no properties present', async t => { + const str = prettifyObject({ log: {}, context }) + t.equal(str, '') +}) + +tap.test('works with single level properties', async t => { + const str = prettifyObject({ log: { foo: 'bar' }, context }) + t.equal(str, ' foo: "bar"\n') +}) + +tap.test('works with multiple level properties', async t => { + const str = prettifyObject({ log: { foo: { bar: 'baz' } }, context }) + t.equal(str, ' foo: {\n "bar": "baz"\n }\n') +}) + +tap.test('skips specified keys', async t => { + const str = prettifyObject({ + log: { foo: 'bar', hello: 'world' }, + skipKeys: ['foo'], + context + }) + t.equal(str, ' hello: "world"\n') +}) + +tap.test('ignores predefined keys', async t => { + const str = prettifyObject({ log: { foo: 'bar', pid: 12345 }, context }) + t.equal(str, ' foo: "bar"\n') +}) + +tap.test('ignores escaped backslashes in string values', async t => { + const str = prettifyObject({ log: { foo_regexp: '\\[^\\w\\s]\\' }, context }) + t.equal(str, ' foo_regexp: "\\[^\\w\\s]\\"\n') +}) + +tap.test('ignores escaped backslashes in string values (singleLine option)', async t => { + const str = prettifyObject({ + log: { foo_regexp: '\\[^\\w\\s]\\' }, + context: { + ...context, + singleLine: true + } + }) + t.equal(str, '{"foo_regexp":"\\[^\\w\\s]\\"}\n') +}) + +tap.test('works with error props', async t => { + const err = Error('Something went wrong') + const serializedError = { + message: err.message, + stack: err.stack + } + const str = prettifyObject({ log: { error: serializedError }, context }) + t.ok(str.startsWith(' error:')) + t.ok(str.includes(' "message": "Something went wrong",')) + t.ok(str.includes(' Error: Something went wrong')) +}) + +tap.test('customPrettifiers gets applied', async t => { + const customPrettifiers = { + foo: v => v.toUpperCase() + } + const str = prettifyObject({ + log: { foo: 'foo' }, + context: { + ...context, + customPrettifiers + } + }) + t.equal(str.startsWith(' foo: FOO'), true) +}) + +tap.test('skips lines omitted by customPrettifiers', async t => { + const customPrettifiers = { + foo: () => { return undefined } + } + const str = prettifyObject({ + log: { foo: 'foo', bar: 'bar' }, + context: { + ...context, + customPrettifiers + } + }) + t.equal(str.includes('bar: "bar"'), true) + t.equal(str.includes('foo: "foo"'), false) +}) + +tap.test('joined lines omits starting eol', async t => { + const str = prettifyObject({ + log: { msg: 'doing work', calls: ['step 1', 'step 2', 'step 3'], level: 30 }, + context: { + ...context, + IDENT: '', + customPrettifiers: { + calls: val => '\n' + val.map(it => ' ' + it).join('\n') + } + } + }) + t.equal(str, [ + 'msg: "doing work"', + 'calls:', + ' step 1', + ' step 2', + ' step 3', + '' + ].join('\n')) +}) + +tap.test('errors skips prettifiers', async t => { + const customPrettifiers = { + err: () => { return 'is_err' } + } + const str = prettifyObject({ + log: { err: Error('boom') }, + context: { + ...context, + customPrettifiers + } + }) + t.equal(str.includes('err: is_err'), true) +}) + +tap.test('errors skips prettifying if no lines are present', async t => { + const customPrettifiers = { + err: () => { return undefined } + } + const str = prettifyObject({ + log: { err: Error('boom') }, + context: { + ...context, + customPrettifiers + } + }) + t.equal(str, '') +}) diff --git a/lib/utils/prettify-time.js b/lib/utils/prettify-time.js new file mode 100644 index 00000000..e876b35f --- /dev/null +++ b/lib/utils/prettify-time.js @@ -0,0 +1,42 @@ +'use strict' + +module.exports = prettifyTime + +const formatTime = require('./format-time') + +/** + * @typedef {object} PrettifyTimeParams + * @property {object} log The log object with the timestamp to be prettified. + * @property {PrettyContext} context The context object built from parsing + * the options. + */ + +/** + * Prettifies a timestamp if the given `log` has either `time`, `timestamp` or custom specified timestamp + * property. + * + * @param {PrettifyTimeParams} input + * + * @returns {undefined|string} If a timestamp property cannot be found then + * `undefined` is returned. Otherwise, the prettified time is returned as a + * string. + */ +function prettifyTime ({ log, context }) { + const { + timestampKey, + translateTime: translateFormat + } = context + const prettifier = context.customPrettifiers?.time + let time = null + + if (timestampKey in log) { + time = log[timestampKey] + } else if ('timestamp' in log) { + time = log.timestamp + } + + if (time === null) return undefined + const output = translateFormat ? formatTime(time, translateFormat) : time + + return prettifier ? prettifier(output) : `[${output}]` +} diff --git a/lib/utils/prettify-time.test.js b/lib/utils/prettify-time.test.js new file mode 100644 index 00000000..cfde6627 --- /dev/null +++ b/lib/utils/prettify-time.test.js @@ -0,0 +1,227 @@ +'use strict' + +process.env.TZ = 'UTC' + +const tap = require('tap') +const prettifyTime = require('./prettify-time') +const { + TIMESTAMP_KEY +} = require('../constants') +const context = { + timestampKey: TIMESTAMP_KEY, + translateTime: true, + customPrettifiers: {} +} + +tap.test('returns `undefined` if `time` or `timestamp` not in log', async t => { + const str = prettifyTime({ log: {}, context }) + t.equal(str, undefined) +}) + +tap.test('returns prettified formatted time from custom field', async t => { + const log = { customtime: 1554642900000 } + let str = prettifyTime({ + log, + context: { + ...context, + timestampKey: 'customtime' + } + }) + t.equal(str, '[13:15:00.000]') + + str = prettifyTime({ + log, + context: { + ...context, + translateTime: false, + timestampKey: 'customtime' + } + }) + t.equal(str, '[1554642900000]') +}) + +tap.test('returns prettified formatted time', async t => { + let log = { time: 1554642900000 } + let str = prettifyTime({ + log, + context: { + ...context + } + }) + t.equal(str, '[13:15:00.000]') + + log = { timestamp: 1554642900000 } + str = prettifyTime({ + log, + context: { + ...context + } + }) + t.equal(str, '[13:15:00.000]') + + log = { time: '2019-04-07T09:15:00.000-04:00' } + str = prettifyTime({ + log, + context: { + ...context + } + }) + t.equal(str, '[13:15:00.000]') + + log = { timestamp: '2019-04-07T09:15:00.000-04:00' } + str = prettifyTime({ + log, + context: { + ...context + } + }) + t.equal(str, '[13:15:00.000]') + + log = { time: 1554642900000 } + str = prettifyTime({ + log, + context: { + ...context, + translateTime: 'd mmm yyyy H:MM' + } + }) + t.equal(str, '[7 Apr 2019 13:15]') + + log = { timestamp: 1554642900000 } + str = prettifyTime({ + log, + context: { + ...context, + translateTime: 'd mmm yyyy H:MM' + } + }) + t.equal(str, '[7 Apr 2019 13:15]') + + log = { time: '2019-04-07T09:15:00.000-04:00' } + str = prettifyTime({ + log, + context: { + ...context, + translateTime: 'd mmm yyyy H:MM' + } + }) + t.equal(str, '[7 Apr 2019 13:15]') + + log = { timestamp: '2019-04-07T09:15:00.000-04:00' } + str = prettifyTime({ + log, + context: { + ...context, + translateTime: 'd mmm yyyy H:MM' + } + }) + t.equal(str, '[7 Apr 2019 13:15]') +}) + +tap.test('passes through value', async t => { + let log = { time: 1554642900000 } + let str = prettifyTime({ + log, + context: { + ...context, + translateTime: undefined + } + }) + t.equal(str, '[1554642900000]') + + log = { timestamp: 1554642900000 } + str = prettifyTime({ + log, + context: { + ...context, + translateTime: undefined + } + }) + t.equal(str, '[1554642900000]') + + log = { time: '2019-04-07T09:15:00.000-04:00' } + str = prettifyTime({ + log, + context: { + ...context, + translateTime: undefined + } + }) + t.equal(str, '[2019-04-07T09:15:00.000-04:00]') + + log = { timestamp: '2019-04-07T09:15:00.000-04:00' } + str = prettifyTime({ + log, + context: { + ...context, + translateTime: undefined + } + }) + t.equal(str, '[2019-04-07T09:15:00.000-04:00]') +}) + +tap.test('handles the 0 timestamp', async t => { + let log = { time: 0 } + let str = prettifyTime({ + log, + context: { + ...context, + translateTime: undefined + } + }) + t.equal(str, '[0]') + + log = { timestamp: 0 } + str = prettifyTime({ + log, + context: { + ...context, + translateTime: undefined + } + }) + t.equal(str, '[0]') +}) + +tap.test('works with epoch as a number or string', (t) => { + t.plan(3) + const epoch = 1522431328992 + const asNumber = prettifyTime({ + log: { time: epoch, msg: 'foo' }, + context: { + ...context, + translateTime: true + } + }) + const asString = prettifyTime({ + log: { time: `${epoch}`, msg: 'foo' }, + context: { + ...context, + translateTime: true + } + }) + const invalid = prettifyTime({ + log: { time: '2 days ago', msg: 'foo' }, + context: { + ...context, + translateTime: true + } + }) + t.same(asString, '[17:35:28.992]') + t.same(asNumber, '[17:35:28.992]') + t.same(invalid, '[2 days ago]') +}) + +tap.test('uses custom prettifier', async t => { + const str = prettifyTime({ + log: { time: 0 }, + context: { + ...context, + customPrettifiers: { + time () { + return 'done' + } + } + } + }) + t.equal(str, 'done') +}) diff --git a/lib/utils/split-property-key.js b/lib/utils/split-property-key.js new file mode 100644 index 00000000..2cba0345 --- /dev/null +++ b/lib/utils/split-property-key.js @@ -0,0 +1,49 @@ +'use strict' + +module.exports = splitPropertyKey + +/** + * Splits the property key delimited by a dot character but not when it is preceded + * by a backslash. + * + * @param {string} key A string identifying the property. + * + * @returns {string[]} Returns a list of string containing each delimited property. + * e.g. `'prop2\.domain\.corp.prop2'` should return [ 'prop2.domain.com', 'prop2' ] + */ +function splitPropertyKey (key) { + const result = [] + let backslash = false + let segment = '' + + for (let i = 0; i < key.length; i++) { + const c = key.charAt(i) + + if (c === '\\') { + backslash = true + continue + } + + if (backslash) { + backslash = false + segment += c + continue + } + + /* Non-escaped dot, push to result */ + if (c === '.') { + result.push(segment) + segment = '' + continue + } + + segment += c + } + + /* Push last entry to result */ + if (segment.length) { + result.push(segment) + } + + return result +} diff --git a/lib/utils/split-property-key.test.js b/lib/utils/split-property-key.test.js new file mode 100644 index 00000000..425f9a06 --- /dev/null +++ b/lib/utils/split-property-key.test.js @@ -0,0 +1,29 @@ +'use strict' + +const tap = require('tap') +const splitPropertyKey = require('./split-property-key') + +tap.test('splitPropertyKey does not change key', async t => { + const result = splitPropertyKey('data1') + t.same(result, ['data1']) +}) + +tap.test('splitPropertyKey splits nested key', async t => { + const result = splitPropertyKey('data1.data2.data-3') + t.same(result, ['data1', 'data2', 'data-3']) +}) + +tap.test('splitPropertyKey splits nested keys ending with a dot', async t => { + const result = splitPropertyKey('data1.data2.data-3.') + t.same(result, ['data1', 'data2', 'data-3']) +}) + +tap.test('splitPropertyKey splits nested escaped key', async t => { + const result = splitPropertyKey('logging\\.domain\\.corp/operation.foo.bar-2') + t.same(result, ['logging.domain.corp/operation', 'foo', 'bar-2']) +}) + +tap.test('splitPropertyKey splits nested escaped key with special characters', async t => { + const result = splitPropertyKey('logging\\.domain\\.corp/operation.!\t@#$%^&*()_+=-<>.bar\\.2') + t.same(result, ['logging.domain.corp/operation', '!\t@#$%^&*()_+=-<>', 'bar.2']) +}) diff --git a/package.json b/package.json index 3d50d5b7..a1f85022 100644 --- a/package.json +++ b/package.json @@ -1,6 +1,6 @@ { "name": "pino-pretty", - "version": "10.1.0", + "version": "10.2.0", "description": "Prettifier for Pino log lines", "type": "commonjs", "main": "index.js", @@ -11,8 +11,10 @@ "scripts": { "ci": "standard && tap --coverage-report=lcovonly && npm run test-types", "lint": "standard | snazzy", - "test": "tap --100 --color", - "test-types": "tsc && tsd" + "test": "tap", + "test-types": "tsc && tsd", + "test:watch": "tap --no-coverage-report -w", + "test:report": "tap --coverage-report=html" }, "repository": { "type": "git", @@ -36,8 +38,8 @@ "dateformat": "^4.6.3", "fast-copy": "^3.0.0", "fast-safe-stringify": "^2.1.1", - "joycon": "^3.1.1", "help-me": "^4.0.1", + "joycon": "^3.1.1", "minimist": "^1.2.6", "on-exit-leak-free": "^2.1.0", "pino-abstract-transport": "^1.0.0", @@ -49,13 +51,14 @@ }, "devDependencies": { "@types/node": "^20.1.0", + "fastbench": "^1.0.1", "pino": "^8.0.0", "pre-commit": "^1.2.2", "rimraf": "^3.0.2", "snazzy": "^9.0.0", "standard": "^17.0.0", "tap": "^16.0.0", - "tsd": "^0.28.0", + "tsd": "^0.29.0", "typescript": "^5.0.2" }, "tsd": { diff --git a/test/error-objects.test.js b/test/error-objects.test.js index 15c11d32..e92e7ddf 100644 --- a/test/error-objects.test.js +++ b/test/error-objects.test.js @@ -313,7 +313,7 @@ test('error like objects tests', (t) => { ' statusCode: 500', ' originalStack: original stack', ' dataBaseSpecificError: {', - ' erroMessage: "some database error message"', + ' errorMessage: "some database error message"', ' evenMoreSpecificStuff: {', ' "someErrorRelatedObject": "error"', ' }', @@ -331,7 +331,7 @@ test('error like objects tests', (t) => { error.statusCode = 500 error.originalStack = 'original stack' error.dataBaseSpecificError = { - erroMessage: 'some database error message', + errorMessage: 'some database error message', evenMoreSpecificStuff: { someErrorRelatedObject: 'error' } diff --git a/test/lib/utils.internals.test.js b/test/lib/utils.internals.test.js deleted file mode 100644 index a0c2ea91..00000000 --- a/test/lib/utils.internals.test.js +++ /dev/null @@ -1,224 +0,0 @@ -'use strict' - -process.env.TZ = 'UTC' - -const tap = require('tap') -const { createCopier } = require('fast-copy') -const stringifySafe = require('fast-safe-stringify') -const { internals } = require('../../lib/utils') -const fastCopy = createCopier({}) - -tap.test('#joinLinesWithIndentation', t => { - t.test('joinLinesWithIndentation adds indentation to beginning of subsequent lines', async t => { - const input = 'foo\nbar\nbaz' - const result = internals.joinLinesWithIndentation({ input }) - t.equal(result, 'foo\n bar\n baz') - }) - - t.test('joinLinesWithIndentation accepts custom indentation, line breaks, and eol', async t => { - const input = 'foo\nbar\r\nbaz' - const result = internals.joinLinesWithIndentation({ input, ident: ' ', eol: '^' }) - t.equal(result, 'foo^ bar^ baz') - }) - - t.end() -}) - -tap.test('#formatTime', t => { - const dateStr = '2019-04-06T13:30:00.000-04:00' - const epoch = new Date(dateStr) - const epochMS = epoch.getTime() - - t.test('passes through epoch if `translateTime` is `false`', async t => { - const formattedTime = internals.formatTime(epochMS) - t.equal(formattedTime, epochMS) - }) - - t.test('translates epoch milliseconds if `translateTime` is `true`', async t => { - const formattedTime = internals.formatTime(epochMS, true) - t.equal(formattedTime, '17:30:00.000') - }) - - t.test('translates epoch milliseconds to UTC string given format', async t => { - const formattedTime = internals.formatTime(epochMS, 'd mmm yyyy H:MM') - t.equal(formattedTime, '6 Apr 2019 17:30') - }) - - t.test('translates epoch milliseconds to SYS:STANDARD', async t => { - const formattedTime = internals.formatTime(epochMS, 'SYS:STANDARD') - t.match(formattedTime, /\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}\.\d{3} [-+]?\d{4}/) - }) - - t.test('translates epoch milliseconds to SYS:', async t => { - const formattedTime = internals.formatTime(epochMS, 'SYS:d mmm yyyy H:MM') - t.match(formattedTime, /\d{1} \w{3} \d{4} \d{1,2}:\d{2}/) - }) - - t.test('passes through date string if `translateTime` is `false`', async t => { - const formattedTime = internals.formatTime(dateStr) - t.equal(formattedTime, dateStr) - }) - - t.test('translates date string if `translateTime` is `true`', async t => { - const formattedTime = internals.formatTime(dateStr, true) - t.equal(formattedTime, '17:30:00.000') - }) - - t.test('translates date string to UTC string given format', async t => { - const formattedTime = internals.formatTime(dateStr, 'd mmm yyyy H:MM') - t.equal(formattedTime, '6 Apr 2019 17:30') - }) - - t.test('translates date string to SYS:STANDARD', async t => { - const formattedTime = internals.formatTime(dateStr, 'SYS:STANDARD') - t.match(formattedTime, /\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}\.\d{3} [-+]?\d{4}/) - }) - - t.test('translates date string to UTC:', async t => { - const formattedTime = internals.formatTime(dateStr, 'UTC:d mmm yyyy H:MM') - t.equal(formattedTime, '6 Apr 2019 17:30') - }) - - t.test('translates date string to SYS:', async t => { - const formattedTime = internals.formatTime(dateStr, 'SYS:d mmm yyyy H:MM') - t.match(formattedTime, /\d{1} \w{3} \d{4} \d{1,2}:\d{2}/) - }) - - t.end() -}) - -tap.test('#createDate', t => { - const wanted = 1624450038567 - - t.test('accepts arguments the Date constructor would accept', async t => { - t.plan(2) - t.same(internals.createDate(1624450038567).getTime(), wanted) - t.same(internals.createDate('2021-06-23T12:07:18.567Z').getTime(), wanted) - }) - - t.test('accepts epoch as a string', async t => { - // If Date() accepts this argument, the createDate function is not needed - // and can be replaced with Date() - t.plan(2) - t.notSame(new Date('16244500385-67').getTime(), wanted) - t.same(internals.createDate('1624450038567').getTime(), wanted) - }) - - t.end() -}) - -tap.test('#isValidDate', t => { - t.test('returns true for valid dates', async t => { - t.same(internals.isValidDate(new Date()), true) - }) - - t.test('returns false for non-dates and invalid dates', async t => { - t.plan(2) - t.same(internals.isValidDate('20210621'), false) - t.same(internals.isValidDate(new Date('2021-41-99')), false) - }) - - t.end() -}) - -tap.test('#prettifyError', t => { - t.test('prettifies error', t => { - const error = Error('Bad error!') - const lines = stringifySafe(error, Object.getOwnPropertyNames(error), 2) - - const prettyError = internals.prettifyError({ keyName: 'errorKey', lines, ident: ' ', eol: '\n' }) - t.match(prettyError, /\s*errorKey: {\n\s*"stack":[\s\S]*"message": "Bad error!"/) - t.end() - }) - - t.end() -}) - -tap.test('#deleteLogProperty', t => { - const logData = { - level: 30, - data1: { - data2: { 'data-3': 'bar' } - } - } - - t.test('deleteLogProperty deletes property of depth 1', async t => { - const log = fastCopy(logData) - internals.deleteLogProperty(log, 'data1') - t.same(log, { level: 30 }) - }) - - t.test('deleteLogProperty deletes property of depth 2', async t => { - const log = fastCopy(logData) - internals.deleteLogProperty(log, 'data1.data2') - t.same(log, { level: 30, data1: { } }) - }) - - t.test('deleteLogProperty deletes property of depth 3', async t => { - const log = fastCopy(logData) - internals.deleteLogProperty(log, 'data1.data2.data-3') - t.same(log, { level: 30, data1: { data2: { } } }) - }) - - t.end() -}) - -tap.test('#splitPropertyKey', t => { - t.test('splitPropertyKey does not change key', async t => { - const result = internals.splitPropertyKey('data1') - t.same(result, ['data1']) - }) - - t.test('splitPropertyKey splits nested key', async t => { - const result = internals.splitPropertyKey('data1.data2.data-3') - t.same(result, ['data1', 'data2', 'data-3']) - }) - - t.test('splitPropertyKey splits nested keys ending with a dot', async t => { - const result = internals.splitPropertyKey('data1.data2.data-3.') - t.same(result, ['data1', 'data2', 'data-3']) - }) - - t.test('splitPropertyKey splits nested escaped key', async t => { - const result = internals.splitPropertyKey('logging\\.domain\\.corp/operation.foo.bar-2') - t.same(result, ['logging.domain.corp/operation', 'foo', 'bar-2']) - }) - - t.test('splitPropertyKey splits nested escaped key with special characters', async t => { - const result = internals.splitPropertyKey('logging\\.domain\\.corp/operation.!\t@#$%^&*()_+=-<>.bar\\.2') - t.same(result, ['logging.domain.corp/operation', '!\t@#$%^&*()_+=-<>', 'bar.2']) - }) - - t.end() -}) - -tap.test('#getPropertyValue', t => { - t.test('getPropertyValue returns the value of the property', async t => { - const result = internals.getPropertyValue({ - foo: 'bar' - }, 'foo') - t.same(result, 'bar') - }) - - t.test('getPropertyValue returns the value of the nested property', async t => { - const result = internals.getPropertyValue({ extra: { foo: { value: 'bar' } } }, 'extra.foo.value') - t.same(result, 'bar') - }) - - t.test('getPropertyValue returns the value of the nested property using the array of nested property keys', async t => { - const result = internals.getPropertyValue({ extra: { foo: { value: 'bar' } } }, ['extra', 'foo', 'value']) - t.same(result, 'bar') - }) - - t.test('getPropertyValue returns undefined for non-existing properties', async t => { - const result = internals.getPropertyValue({ extra: { foo: { value: 'bar' } } }, 'extra.foo.value-2') - t.same(result, undefined) - }) - - t.test('getPropertyValue returns undefined for non-existing properties using the array of nested property keys', async t => { - const result = internals.getPropertyValue({ extra: { foo: { value: 'bar' } } }, ['extra', 'foo', 'value-2']) - t.same(result, undefined) - }) - - t.end() -}) diff --git a/test/lib/utils.public.test.js b/test/lib/utils.public.test.js deleted file mode 100644 index c6b20e2c..00000000 --- a/test/lib/utils.public.test.js +++ /dev/null @@ -1,629 +0,0 @@ -'use strict' - -process.env.TZ = 'UTC' - -const tap = require('tap') -const getColorizer = require('../../lib/colors') -const utils = require('../../lib/utils') -const rimraf = require('rimraf') -const { join } = require('path') -const fs = require('fs') - -tap.test('prettifyErrorLog', t => { - const { prettifyErrorLog } = utils - - t.test('returns string with default settings', async t => { - const err = Error('Something went wrong') - const str = prettifyErrorLog({ log: err }) - t.ok(str.startsWith(' Error: Something went wrong')) - }) - - t.test('returns string with custom ident', async t => { - const err = Error('Something went wrong') - const str = prettifyErrorLog({ log: err, ident: ' ' }) - t.ok(str.startsWith(' Error: Something went wrong')) - }) - - t.test('returns string with custom eol', async t => { - const err = Error('Something went wrong') - const str = prettifyErrorLog({ log: err, eol: '\r\n' }) - t.ok(str.startsWith(' Error: Something went wrong\r\n')) - }) - - t.end() -}) - -tap.test('prettifyLevel', t => { - const { prettifyLevel } = utils - - t.test('returns `undefined` for unknown level', async t => { - const colorized = prettifyLevel({ log: {} }) - t.equal(colorized, undefined) - }) - - t.test('returns non-colorized value for default colorizer', async t => { - const log = { - level: 30 - } - const colorized = prettifyLevel({ log }) - t.equal(colorized, 'INFO') - }) - - t.test('returns colorized value for color colorizer', async t => { - const log = { - level: 30 - } - const colorizer = getColorizer(true) - const colorized = prettifyLevel({ log, colorizer }) - t.equal(colorized, '\u001B[32mINFO\u001B[39m') - }) - - t.end() -}) - -tap.test('prettifyMessage', t => { - const { prettifyMessage } = utils - - t.test('returns `undefined` if `messageKey` not found', async t => { - const str = prettifyMessage({ log: {} }) - t.equal(str, undefined) - }) - - t.test('returns `undefined` if `messageKey` not string', async t => { - const str = prettifyMessage({ log: { msg: {} } }) - t.equal(str, undefined) - }) - - t.test('returns non-colorized value for default colorizer', async t => { - const str = prettifyMessage({ log: { msg: 'foo' } }) - t.equal(str, 'foo') - }) - - t.test('returns non-colorized value for alternate `messageKey`', async t => { - const str = prettifyMessage({ log: { message: 'foo' }, messageKey: 'message' }) - t.equal(str, 'foo') - }) - - t.test('returns colorized value for color colorizer', async t => { - const colorizer = getColorizer(true) - const str = prettifyMessage({ log: { msg: 'foo' }, colorizer }) - t.equal(str, '\u001B[36mfoo\u001B[39m') - }) - - t.test('returns colorized value for color colorizer for alternate `messageKey`', async t => { - const colorizer = getColorizer(true) - const str = prettifyMessage({ log: { message: 'foo' }, messageKey: 'message', colorizer }) - t.equal(str, '\u001B[36mfoo\u001B[39m') - }) - - t.test('returns message formatted by `messageFormat` option', async t => { - const str = prettifyMessage({ log: { msg: 'foo', context: 'appModule' }, messageFormat: '{context} - {msg}' }) - t.equal(str, 'appModule - foo') - }) - - t.test('returns message formatted by `messageFormat` option - missing prop', async t => { - const str = prettifyMessage({ log: { context: 'appModule' }, messageFormat: '{context} - {msg}' }) - t.equal(str, 'appModule - ') - }) - - t.test('returns message formatted by `messageFormat` option - levelLabel & useOnlyCustomProps false', async t => { - const str = prettifyMessage({ log: { msg: 'foo', context: 'appModule', level: 30 }, messageFormat: '[{level}] {levelLabel} {context} - {msg}', customLevels: {} }) - t.equal(str, '[30] INFO appModule - foo') - }) - - t.test('returns message formatted by `messageFormat` option - levelLabel & useOnlyCustomProps true', async t => { - const str = prettifyMessage({ log: { msg: 'foo', context: 'appModule', level: 30 }, messageFormat: '[{level}] {levelLabel} {context} - {msg}', customLevels: { 30: 'CHECK' }, useOnlyCustomProps: true }) - t.equal(str, '[30] CHECK appModule - foo') - }) - - t.test('returns message formatted by `messageFormat` option - levelLabel & customLevels', async t => { - const str = prettifyMessage({ log: { msg: 'foo', context: 'appModule', level: 123 }, messageFormat: '[{level}] {levelLabel} {context} - {msg}', customLevels: { 123: 'CUSTOM' } }) - t.equal(str, '[123] CUSTOM appModule - foo') - }) - - t.test('returns message formatted by `messageFormat` option - levelLabel, customLevels & useOnlyCustomProps', async t => { - const str = prettifyMessage({ log: { msg: 'foo', context: 'appModule', level: 123 }, messageFormat: '[{level}] {levelLabel} {context} - {msg}', customLevels: { 123: 'CUSTOM' }, useOnlyCustomProps: true }) - t.equal(str, '[123] CUSTOM appModule - foo') - }) - - t.test('returns message formatted by `messageFormat` option - levelLabel, customLevels & useOnlyCustomProps false', async t => { - const str = prettifyMessage({ log: { msg: 'foo', context: 'appModule', level: 40 }, messageFormat: '[{level}] {levelLabel} {context} - {msg}', customLevels: { 123: 'CUSTOM' }, useOnlyCustomProps: false }) - t.equal(str, '[40] WARN appModule - foo') - }) - - t.test('`messageFormat` supports nested curly brackets', async t => { - const str = prettifyMessage({ log: { level: 30 }, messageFormat: '{{level}}-{level}-{{level}-{level}}' }) - t.equal(str, '{30}-30-{30-30}') - }) - - t.test('`messageFormat` supports nested object', async t => { - const str = prettifyMessage({ log: { level: 30, request: { url: 'localhost/test' }, msg: 'foo' }, messageFormat: '{request.url} - param: {request.params.process} - {msg}' }) - t.equal(str, 'localhost/test - param: - foo') - }) - - t.test('`messageFormat` supports function definition', async t => { - const str = prettifyMessage({ - log: { level: 30, request: { url: 'localhost/test' }, msg: 'incoming request' }, - messageFormat: (log, messageKey, levelLabel) => { - let msg = log[messageKey] - if (msg === 'incoming request') msg = `--> ${log.request.url}` - return msg - } - }) - t.equal(str, '--> localhost/test') - }) - - t.end() -}) - -tap.test('prettifyMetadata', t => { - const { prettifyMetadata } = utils - - t.test('returns `undefined` if no metadata present', async t => { - const str = prettifyMetadata({ log: {} }) - t.equal(str, undefined) - }) - - t.test('works with only `name` present', async t => { - const str = prettifyMetadata({ log: { name: 'foo' } }) - t.equal(str, '(foo)') - }) - - t.test('works with only `pid` present', async t => { - const str = prettifyMetadata({ log: { pid: '1234' } }) - t.equal(str, '(1234)') - }) - - t.test('works with only `hostname` present', async t => { - const str = prettifyMetadata({ log: { hostname: 'bar' } }) - t.equal(str, '(on bar)') - }) - - t.test('works with only `name` & `pid` present', async t => { - const str = prettifyMetadata({ log: { name: 'foo', pid: '1234' } }) - t.equal(str, '(foo/1234)') - }) - - t.test('works with only `name` & `hostname` present', async t => { - const str = prettifyMetadata({ log: { name: 'foo', hostname: 'bar' } }) - t.equal(str, '(foo on bar)') - }) - - t.test('works with only `pid` & `hostname` present', async t => { - const str = prettifyMetadata({ log: { pid: '1234', hostname: 'bar' } }) - t.equal(str, '(1234 on bar)') - }) - - t.test('works with only `name`, `pid`, & `hostname` present', async t => { - const str = prettifyMetadata({ log: { name: 'foo', pid: '1234', hostname: 'bar' } }) - t.equal(str, '(foo/1234 on bar)') - }) - - t.test('works with only `name` & `caller` present', async t => { - const str = prettifyMetadata({ log: { name: 'foo', caller: 'baz' } }) - t.equal(str, '(foo) ') - }) - - t.test('works with only `pid` & `caller` present', async t => { - const str = prettifyMetadata({ log: { pid: '1234', caller: 'baz' } }) - t.equal(str, '(1234) ') - }) - - t.test('works with only `hostname` & `caller` present', async t => { - const str = prettifyMetadata({ log: { hostname: 'bar', caller: 'baz' } }) - t.equal(str, '(on bar) ') - }) - - t.test('works with only `name`, `pid`, & `caller` present', async t => { - const str = prettifyMetadata({ log: { name: 'foo', pid: '1234', caller: 'baz' } }) - t.equal(str, '(foo/1234) ') - }) - - t.test('works with only `name`, `hostname`, & `caller` present', async t => { - const str = prettifyMetadata({ log: { name: 'foo', hostname: 'bar', caller: 'baz' } }) - t.equal(str, '(foo on bar) ') - }) - - t.test('works with only `caller` present', async t => { - const str = prettifyMetadata({ log: { caller: 'baz' } }) - t.equal(str, '') - }) - - t.test('works with only `pid`, `hostname`, & `caller` present', async t => { - const str = prettifyMetadata({ log: { pid: '1234', hostname: 'bar', caller: 'baz' } }) - t.equal(str, '(1234 on bar) ') - }) - - t.test('works with all four present', async t => { - const str = prettifyMetadata({ log: { name: 'foo', pid: '1234', hostname: 'bar', caller: 'baz' } }) - t.equal(str, '(foo/1234 on bar) ') - }) - - t.end() -}) - -tap.test('prettifyObject', t => { - const { prettifyObject } = utils - - t.test('returns empty string if no properties present', async t => { - const str = prettifyObject({ input: {} }) - t.equal(str, '') - }) - - t.test('works with single level properties', async t => { - const str = prettifyObject({ input: { foo: 'bar' } }) - t.equal(str, ' foo: "bar"\n') - }) - - t.test('works with multiple level properties', async t => { - const str = prettifyObject({ input: { foo: { bar: 'baz' } } }) - t.equal(str, ' foo: {\n "bar": "baz"\n }\n') - }) - - t.test('skips specified keys', async t => { - const str = prettifyObject({ input: { foo: 'bar', hello: 'world' }, skipKeys: ['foo'] }) - t.equal(str, ' hello: "world"\n') - }) - - t.test('ignores predefined keys', async t => { - const str = prettifyObject({ input: { foo: 'bar', pid: 12345 } }) - t.equal(str, ' foo: "bar"\n') - }) - - t.test('ignores escaped backslashes in string values', async t => { - const str = prettifyObject({ input: { foo_regexp: '\\[^\\w\\s]\\' } }) - t.equal(str, ' foo_regexp: "\\[^\\w\\s]\\"\n') - }) - - t.test('ignores escaped backslashes in string values (singleLine option)', async t => { - const str = prettifyObject({ input: { foo_regexp: '\\[^\\w\\s]\\' }, singleLine: true }) - t.equal(str, '{"foo_regexp":"\\[^\\w\\s]\\"}\n') - }) - - t.test('works with error props', async t => { - const err = Error('Something went wrong') - const serializedError = { - message: err.message, - stack: err.stack - } - const str = prettifyObject({ input: { error: serializedError } }) - t.ok(str.startsWith(' error:')) - t.ok(str.includes(' "message": "Something went wrong",')) - t.ok(str.includes(' Error: Something went wrong')) - }) - - t.end() -}) - -tap.test('prettifyTime', t => { - const { prettifyTime } = utils - - t.test('returns `undefined` if `time` or `timestamp` not in log', async t => { - const str = prettifyTime({ log: {} }) - t.equal(str, undefined) - }) - - t.test('returns prettified formatted time from custom field', async t => { - const log = { customtime: 1554642900000 } - let str = prettifyTime({ log, translateFormat: true, timestampKey: 'customtime' }) - t.equal(str, '[13:15:00.000]') - - str = prettifyTime({ log, translateFormat: false, timestampKey: 'customtime' }) - t.equal(str, '[1554642900000]') - }) - - t.test('returns prettified formatted time', async t => { - let log = { time: 1554642900000 } - let str = prettifyTime({ log, translateFormat: true }) - t.equal(str, '[13:15:00.000]') - - log = { timestamp: 1554642900000 } - str = prettifyTime({ log, translateFormat: true }) - t.equal(str, '[13:15:00.000]') - - log = { time: '2019-04-07T09:15:00.000-04:00' } - str = prettifyTime({ log, translateFormat: true }) - t.equal(str, '[13:15:00.000]') - - log = { timestamp: '2019-04-07T09:15:00.000-04:00' } - str = prettifyTime({ log, translateFormat: true }) - t.equal(str, '[13:15:00.000]') - - log = { time: 1554642900000 } - str = prettifyTime({ log, translateFormat: 'd mmm yyyy H:MM' }) - t.equal(str, '[7 Apr 2019 13:15]') - - log = { timestamp: 1554642900000 } - str = prettifyTime({ log, translateFormat: 'd mmm yyyy H:MM' }) - t.equal(str, '[7 Apr 2019 13:15]') - - log = { time: '2019-04-07T09:15:00.000-04:00' } - str = prettifyTime({ log, translateFormat: 'd mmm yyyy H:MM' }) - t.equal(str, '[7 Apr 2019 13:15]') - - log = { timestamp: '2019-04-07T09:15:00.000-04:00' } - str = prettifyTime({ log, translateFormat: 'd mmm yyyy H:MM' }) - t.equal(str, '[7 Apr 2019 13:15]') - }) - - t.test('passes through value', async t => { - let log = { time: 1554642900000 } - let str = prettifyTime({ log }) - t.equal(str, '[1554642900000]') - - log = { timestamp: 1554642900000 } - str = prettifyTime({ log }) - t.equal(str, '[1554642900000]') - - log = { time: '2019-04-07T09:15:00.000-04:00' } - str = prettifyTime({ log }) - t.equal(str, '[2019-04-07T09:15:00.000-04:00]') - - log = { timestamp: '2019-04-07T09:15:00.000-04:00' } - str = prettifyTime({ log }) - t.equal(str, '[2019-04-07T09:15:00.000-04:00]') - }) - - t.test('handles the 0 timestamp', async t => { - let log = { time: 0 } - let str = prettifyTime({ log }) - t.equal(str, '[0]') - - log = { timestamp: 0 } - str = prettifyTime({ log }) - t.equal(str, '[0]') - }) - - t.test('works with epoch as a number or string', (t) => { - t.plan(3) - const epoch = 1522431328992 - const asNumber = prettifyTime({ - log: { time: epoch, msg: 'foo' }, - translateFormat: true - }) - const asString = prettifyTime({ - log: { time: `${epoch}`, msg: 'foo' }, - translateFormat: true - }) - const invalid = prettifyTime({ - log: { time: '2 days ago', msg: 'foo' }, - translateFormat: true - }) - t.same(asString, '[17:35:28.992]') - t.same(asNumber, '[17:35:28.992]') - t.same(invalid, '[2 days ago]') - }) - - t.end() -}) - -const logData = { - level: 30, - time: 1522431328992, - data1: { - data2: { 'data-3': 'bar' }, - error: new Error('test') - } -} -const logData2 = Object.assign({ - 'logging.domain.corp/operation': { - id: 'foo', - producer: 'bar' - } -}, logData) - -tap.test('#filterLog with an ignoreKeys option', t => { - const { filterLog } = utils - - t.test('filterLog removes single entry', async t => { - const result = filterLog({ log: logData, ignoreKeys: ['data1.data2.data-3'] }) - t.same(result, { level: 30, time: 1522431328992, data1: { data2: { }, error: new Error('test') } }) - }) - - t.test('filterLog removes multiple entries', async t => { - const result = filterLog({ log: logData, ignoreKeys: ['time', 'data1'] }) - t.same(result, { level: 30 }) - }) - - t.test('filterLog keeps error instance', async t => { - const result = filterLog({ log: logData, ignoreKeys: [] }) - t.equal(logData.data1.error, result.data1.error) - }) - - t.test('filterLog removes entry with escape sequence', async t => { - const result = filterLog({ log: logData2, ignoreKeys: ['data1', 'logging\\.domain\\.corp/operation'] }) - t.same(result, { level: 30, time: 1522431328992 }) - }) - - t.test('filterLog removes entry with escape sequence nested', async t => { - const result = filterLog({ log: logData2, ignoreKeys: ['data1', 'logging\\.domain\\.corp/operation.producer'] }) - t.same(result, { level: 30, time: 1522431328992, 'logging.domain.corp/operation': { id: 'foo' } }) - }) - - t.end() -}) - -const ignoreKeysArray = [ - undefined, - ['level'], - ['level', 'data1.data2.data-3'] -] -ignoreKeysArray.forEach(ignoreKeys => { - tap.test(`#filterLog with an includeKeys option when the ignoreKeys being ${ignoreKeys}`, t => { - const { filterLog } = utils - - t.test('filterLog include nothing', async t => { - const result = filterLog({ log: logData, ignoreKeys, includeKeys: [] }) - t.same(result, {}) - }) - - t.test('filterLog include single entry', async t => { - const result = filterLog({ log: logData, ignoreKeys, includeKeys: ['time'] }) - t.same(result, { time: 1522431328992 }) - }) - - t.test('filterLog include multiple entries', async t => { - const result = filterLog({ log: logData, ignoreKeys, includeKeys: ['time', 'data1'] }) - t.same(result, { - time: 1522431328992, - data1: { - data2: { 'data-3': 'bar' }, - error: new Error('test') - } - }) - }) - - t.end() - }) -}) - -tap.test('#filterLog with circular references', t => { - const { filterLog } = utils - const logData = { - level: 30, - time: 1522431328992, - data1: 'test' - } - logData.circular = logData - - t.test('filterLog removes single entry', async t => { - const result = filterLog({ log: logData, ignoreKeys: ['data1'] }) - - t.same(result.circular.level, result.level) - t.same(result.circular.time, result.time) - - delete result.circular - t.same(result, { level: 30, time: 1522431328992 }) - }) - - t.test('filterLog includes single entry', async t => { - const result = filterLog({ log: logData, includeKeys: ['data1'] }) - - t.same(result, { data1: 'test' }) - }) - - t.test('filterLog includes circular keys', async t => { - const result = filterLog({ log: logData, includeKeys: ['level', 'circular'] }) - - t.same(result.circular.level, logData.level) - t.same(result.circular.time, logData.time) - - delete result.circular - t.same(result, { level: 30 }) - }) - - t.end() -}) - -tap.test('buildSafeSonicBoom', t => { - const { buildSafeSonicBoom } = utils - - function noop () {} - - const file = () => { - const dest = join(__dirname, `${process.pid}-${process.hrtime().toString()}`) - const fd = fs.openSync(dest, 'w') - return { dest, fd } - } - - t.test('should not write when error emitted and code is "EPIPE"', async t => { - t.plan(1) - - const { fd, dest } = file() - const stream = buildSafeSonicBoom({ sync: true, fd, mkdir: true }) - t.teardown(() => rimraf(dest, noop)) - - stream.emit('error', { code: 'EPIPE' }) - stream.write('will not work') - - const dataFile = fs.readFileSync(dest) - t.equal(dataFile.length, 0) - }) - - t.test('should stream.write works when error code is not "EPIPE"', async t => { - t.plan(3) - const { fd, dest } = file() - const stream = buildSafeSonicBoom({ sync: true, fd, mkdir: true }) - - t.teardown(() => rimraf(dest, noop)) - - stream.on('error', () => t.pass('error emitted')) - - stream.emit('error', 'fake error description') - - t.ok(stream.write('will work')) - - const dataFile = fs.readFileSync(dest) - t.equal(dataFile.toString(), 'will work') - }) - - t.end() -}) - -tap.test('handleCustomlevelsOpts', t => { - const { handleCustomlevelsOpts } = utils - - t.test('returns a empty object `{}` for unknown parameter', async t => { - const handledCustomLevel = handleCustomlevelsOpts(123) - t.same(handledCustomLevel, {}) - }) - - t.test('returns a filled object for string parameter', async t => { - const handledCustomLevel = handleCustomlevelsOpts('ok:10,warn:20,error:35') - t.same(handledCustomLevel, { - 10: 'OK', - 20: 'WARN', - 35: 'ERROR', - default: 'USERLVL' - }) - }) - - t.test('returns a filled object for object parameter', async t => { - const handledCustomLevel = handleCustomlevelsOpts({ - ok: 10, - warn: 20, - error: 35 - }) - t.same(handledCustomLevel, { - 10: 'OK', - 20: 'WARN', - 35: 'ERROR', - default: 'USERLVL' - }) - }) - - t.end() -}) - -tap.test('handleCustomlevelNamesOpts', t => { - const { handleCustomlevelNamesOpts } = utils - - t.test('returns a empty object `{}` for unknown parameter', async t => { - const handledCustomLevelNames = handleCustomlevelNamesOpts(123) - t.same(handledCustomLevelNames, {}) - }) - - t.test('returns a filled object for string parameter', async t => { - const handledCustomLevelNames = handleCustomlevelNamesOpts('ok:10,warn:20,error:35') - t.same(handledCustomLevelNames, { - ok: 10, - warn: 20, - error: 35 - }) - }) - - t.test('returns a filled object for object parameter', async t => { - const handledCustomLevelNames = handleCustomlevelNamesOpts({ - ok: 10, - warn: 20, - error: 35 - }) - t.same(handledCustomLevelNames, { - ok: 10, - warn: 20, - error: 35 - }) - }) - - t.end() -})