From 570bc1a98c1ffdb7d6ef0158cb7fb262fc2a9e76 Mon Sep 17 00:00:00 2001 From: tagyoureit Date: Sun, 10 Mar 2019 22:32:18 -0700 Subject: [PATCH] splat refactor and add metadataArray --- README.md | 74 +++++++++++++++++++++-- index.js | 1 + metadata.js | 14 +++++ metadataArray.js | 52 +++++++++++++++++ splat.js | 57 +++++------------- test/metadata.test.js | 26 +++++++++ test/metadataArray.test.js | 117 +++++++++++++++++++++++++++++++++++++ test/splat.test.js | 24 ++++---- 8 files changed, 306 insertions(+), 59 deletions(-) create mode 100644 metadataArray.js create mode 100644 test/metadataArray.test.js diff --git a/README.md b/README.md index 4d9a8e7..442f33f 100644 --- a/README.md +++ b/README.md @@ -27,6 +27,7 @@ const alignedWithColorsAndTime = format.combine( - [Label](#label) - [Logstash](#logstash) - [Metadata](#metadata) + - [Metadata Array](#metadataArray) - [PadLevels](#padlevels) - [PrettyPrint](#prettyprint) - [Printf](#printf) @@ -451,6 +452,8 @@ It accepts the following options: * **fillExcept**: An array of keys that should not be added to the metadata object. * **fillWith**: An array of keys that will be added to the metadata object. +Do not use this simultaneously with metadataArray as they both process the same information differently. The key/values pairs must be subsequently exposed with json() or a custom printf() format. + ```js const { format } = require('logform'); @@ -464,6 +467,71 @@ const info = metadataFormat.transform({ console.log(info); // { level: 'info', message: 'my message', metadata: { meta: 42 } } + +const info2 = metadataFormat.transform({ + level: 'info', + message: 'my message', + [SPLAT]: [{meta: 42}] +}); + +// above could be written with Winston as: +// logger.info('my message', {meta: 42}) + +console.log(info2); +// { level: 'info', message: 'my message', metadata: { meta: 42 } } +``` + +### Metadata Array + +The `metadataArray` format stringifies metadata (info[SPLAT]) into info.message. It will stringify Errors, objects/arrays, and other data types found in info[SPLAT]. +It accepts the following options: + +* **messageSplatDelimeter**: A string to separate the meassage from the splat. Defaults to ` `. +* **innerSplatDelimeter**: A delimeter to be used to separate multiple splat. Defaults to `, `. + +This works well in conjunction with splat. Splat will now take any "extra" matadata and leave it in info[SPLAT]. Do not use this simultaneously with metadata as they both process the same information differently. +```js +logger.info("my message %s", "should be one", {an:"object"}) +/* after splat transform; + info: { + level: "info", + message: "my message should be one", + [SPLAT]: [{an:"object"}] + } +*/ +``` + +```js +const { format } = require('logform'); + +const metadataArray = format.metadataArray(); + +const info = metadataArray.transform({ + level: 'info', + message: 'my message', + [SPLAT]: [{an:"object"}] +}); + +console.log(info); +// { level: 'info', message: 'my message {"an":"object"} } + +const info2 = metadataArray.transform({ + level: 'info', + message: 'my message', + [SPLAT]: [{an:"object"}, [1, 2, 3], throw new('my bad!')] +}, { messageSplatDelimeter = ' ', innerSplatDelimeter = ', ' }); + +console.log(info); +// { level: 'info', message: 'my message:\n\t{"an":"object"}\n\t[1, 2, 3]} +// printed info.message... +/* +info: my message: + {"an":"object"} + [1, 2, 3] + Error: my bad! + at {...rest of stack} +*/ + ``` ### PadLevels @@ -580,8 +648,7 @@ console.log(info); ``` Any additional splat parameters beyond those needed for the `%` tokens -(aka "metas") are assumed to be objects. Their enumerable properties are -merged into the `info`. +are left in info[SPLAT] in an array for later processing. (See metadata or metadataArray) ```js const { format } = require('logform'); @@ -597,8 +664,7 @@ const info = splatFormat.transform({ console.log(info); // { level: 'info', // message: 'my message test', -// thisIsMeta: true, -// splat: [ 'test' ] } +// [SPLAT]: [{thisIsMeta: true}], ``` This was previously exposed implicitly in `winston < 3.0.0`. diff --git a/index.js b/index.js index 2e663aa..2b93a1a 100644 --- a/index.js +++ b/index.js @@ -51,3 +51,4 @@ exposeFormat('simple'); exposeFormat('splat'); exposeFormat('timestamp'); exposeFormat('uncolorize'); +exposeFormat('metadataArray'); diff --git a/metadata.js b/metadata.js index dc796db..7f8fc0b 100644 --- a/metadata.js +++ b/metadata.js @@ -1,6 +1,7 @@ 'use strict'; const format = require('./format'); +const { SPLAT } = require('triple-beam'); function fillExcept(info, fillExceptKeys, metadataKey) { const savedKeys = fillExceptKeys.reduce((acc, key) => { @@ -34,11 +35,24 @@ function fillWith(info, fillWithKeys, metadataKey) { * object in winston 2.x. */ module.exports = format((info, opts = {}) => { + + let metadataKey = 'metadata'; if (opts.key) { metadataKey = opts.key; } + // this assists with situations where the hotpath is not taken + // and the user provides 1+ object in the format + // logger.info('message', obj1, obj2, etc) + // Logger.js#234 will push obj1, obj2, etc to info[SPLAT] + const splat = info[SPLAT] || []; + if (splat.length) { + splat.forEach((item) => { + Object.assign(info, item); + }); + } + let fillExceptKeys = []; if (!opts.fillExcept && !opts.fillWith) { fillExceptKeys.push('level'); diff --git a/metadataArray.js b/metadataArray.js new file mode 100644 index 0000000..d1a9346 --- /dev/null +++ b/metadataArray.js @@ -0,0 +1,52 @@ +'use strict'; + +const { SPLAT } = require('triple-beam'); +const format = require('./format'); +const jsonStringify = require('fast-safe-stringify'); + +/** + * Transforms the `info` object by adding info[meta] from any + * unused info[SPLAT] items. + * + * @param {Info} info Logform info message. + * @param {Object} opts Options for this instance. + * @returns {Info} Modified info message + */ + +module.exports = format((info, { messageSplatDelimeter = ' ', innerSplatDelimeter = ', ' }) => { + // not including info.splat here because if the user takes the hot path + // they will most likely not (aka shouldn't) include additional objects inside splat + const splat = info[SPLAT] || []; + + // if no splat, return + if ((!splat.length)) { + return info; + + } + + let splatStringified = ''; + info[SPLAT].forEach(function (el, idx) { + // add delimeter before al elements after the first + if (idx !== 0) { + splatStringified += innerSplatDelimeter; + } + // we can even parse for errors + if (el instanceof Error) { + splatStringified += `${el.stack}`; + } else if (typeof el === 'object') { + // standard string/array objects + splatStringified += jsonStringify(el); + } else { + // strings, numbers, etc + splatStringified += el; + } + + }); + info.message = `${info.message}${messageSplatDelimeter}${splatStringified}`; + delete info[SPLAT]; + return info; + + +}); + + diff --git a/splat.js b/splat.js index 08ff6f7..2b693e0 100644 --- a/splat.js +++ b/splat.js @@ -52,23 +52,11 @@ class Splatter { // metas = [100, 'wow', { such: 'js' }, { thisIsMeta: true }].splice(-1, -1 * -1); // splat = [100, 'wow', { such: 'js' }] const expectedSplat = tokens.length - escapes; - const extraSplat = expectedSplat - splat.length; - const metas = extraSplat < 0 - ? splat.splice(extraSplat, -1 * extraSplat) + const splatMerge = expectedSplat > 0 + ? splat.splice(0, expectedSplat) : []; - // Now that { splat } has been separated from any potential { meta }. we - // can assign this to the `info` object and write it to our format stream. - // If the additional metas are **NOT** objects or **LACK** enumerable properties - // you are going to have a bad time. - const metalen = metas.length; - if (metalen) { - for (let i = 0; i < metalen; i++) { - Object.assign(info, metas[i]); - } - } - - info.message = util.format(msg, ...splat); + info.message = util.format(msg, ...splatMerge); return info; } @@ -82,44 +70,31 @@ class Splatter { * @returns {Info} Modified info message */ transform(info) { + // look for info.mesasge fist. if it isn't set then set it from info[MESSAGE] const msg = info.message; - const splat = info[SPLAT] || info.splat; - - // No need to process anything if splat is undefined - if (!splat || !splat.length) { - return info; + // info[SPLAT] will be preset if user uses logger.log('level', 'message', ...) + // info.splat will be used in hot path (eg logger.log({level: 'level', message: 'msg %s', splat: 'string'})) + let splat = info[SPLAT] || info.splat; + // following checks if hotpath is taken and splat is not passed in an array + if (!Array.isArray(splat)) { + splat = [splat]; + // and write back to info object so we don't need to check twice (once here, once in _splat) + info[SPLAT] = splat; } // Extract tokens, if none available default to empty array to // ensure consistancy in expected results const tokens = msg && msg.match && msg.match(formatRegExp); - // This condition will take care of inputs with info[SPLAT] - // but no tokens present - if (!tokens && (splat || splat.length)) { - const metas = splat.length > 1 - ? splat.splice(0) - : splat; - - // Now that { splat } has been separated from any potential { meta }. we - // can assign this to the `info` object and write it to our format stream. - // If the additional metas are **NOT** objects or **LACK** enumerable properties - // you are going to have a bad time. - const metalen = metas.length; - if (metalen) { - for (let i = 0; i < metalen; i++) { - Object.assign(info, metas[i]); - } - } + // No need to process anything if splat is undefined + if (!splat || !splat.length || !tokens) { return info; } - if (tokens) { - return this._splat(info, tokens); - } + return this._splat(info, tokens); + - return info; } } diff --git a/test/metadata.test.js b/test/metadata.test.js index 3098fec..bca62fa 100644 --- a/test/metadata.test.js +++ b/test/metadata.test.js @@ -3,6 +3,7 @@ const assume = require('assume'); const metadata = require('../metadata'); const helpers = require('./helpers'); +const { SPLAT } = require('triple-beam'); describe('metadata', () => { const testInfoObject = { @@ -14,6 +15,17 @@ describe('metadata', () => { } }; + const testInfoObjectSplat = { + level: 'info', + message: 'whatever', + [SPLAT]: [{ someKey: 'someValue' }, + { + someObject: { + key: 'value' + } + }] + }; + it('metadata() (default) removes message and level and puts everything else into metadata', helpers.assumeFormatted( metadata(), testInfoObject, @@ -27,6 +39,19 @@ describe('metadata', () => { } )); + it('[SPLAT]: metadata() (default) removes message and level and puts everything else into metadata', helpers.assumeFormatted( + metadata(), + testInfoObjectSplat, + info => { + assume(info.level).is.a('string'); + assume(info.message).is.a('string'); + assume(info.metadata).is.a('object'); + assume(info.metadata.someKey).equals('someValue'); + assume(info.metadata.someObject).is.a('object'); + assume(info.metadata.someObject.key).equals('value'); + } + )); + it('metadata({ fillWith: [keys] }) only adds specified keys to the metadata object', helpers.assumeFormatted( metadata({ fillWith: ['level', 'someObject'] }), testInfoObject, @@ -68,4 +93,5 @@ describe('metadata', () => { assume(info.myCustomKey.level).equals('info'); } )); + }); diff --git a/test/metadataArray.test.js b/test/metadataArray.test.js new file mode 100644 index 0000000..d542e40 --- /dev/null +++ b/test/metadataArray.test.js @@ -0,0 +1,117 @@ +'use strict'; + +const assume = require('assume'); +const metadataArray = require('../metadataArray'); +const helpers = require('./helpers'); +const { MESSAGE, SPLAT } = require('triple-beam'); + +describe('metadataArray', () => { + + it('metadataArray() does nothing with no splat', + helpers.assumeFormatted( + metadataArray(), + { level: 'info', message: 'whatever' }, + info => { + assume(info.level).is.a('string'); + assume(info.message).is.a('string'); + assume(info.level).equals('info'); + assume(info.message).equals('whatever'); + assume(info[MESSAGE]).equals(undefined); + assume(info[SPLAT]).equals(undefined); + } + )); + + it('metadataArray() captures a single splat', helpers.assumeFormatted( + metadataArray(), + { level: 'info', message: 'whatever', [SPLAT]: [1, 2, 3] }, + info => { + assume(info.level).is.a('string'); + assume(info.message).is.a('string'); + assume(info.level).equals('info'); + assume(info.message).equals('whatever 1, 2, 3'); + assume(info[SPLAT]).equals(undefined); + } + )); + + it('metadataArray() ignores { rest }', helpers.assumeFormatted( + metadataArray(), + { level: 'info', message: 'whatever', rest: 'something', [SPLAT]: [{ an: 'object' }] }, + info => { + assume(info.level).is.a('string'); + assume(info.message).is.a('string'); + assume(info.rest).is.an('string'); + assume(info.level).equals('info'); + assume(info.message).equals('whatever {"an":"object"}'); + assume(info.rest).equals('something'); + assume(info[SPLAT]).deep.equals(undefined); + } + )); + + + + it('metadataArray() captures multiple splat', helpers.assumeFormatted( + metadataArray(), + { level: 'info', message: 'whatever', [SPLAT]: [{ an: 'object' }, ['an', 'array']] }, + info => { + assume(info.level).is.a('string'); + assume(info.message).is.a('string'); + assume(info.level).equals('info'); + assume(info.message).equals('whatever {"an":"object"}, ["an","array"]'); + assume(info[SPLAT]).deep.equals(undefined); + } + )); + + it('metadataArray() captures an info.splat passed in an object', helpers.assumeFormatted( + metadataArray(), + { level: 'info', message: 'whatever', splat: [{ an: 'object' }, ['an', 'array']] }, + info => { + assume(info.level).is.a('string'); + assume(info.message).is.a('string'); + assume(info.level).equals('info'); + assume(info.message).equals('whatever'); + assume(info[SPLAT]).equals(undefined); + assume(Array.isArray(info.splat)).true(); + assume(info.splat).deep.equals([{ an: 'object' }, ['an', 'array']]); + } + )); + + it('metadataArray() captures multiple splat and info.splat', helpers.assumeFormatted( + metadataArray(), + { level: 'info', message: 'whatever', [SPLAT]: [{ an: 'object' }, ['an', 'array']], splat: { another: 'object' }}, + info => { + assume(info.level).is.a('string'); + assume(info.message).is.a('string'); + assume(info.level).equals('info'); + assume(info.message).equals('whatever {"an":"object"}, ["an","array"]'); + assume(info[SPLAT]).deep.equals(undefined); + assume(info.splat).deep.equals({ another: 'object' }); + + } + )); + + it('metadataArray() captures multiple splat and info.splat', helpers.assumeFormatted( + metadataArray(), + { level: 'info', message: 'whatever', [SPLAT]: [{ an: 'object' }, ['an', 'array'], new Error('Catch me')] }, + info => { + assume(info.level).is.a('string'); + assume(info.message).is.a('string'); + assume(info.level).equals('info'); + assume(info.message.substring(0, 79)).equals('whatever {"an":"object"}, ["an","array"], Error: Catch me\n at Suite.describe'); + assume(info[SPLAT]).deep.equals(undefined); + } + )); + + it('metadataArray() captures multiple splat and info.splat', helpers.assumeFormatted( + metadataArray({ messageSplatDelimeter: ':', innerSplatDelimeter: '\n\t' }), + { level: 'info', message: 'whatever', [SPLAT]: [{ an: 'object' }, ['an', 'array']] }, + info => { + assume(info.level).is.a('string'); + assume(info.message).is.a('string'); + assume(info.level).equals('info'); + assume(info.message).equals('whatever:{"an":"object"}\n\t["an","array"]'); + assume(info[SPLAT]).deep.equals(undefined); + } + )); + + +}); diff --git a/test/splat.test.js b/test/splat.test.js index b039628..ce2f6c5 100644 --- a/test/splat.test.js +++ b/test/splat.test.js @@ -46,19 +46,17 @@ describe('splat', () => { 'test %j', [{ number: 123 }], 'test {"number":123}' )); - it('balanced number of arguments to % | does not have "meta"', assumeSplat( + it('balanced number of arguments to % | does not have "metadata"', assumeSplat( 'test %j', [{ number: 123 }], info => { assume(info.message).equals('test {"number":123}'); - assume(info.meta).equals(undefined); + assume(info[SPLAT]).deep.equals([]); } )); - it('more arguments than % | multiple "meta"', assumeSplat( + it('more arguments than % | multiple "metadata"', assumeSplat( 'test %j', [{ number: 123 }, { an: 'object' }, ['an', 'array']], info => { assume(info.message).equals('test {"number":123}'); - assume(info.an).equals('object'); - assume(info[0]).equals('an'); - assume(info[1]).equals('array'); + assume(info[SPLAT]).deep.equals([{ an: 'object' }, ['an', 'array']]); } )); @@ -69,31 +67,29 @@ describe('splat', () => { it('no % and one object | returns the message and properties', assumeSplat( 'see an object', [{ an: 'object' }], info => { assume(info.message).equals('see an object'); - assume(info.an).equals('object'); + assume(info[SPLAT]).deep.equals([{ an: 'object' }]); } )); it('no % and two objects | returns the string and all properties', assumeSplat( 'lots to see here', [{ an: 'object' }, ['an', 'array']], info => { assume(info.message).equals('lots to see here'); - assume(info.an).equals('object'); - assume(info[0]).equals('an'); - assume(info[1]).equals('array'); + assume(info[SPLAT]).deep.equals([{ an: 'object' }, ['an', 'array']]); } )); it('no % and no splat | returns the same info', assumeSplat( 'nothing to see here', [], info => { assume(info.message).equals('nothing to see here'); - assume(info.meta).equals(undefined); + assume(info[SPLAT]).deep.equals([]); } )); it('no % but some splat | returns the same message with new properties', assumeSplat( 'Look! No tokens!', ['ok'], info => { assume(info.message).equals('Look! No tokens!'); - assume(info[0]).equals('o'); - assume(info[1]).equals('k'); + assume(info[SPLAT]).deep.equals(['ok']); + } )); @@ -102,7 +98,7 @@ describe('splat', () => { ['Hi', 42, 'feeling', { today: true }], info => { assume(info.message).equals('Hi #42, how are you feeling'); - assume(info.today).true(); + assume(info[SPLAT]).deep.equals([{ today: true }]); } ));