From 396a4de469e9657e8a3c78da52d82b578917b4c2 Mon Sep 17 00:00:00 2001 From: Pawel Soltys Date: Sat, 27 Aug 2022 21:58:26 +0200 Subject: [PATCH 1/7] 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() { From 03b3f5087065a7f444a52b6db0363a8037652d9f Mon Sep 17 00:00:00 2001 From: Pawel Soltys Date: Mon, 29 Aug 2022 15:11:04 +0200 Subject: [PATCH 2/7] FEAT: added `%F` field containing fully qualified caller name --- lib/LoggingEvent.js | 4 ++++ lib/layouts.js | 7 +++++- lib/logger.js | 1 + test/tap/LoggingEvent-test.js | 45 +++++++++++++---------------------- test/tap/layouts-test.js | 16 +++++++++++++ test/tap/logger-test.js | 4 ++++ 6 files changed, 47 insertions(+), 30 deletions(-) diff --git a/lib/LoggingEvent.js b/lib/LoggingEvent.js index 34901fc..494da4c 100644 --- a/lib/LoggingEvent.js +++ b/lib/LoggingEvent.js @@ -30,6 +30,7 @@ class LoggingEvent { this.callStack = location.callStack; this.className = location.className; this.functionAlias = location.functionAlias; + this.callerName = location.callerName; } } @@ -81,6 +82,9 @@ class LoggingEvent { lineNumber: rehydratedEvent.lineNumber, columnNumber: rehydratedEvent.columnNumber, callStack: rehydratedEvent.callStack, + className: rehydratedEvent.className, + functionAlias: rehydratedEvent.functionAlias, + callerName: rehydratedEvent.callerName, }; event = new LoggingEvent( rehydratedEvent.categoryName, diff --git a/lib/layouts.js b/lib/layouts.js index 33de098..f9d99e5 100644 --- a/lib/layouts.js +++ b/lib/layouts.js @@ -133,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]+)?([[\]cdhmnprzxXyflosMCA%])(\{([^}]+)\})?|([^%]+)/; + const regex = /%(-?[0-9]+)?(\.?-?[0-9]+)?([[\]cdhmnprzxXyflosMCAF%])(\{([^}]+)\})?|([^%]+)/; pattern = pattern || TTCC_CONVERSION_PATTERN; @@ -337,6 +337,10 @@ function patternLayout(pattern, tokens) { return loggingEvent.functionAlias || ''; } + function callerName(loggingEvent) { + return loggingEvent.callerName || ''; + } + const replacers = { c: categoryName, d: formatAsDate, @@ -359,6 +363,7 @@ function patternLayout(pattern, tokens) { M: functionName, C: className, A: functionAlias, + F: callerName, }; function replaceToken(conversionCharacter, loggingEvent, specifier) { diff --git a/lib/logger.js b/lib/logger.js index 4ee3457..9291e6e 100644 --- a/lib/logger.js +++ b/lib/logger.js @@ -38,6 +38,7 @@ function defaultParseCallStack(data, skipIdx = 4) { callStack: stacklines.join('\n'), className, functionAlias, + callerName: lineMatch[1] || '', }; // eslint-disable-next-line no-else-return } else { diff --git a/test/tap/LoggingEvent-test.js b/test/tap/LoggingEvent-test.js index 7cb28e5..fa133c1 100644 --- a/test/tap/LoggingEvent-test.js +++ b/test/tap/LoggingEvent-test.js @@ -107,6 +107,7 @@ test('LoggingEvent', (batch) => { const functionName = 'foo'; const className = ''; const functionAlias = ''; + const callerName = 'foo'; const location = { functionName, fileName, @@ -115,6 +116,7 @@ test('LoggingEvent', (batch) => { callStack, className, functionAlias, + callerName, }; const event = new LoggingEvent( 'cheese', @@ -130,15 +132,7 @@ test('LoggingEvent', (batch) => { 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.equal(event.callerName, callerName); t.end(); }); @@ -152,6 +146,7 @@ test('LoggingEvent', (batch) => { const functionName = 'foo'; const functionAlias = 'bar'; const className = ''; + const callerName = 'foo [as bar]'; const location = { functionName, fileName, @@ -160,6 +155,7 @@ test('LoggingEvent', (batch) => { callStack, className, functionAlias, + callerName, }; const event = new LoggingEvent( 'cheese', @@ -175,16 +171,7 @@ test('LoggingEvent', (batch) => { 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.equal(event.callerName, callerName); t.end(); }); @@ -198,6 +185,7 @@ test('LoggingEvent', (batch) => { const className = 'Foo'; const functionName = 'bar'; const functionAlias = ''; + const callerName = 'Foo.bar'; const location = { functionName, fileName, @@ -206,6 +194,7 @@ test('LoggingEvent', (batch) => { callStack, className, functionAlias, + callerName, }; const event = new LoggingEvent( 'cheese', @@ -220,17 +209,8 @@ test('LoggingEvent', (batch) => { t.equal(event.columnNumber, columnNumber); t.equal(event.callStack, callStack); t.equal(event.className, className); + t.equal(event.callerName, callerName); 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(); }); @@ -244,6 +224,7 @@ test('LoggingEvent', (batch) => { const className = 'Foo'; const functionName = 'bar'; const functionAlias = 'baz'; + const callerName = 'Foo.bar [as baz]'; const location = { functionName, fileName, @@ -252,6 +233,7 @@ test('LoggingEvent', (batch) => { callStack, className, functionAlias, + callerName, }; const event = new LoggingEvent( 'cheese', @@ -267,7 +249,11 @@ test('LoggingEvent', (batch) => { t.equal(event.callStack, callStack); t.equal(event.className, className); t.equal(event.functionAlias, functionAlias); + t.equal(event.callerName, callerName); + t.end(); + }); + batch.test('Should not contain names if location not provided', (t) => { const event2 = new LoggingEvent('cheese', levels.DEBUG, ['log message'], { user: 'bob', }); @@ -278,6 +264,7 @@ test('LoggingEvent', (batch) => { t.equal(event2.callStack, undefined); t.equal(event2.className, undefined); t.equal(event2.functionAlias, undefined); + t.equal(event2.callerName, undefined); t.end(); }); diff --git a/test/tap/layouts-test.js b/test/tap/layouts-test.js index 13cec8c..c9987a4 100644 --- a/test/tap/layouts-test.js +++ b/test/tap/layouts-test.js @@ -307,6 +307,7 @@ test('log4js layouts', (batch) => { const className = 'Foo'; const functionName = 'bar'; const functionAlias = 'baz'; + const callerName = 'Foo.bar [as baz]'; const event = { data: ['this is a test'], startTime: new Date('2010-12-05 14:18:30.045'), @@ -327,6 +328,7 @@ test('log4js layouts', (batch) => { className, functionName, functionAlias, + callerName, }; event.startTime.getTimezoneOffset = () => -600; @@ -934,6 +936,20 @@ test('log4js layouts', (batch) => { } ); + t.test('%F should output fully qualified caller name', (assert) => { + testPattern(assert, layout, event, tokens, '%F', callerName); + assert.end(); + }); + + t.test( + '%F should output empty string when callerName not exist', + (assert) => { + delete event.callerName; + testPattern(assert, layout, event, tokens, '%F', ''); + assert.end(); + } + ); + t.end(); }); diff --git a/test/tap/logger-test.js b/test/tap/logger-test.js index 00426d5..9c91c5f 100644 --- a/test/tap/logger-test.js +++ b/test/tap/logger-test.js @@ -266,6 +266,7 @@ test('../../lib/logger', (batch) => { t.equal(results.className, 'Foo'); t.equal(results.functionName, 'bar'); t.equal(results.functionAlias, 'baz'); + t.equal(results.callerName, 'Foo.bar [as 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 @@ -274,6 +275,7 @@ test('../../lib/logger', (batch) => { t.equal(results.className, ''); t.equal(results.functionName, 'bar'); t.equal(results.functionAlias, 'baz'); + t.equal(results.callerName, 'bar [as 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 @@ -282,6 +284,7 @@ test('../../lib/logger', (batch) => { t.equal(results.className, ''); t.equal(results.functionName, 'bar'); t.equal(results.functionAlias, ''); + t.equal(results.callerName, 'bar'); 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 @@ -290,6 +293,7 @@ test('../../lib/logger', (batch) => { t.equal(results.className, ''); t.equal(results.functionName, ''); t.equal(results.functionAlias, ''); + t.equal(results.callerName, ''); t.end(); }); From 397b06e15f5a6d485cafdbb141ab80b916eb9004 Mon Sep 17 00:00:00 2001 From: Pawel Soltys Date: Thu, 1 Sep 2022 12:48:10 +0200 Subject: [PATCH 3/7] FEAT: documentation for %F field --- docs/layouts.md | 1 + lib/layouts.js | 1 + 2 files changed, 2 insertions(+) diff --git a/docs/layouts.md b/docs/layouts.md index fb77028..4174110 100644 --- a/docs/layouts.md +++ b/docs/layouts.md @@ -146,6 +146,7 @@ Fields can be any of: - `%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)) +- `%F` fully qualified caller name (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/layouts.js b/lib/layouts.js index f9d99e5..2c01d96 100644 --- a/lib/layouts.js +++ b/lib/layouts.js @@ -112,6 +112,7 @@ function dummyLayout(loggingEvent) { * - %M method or function name * - %C class name * - %A method or function name + * - %F fully qualified caller 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. From 4360da010fffba1c1fcec8b9412df0da6581d8dd Mon Sep 17 00:00:00 2001 From: Pawel Soltys Date: Thu, 1 Sep 2022 12:49:14 +0200 Subject: [PATCH 4/7] FIX: missing test cases for %M, %C, %A and %F fields --- test/tap/LoggingEvent-test.js | 30 +++++++++++++++--------------- test/tap/logger-test.js | 9 +++++++++ 2 files changed, 24 insertions(+), 15 deletions(-) diff --git a/test/tap/LoggingEvent-test.js b/test/tap/LoggingEvent-test.js index fa133c1..150c428 100644 --- a/test/tap/LoggingEvent-test.js +++ b/test/tap/LoggingEvent-test.js @@ -69,11 +69,19 @@ test('LoggingEvent', (batch) => { const fileName = '/log4js-node/test/tap/layouts-test.js'; const lineNumber = 1; const columnNumber = 14; + const className = ''; + const functionName = ''; + const functionAlias = ''; + const callerName = ''; const location = { + functionName, fileName, lineNumber, columnNumber, callStack, + className, + functionAlias, + callerName, }; const event = new LoggingEvent( 'cheese', @@ -82,10 +90,14 @@ test('LoggingEvent', (batch) => { { 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); + t.equal(event.callerName, callerName); const event2 = new LoggingEvent('cheese', levels.DEBUG, ['log message'], { user: 'bob', @@ -94,6 +106,9 @@ test('LoggingEvent', (batch) => { 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.equal(event2.callerName, undefined); t.end(); }); @@ -253,20 +268,5 @@ test('LoggingEvent', (batch) => { t.end(); }); - batch.test('Should not contain names if location not provided', (t) => { - 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.equal(event2.callerName, undefined); - t.end(); - }); - batch.end(); }); diff --git a/test/tap/logger-test.js b/test/tap/logger-test.js index 9c91c5f..2524a3a 100644 --- a/test/tap/logger-test.js +++ b/test/tap/logger-test.js @@ -295,6 +295,15 @@ test('../../lib/logger', (batch) => { t.equal(results.functionAlias, ''); t.equal(results.callerName, ''); + const callStack5 = + ' 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 + results = logger.parseCallStack({ stack: callStack5 }, 0); + t.ok(results); + t.equal(results.className, 'Foo'); + t.equal(results.functionName, 'bar'); + t.equal(results.functionAlias, ''); + t.equal(results.callerName, 'Foo.bar'); + t.end(); }); From 5f988bd097b4b5218fd564a2a1cd0466c5501f0f Mon Sep 17 00:00:00 2001 From: Pawel Soltys Date: Thu, 1 Sep 2022 12:54:26 +0200 Subject: [PATCH 5/7] FIX: remove unneeded test cases --- test/tap/LoggingEvent-test.js | 117 ---------------------------------- 1 file changed, 117 deletions(-) diff --git a/test/tap/LoggingEvent-test.js b/test/tap/LoggingEvent-test.js index 150c428..4fed49c 100644 --- a/test/tap/LoggingEvent-test.js +++ b/test/tap/LoggingEvent-test.js @@ -112,123 +112,6 @@ 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 callerName = 'foo'; - const location = { - functionName, - fileName, - lineNumber, - columnNumber, - callStack, - className, - functionAlias, - callerName, - }; - 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, ''); - t.equal(event.callerName, callerName); - 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 callerName = 'foo [as bar]'; - const location = { - functionName, - fileName, - lineNumber, - columnNumber, - callStack, - className, - functionAlias, - callerName, - }; - 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); - t.equal(event.callerName, callerName); - 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 callerName = 'Foo.bar'; - const location = { - functionName, - fileName, - lineNumber, - columnNumber, - callStack, - className, - functionAlias, - callerName, - }; - 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.callerName, callerName); - t.equal(event.functionAlias, ''); - 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 = From 6ea3e43c62f2d075a335b87967e3b1c8a1b28067 Mon Sep 17 00:00:00 2001 From: Pawel Soltys Date: Thu, 1 Sep 2022 13:02:43 +0200 Subject: [PATCH 6/7] FIX: add missing field to test --- test/tap/LoggingEvent-test.js | 1 + 1 file changed, 1 insertion(+) diff --git a/test/tap/LoggingEvent-test.js b/test/tap/LoggingEvent-test.js index 4fed49c..d7596d5 100644 --- a/test/tap/LoggingEvent-test.js +++ b/test/tap/LoggingEvent-test.js @@ -106,6 +106,7 @@ test('LoggingEvent', (batch) => { t.equal(event2.lineNumber, undefined); t.equal(event2.columnNumber, undefined); t.equal(event2.callStack, undefined); + t.equal(event.functionName, undefined); t.equal(event2.className, undefined); t.equal(event2.functionAlias, undefined); t.equal(event2.callerName, undefined); From dd3051d9edbff32d7198f3ce84fae294697114af Mon Sep 17 00:00:00 2001 From: "Pawel \"l0ner\" Soltys" Date: Thu, 1 Sep 2022 13:10:18 +0200 Subject: [PATCH 7/7] FIX: typo in LoggingEvent test Co-authored-by: Lam Wei Li --- test/tap/LoggingEvent-test.js | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/test/tap/LoggingEvent-test.js b/test/tap/LoggingEvent-test.js index d7596d5..ec4df9f 100644 --- a/test/tap/LoggingEvent-test.js +++ b/test/tap/LoggingEvent-test.js @@ -106,7 +106,7 @@ test('LoggingEvent', (batch) => { t.equal(event2.lineNumber, undefined); t.equal(event2.columnNumber, undefined); t.equal(event2.callStack, undefined); - t.equal(event.functionName, undefined); + t.equal(event2.functionName, undefined); t.equal(event2.className, undefined); t.equal(event2.functionAlias, undefined); t.equal(event2.callerName, undefined);