From 396a4de469e9657e8a3c78da52d82b578917b4c2 Mon Sep 17 00:00:00 2001 From: Pawel Soltys Date: Sat, 27 Aug 2022 21:58:26 +0200 Subject: [PATCH] FEAT: patternLayout function name, class name and function alias Added to patternLayout the following fields: - %M - function name of the caller issuing the logging request - %C - class name of the caller issuing the logging request - %A - function alias of the caller issuing the logging request The first two come from log4j, and use the same field specifiers. When called from method bar of a Class foo: - %M will be replaced with bar - %C will be replaced with Foo - %A will be empty When called from function foo: - %M will be replaced with foo - %C will be empty - %A will be empty %A will be non empty only if the call stack parsed to obtain the values contains string [as foo]. --- docs/layouts.md | 3 + lib/LoggingEvent.js | 2 + lib/layouts.js | 20 +++- lib/logger.js | 19 +++- test/tap/LoggingEvent-test.js | 184 ++++++++++++++++++++++++++++++++++ test/tap/layouts-test.js | 50 ++++++++- test/tap/logger-test.js | 41 ++++++++ 7 files changed, 316 insertions(+), 3 deletions(-) diff --git a/docs/layouts.md b/docs/layouts.md index fae80d1..fb77028 100644 --- a/docs/layouts.md +++ b/docs/layouts.md @@ -143,6 +143,9 @@ Fields can be any of: - `%l` line number (requires `enableCallStack: true` on the category, see [configuration object](api.md)) - `%o` column postion (requires `enableCallStack: true` on the category, see [configuration object](api.md)) - `%s` call stack (requires `enableCallStack: true` on the category, see [configuration object](api.md)) +- `%M` function or method name (requires `enableCallStack: true` on the category, see [configuration object](api.md)) +- `%C` class name (requires `enableCallStack: true` on the category, see [configuration object](api.md)) +- `%A` function or method name alias (requires `enableCallStack: true` on the category, see [configuration object](api.md)) - `%x{}` add dynamic tokens to your log. Tokens are specified in the tokens parameter. - `%X{}` add values from the Logger context. Tokens are keys into the context values. - `%[` start a coloured block (colour will be taken from the log level, similar to `colouredLayout`) diff --git a/lib/LoggingEvent.js b/lib/LoggingEvent.js index a3dff7a..34901fc 100644 --- a/lib/LoggingEvent.js +++ b/lib/LoggingEvent.js @@ -28,6 +28,8 @@ class LoggingEvent { this.lineNumber = location.lineNumber; this.columnNumber = location.columnNumber; this.callStack = location.callStack; + this.className = location.className; + this.functionAlias = location.functionAlias; } } diff --git a/lib/layouts.js b/lib/layouts.js index 8884162..33de098 100644 --- a/lib/layouts.js +++ b/lib/layouts.js @@ -109,6 +109,9 @@ function dummyLayout(loggingEvent) { * - %l line number * - %o column postion * - %s call stack + * - %M method or function name + * - %C class name + * - %A method or function name * - %x{} add dynamic tokens to your log. Tokens are specified in the tokens parameter * - %X{} add dynamic tokens to your log. Tokens are specified in logger context * You can use %[ and %] to define a colored block. @@ -130,7 +133,7 @@ function dummyLayout(loggingEvent) { */ function patternLayout(pattern, tokens) { const TTCC_CONVERSION_PATTERN = '%r %p %c - %m%n'; - const regex = /%(-?[0-9]+)?(\.?-?[0-9]+)?([[\]cdhmnprzxXyflos%])(\{([^}]+)\})?|([^%]+)/; + const regex = /%(-?[0-9]+)?(\.?-?[0-9]+)?([[\]cdhmnprzxXyflosMCA%])(\{([^}]+)\})?|([^%]+)/; pattern = pattern || TTCC_CONVERSION_PATTERN; @@ -322,6 +325,18 @@ function patternLayout(pattern, tokens) { return loggingEvent.callStack || ''; } + function functionName(loggingEvent) { + return loggingEvent.functionName || ''; + } + + function className(loggingEvent) { + return loggingEvent.className || ''; + } + + function functionAlias(loggingEvent) { + return loggingEvent.functionAlias || ''; + } + const replacers = { c: categoryName, d: formatAsDate, @@ -341,6 +356,9 @@ function patternLayout(pattern, tokens) { l: lineNumber, o: columnNumber, s: callStack, + M: functionName, + C: className, + A: functionAlias, }; function replaceToken(conversionCharacter, loggingEvent, specifier) { diff --git a/lib/logger.js b/lib/logger.js index d979caf..4ee3457 100644 --- a/lib/logger.js +++ b/lib/logger.js @@ -15,12 +15,29 @@ function defaultParseCallStack(data, skipIdx = 4) { const lineMatch = stackReg.exec(stacklines[0]); /* istanbul ignore else: failsafe */ if (lineMatch && lineMatch.length === 6) { + // extract class, function and alias names + let className = ''; + let functionName = ''; + let functionAlias = ''; + if (lineMatch[1] && lineMatch[1] !== '') { + // WARN: this will unset alias if alias is not present. + [functionName, functionAlias] = lineMatch[1] + .replace(/[[\]]/g, '') + .split(' as '); + functionAlias = functionAlias || ''; + + if (functionName.includes('.')) + [className, functionName] = functionName.split('.'); + } + return { - functionName: lineMatch[1], + functionName, fileName: lineMatch[2], lineNumber: parseInt(lineMatch[3], 10), columnNumber: parseInt(lineMatch[4], 10), callStack: stacklines.join('\n'), + className, + functionAlias, }; // eslint-disable-next-line no-else-return } else { diff --git a/test/tap/LoggingEvent-test.js b/test/tap/LoggingEvent-test.js index f3cd49e..7cb28e5 100644 --- a/test/tap/LoggingEvent-test.js +++ b/test/tap/LoggingEvent-test.js @@ -97,5 +97,189 @@ test('LoggingEvent', (batch) => { t.end(); }); + batch.test('Should contain function name', (t) => { + // console.log([Error('123').stack.split('\n').slice(1).join('\n')]) + const callStack = + ' at foo (repl:1:14)\n at ContextifyScript.Script.runInThisContext (vm.js:50:33)\n at REPLServer.defaultEval (repl.js:240:29)\n at bound (domain.js:301:14)\n at REPLServer.runBound [as eval] (domain.js:314:12)\n at REPLServer.onLine (repl.js:468:10)\n at emitOne (events.js:121:20)\n at REPLServer.emit (events.js:211:7)\n at REPLServer.Interface._onLine (readline.js:280:10)\n at REPLServer.Interface._line (readline.js:629:8)'; // eslint-disable-line max-len + const fileName = '/log4js-node/test/tap/layouts-test.js'; + const lineNumber = 1; + const columnNumber = 14; + const functionName = 'foo'; + const className = ''; + const functionAlias = ''; + const location = { + functionName, + fileName, + lineNumber, + columnNumber, + callStack, + className, + functionAlias, + }; + const event = new LoggingEvent( + 'cheese', + levels.DEBUG, + ['log message'], + { user: 'bob' }, + location + ); + t.equal(event.functionName, functionName); + t.equal(event.fileName, fileName); + t.equal(event.lineNumber, lineNumber); + t.equal(event.columnNumber, columnNumber); + t.equal(event.callStack, callStack); + t.equal(event.className, ''); + t.equal(event.functionAlias, ''); + + const event2 = new LoggingEvent('cheese', levels.DEBUG, ['log message'], { + user: 'bob', + }); + t.equal(event2.functionName, undefined); + t.equal(event2.fileName, undefined); + t.equal(event2.lineNumber, undefined); + t.equal(event2.columnNumber, undefined); + t.equal(event2.callStack, undefined); + t.end(); + }); + + batch.test('Should contain function name and alias', (t) => { + // console.log([Error('123').stack.split('\n').slice(1).join('\n')]) + const callStack = + ' at foo [as bar] (repl:1:14)\n at ContextifyScript.Script.runInThisContext (vm.js:50:33)\n at REPLServer.defaultEval (repl.js:240:29)\n at bound (domain.js:301:14)\n at REPLServer.runBound [as eval] (domain.js:314:12)\n at REPLServer.onLine (repl.js:468:10)\n at emitOne (events.js:121:20)\n at REPLServer.emit (events.js:211:7)\n at REPLServer.Interface._onLine (readline.js:280:10)\n at REPLServer.Interface._line (readline.js:629:8)'; // eslint-disable-line max-len + const fileName = '/log4js-node/test/tap/layouts-test.js'; + const lineNumber = 1; + const columnNumber = 14; + const functionName = 'foo'; + const functionAlias = 'bar'; + const className = ''; + const location = { + functionName, + fileName, + lineNumber, + columnNumber, + callStack, + className, + functionAlias, + }; + const event = new LoggingEvent( + 'cheese', + levels.DEBUG, + ['log message'], + { user: 'bob' }, + location + ); + t.equal(event.functionName, functionName); + t.equal(event.fileName, fileName); + t.equal(event.lineNumber, lineNumber); + t.equal(event.columnNumber, columnNumber); + t.equal(event.callStack, callStack); + t.equal(event.className, ''); + t.equal(event.functionAlias, functionAlias); + + const event2 = new LoggingEvent('cheese', levels.DEBUG, ['log message'], { + user: 'bob', + }); + t.equal(event2.functionName, undefined); + t.equal(event2.fileName, undefined); + t.equal(event2.lineNumber, undefined); + t.equal(event2.columnNumber, undefined); + t.equal(event2.callStack, undefined); + t.equal(event2.functionAlias, undefined); + t.end(); + }); + + batch.test('Should contain class and method names', (t) => { + // console.log([Error('123').stack.split('\n').slice(1).join('\n')]) + const callStack = + ' at Foo.bar (repl:1:14)\n at ContextifyScript.Script.runInThisContext (vm.js:50:33)\n at REPLServer.defaultEval (repl.js:240:29)\n at bound (domain.js:301:14)\n at REPLServer.runBound [as eval] (domain.js:314:12)\n at REPLServer.onLine (repl.js:468:10)\n at emitOne (events.js:121:20)\n at REPLServer.emit (events.js:211:7)\n at REPLServer.Interface._onLine (readline.js:280:10)\n at REPLServer.Interface._line (readline.js:629:8)'; // eslint-disable-line max-len + const fileName = '/log4js-node/test/tap/layouts-test.js'; + const lineNumber = 1; + const columnNumber = 14; + const className = 'Foo'; + const functionName = 'bar'; + const functionAlias = ''; + const location = { + functionName, + fileName, + lineNumber, + columnNumber, + callStack, + className, + functionAlias, + }; + const event = new LoggingEvent( + 'cheese', + levels.DEBUG, + ['log message'], + { user: 'bob' }, + location + ); + t.equal(event.functionName, functionName); + t.equal(event.fileName, fileName); + t.equal(event.lineNumber, lineNumber); + t.equal(event.columnNumber, columnNumber); + t.equal(event.callStack, callStack); + t.equal(event.className, className); + t.equal(event.functionAlias, ''); + + const event2 = new LoggingEvent('cheese', levels.DEBUG, ['log message'], { + user: 'bob', + }); + t.equal(event2.functionName, undefined); + t.equal(event2.fileName, undefined); + t.equal(event2.lineNumber, undefined); + t.equal(event2.columnNumber, undefined); + t.equal(event2.callStack, undefined); + t.equal(event2.className, undefined); + t.end(); + }); + + batch.test('Should contain class, method and alias names', (t) => { + // console.log([Error('123').stack.split('\n').slice(1).join('\n')]) + const callStack = + ' at Foo.bar [as baz] (repl:1:14)\n at ContextifyScript.Script.runInThisContext (vm.js:50:33)\n at REPLServer.defaultEval (repl.js:240:29)\n at bound (domain.js:301:14)\n at REPLServer.runBound [as eval] (domain.js:314:12)\n at REPLServer.onLine (repl.js:468:10)\n at emitOne (events.js:121:20)\n at REPLServer.emit (events.js:211:7)\n at REPLServer.Interface._onLine (readline.js:280:10)\n at REPLServer.Interface._line (readline.js:629:8)'; // eslint-disable-line max-len + const fileName = '/log4js-node/test/tap/layouts-test.js'; + const lineNumber = 1; + const columnNumber = 14; + const className = 'Foo'; + const functionName = 'bar'; + const functionAlias = 'baz'; + const location = { + functionName, + fileName, + lineNumber, + columnNumber, + callStack, + className, + functionAlias, + }; + const event = new LoggingEvent( + 'cheese', + levels.DEBUG, + ['log message'], + { user: 'bob' }, + location + ); + t.equal(event.functionName, functionName); + t.equal(event.fileName, fileName); + t.equal(event.lineNumber, lineNumber); + t.equal(event.columnNumber, columnNumber); + t.equal(event.callStack, callStack); + t.equal(event.className, className); + t.equal(event.functionAlias, functionAlias); + + const event2 = new LoggingEvent('cheese', levels.DEBUG, ['log message'], { + user: 'bob', + }); + t.equal(event2.functionName, undefined); + t.equal(event2.fileName, undefined); + t.equal(event2.lineNumber, undefined); + t.equal(event2.columnNumber, undefined); + t.equal(event2.callStack, undefined); + t.equal(event2.className, undefined); + t.equal(event2.functionAlias, undefined); + t.end(); + }); + batch.end(); }); diff --git a/test/tap/layouts-test.js b/test/tap/layouts-test.js index f240eec..13cec8c 100644 --- a/test/tap/layouts-test.js +++ b/test/tap/layouts-test.js @@ -300,10 +300,13 @@ test('log4js layouts', (batch) => { // console.log([Error('123').stack.split('\n').slice(1).join('\n')]) const callStack = - ' at repl:1:14\n at ContextifyScript.Script.runInThisContext (vm.js:50:33)\n at REPLServer.defaultEval (repl.js:240:29)\n at bound (domain.js:301:14)\n at REPLServer.runBound [as eval] (domain.js:314:12)\n at REPLServer.onLine (repl.js:468:10)\n at emitOne (events.js:121:20)\n at REPLServer.emit (events.js:211:7)\n at REPLServer.Interface._onLine (readline.js:280:10)\n at REPLServer.Interface._line (readline.js:629:8)'; // eslint-disable-line max-len + ' at Foo.bar [as baz] (repl:1:14)\n at ContextifyScript.Script.runInThisContext (vm.js:50:33)\n at REPLServer.defaultEval (repl.js:240:29)\n at bound (domain.js:301:14)\n at REPLServer.runBound [as eval] (domain.js:314:12)\n at REPLServer.onLine (repl.js:468:10)\n at emitOne (events.js:121:20)\n at REPLServer.emit (events.js:211:7)\n at REPLServer.Interface._onLine (readline.js:280:10)\n at REPLServer.Interface._line (readline.js:629:8)'; // eslint-disable-line max-len const fileName = path.normalize('/log4js-node/test/tap/layouts-test.js'); const lineNumber = 1; const columnNumber = 14; + const className = 'Foo'; + const functionName = 'bar'; + const functionAlias = 'baz'; const event = { data: ['this is a test'], startTime: new Date('2010-12-05 14:18:30.045'), @@ -321,6 +324,9 @@ test('log4js layouts', (batch) => { fileName, lineNumber, columnNumber, + className, + functionName, + functionAlias, }; event.startTime.getTimezoneOffset = () => -600; @@ -886,6 +892,48 @@ test('log4js layouts', (batch) => { assert.end(); }); + t.test('%M should output function name', (assert) => { + testPattern(assert, layout, event, tokens, '%M', functionName); + assert.end(); + }); + + t.test( + '%M should output empty string when functionName not exist', + (assert) => { + delete event.functionName; + testPattern(assert, layout, event, tokens, '%M', ''); + assert.end(); + } + ); + + t.test('%C should output class name', (assert) => { + testPattern(assert, layout, event, tokens, '%C', className); + assert.end(); + }); + + t.test( + '%C should output empty string when className not exist', + (assert) => { + delete event.className; + testPattern(assert, layout, event, tokens, '%C', ''); + assert.end(); + } + ); + + t.test('%A should output function alias', (assert) => { + testPattern(assert, layout, event, tokens, '%A', functionAlias); + assert.end(); + }); + + t.test( + '%A should output empty string when functionAlias not exist', + (assert) => { + delete event.functionAlias; + testPattern(assert, layout, event, tokens, '%A', ''); + assert.end(); + } + ); + t.end(); }); diff --git a/test/tap/logger-test.js b/test/tap/logger-test.js index 3baa296..00426d5 100644 --- a/test/tap/logger-test.js +++ b/test/tap/logger-test.js @@ -253,6 +253,47 @@ test('../../lib/logger', (batch) => { t.end(); }); + batch.test('parseCallStack names extraction', (t) => { + const logger = new Logger('stack'); + logger.useCallStack = true; + + let results; + + const callStack1 = + ' at Foo.bar [as baz] (repl:1:14)\n at ContextifyScript.Script.runInThisContext (vm.js:50:33)\n at REPLServer.defaultEval (repl.js:240:29)\n at bound (domain.js:301:14)\n at REPLServer.runBound [as eval] (domain.js:314:12)\n at REPLServer.onLine (repl.js:468:10)\n at emitOne (events.js:121:20)\n at REPLServer.emit (events.js:211:7)\n at REPLServer.Interface._onLine (readline.js:280:10)\n at REPLServer.Interface._line (readline.js:629:8)'; // eslint-disable-line max-len + results = logger.parseCallStack({ stack: callStack1 }, 0); + t.ok(results); + t.equal(results.className, 'Foo'); + t.equal(results.functionName, 'bar'); + t.equal(results.functionAlias, 'baz'); + + const callStack2 = + ' at bar [as baz] (repl:1:14)\n at ContextifyScript.Script.runInThisContext (vm.js:50:33)\n at REPLServer.defaultEval (repl.js:240:29)\n at bound (domain.js:301:14)\n at REPLServer.runBound [as eval] (domain.js:314:12)\n at REPLServer.onLine (repl.js:468:10)\n at emitOne (events.js:121:20)\n at REPLServer.emit (events.js:211:7)\n at REPLServer.Interface._onLine (readline.js:280:10)\n at REPLServer.Interface._line (readline.js:629:8)'; // eslint-disable-line max-len + results = logger.parseCallStack({ stack: callStack2 }, 0); + t.ok(results); + t.equal(results.className, ''); + t.equal(results.functionName, 'bar'); + t.equal(results.functionAlias, 'baz'); + + const callStack3 = + ' at bar (repl:1:14)\n at ContextifyScript.Script.runInThisContext (vm.js:50:33)\n at REPLServer.defaultEval (repl.js:240:29)\n at bound (domain.js:301:14)\n at REPLServer.runBound [as eval] (domain.js:314:12)\n at REPLServer.onLine (repl.js:468:10)\n at emitOne (events.js:121:20)\n at REPLServer.emit (events.js:211:7)\n at REPLServer.Interface._onLine (readline.js:280:10)\n at REPLServer.Interface._line (readline.js:629:8)'; // eslint-disable-line max-len + results = logger.parseCallStack({ stack: callStack3 }, 0); + t.ok(results); + t.equal(results.className, ''); + t.equal(results.functionName, 'bar'); + t.equal(results.functionAlias, ''); + + const callStack4 = + ' at repl:1:14\n at ContextifyScript.Script.runInThisContext (vm.js:50:33)\n at REPLServer.defaultEval (repl.js:240:29)\n at bound (domain.js:301:14)\n at REPLServer.runBound [as eval] (domain.js:314:12)\n at REPLServer.onLine (repl.js:468:10)\n at emitOne (events.js:121:20)\n at REPLServer.emit (events.js:211:7)\n at REPLServer.Interface._onLine (readline.js:280:10)\n at REPLServer.Interface._line (readline.js:629:8)'; // eslint-disable-line max-len + results = logger.parseCallStack({ stack: callStack4 }, 0); + t.ok(results); + t.equal(results.className, ''); + t.equal(results.functionName, ''); + t.equal(results.functionAlias, ''); + + t.end(); + }); + batch.test('should correctly change the parseCallStack function', (t) => { const logger = new Logger('stack'); const parseFunction = function() {