archive-gh-me/log4js-node
1
0
Fork 0
mirror of https://github.com/log4js-node/log4js-node.git synced 2025-12-08 19:26:01 +00:00
Code Issues Projects Releases Wiki Activity

Merge pull request #1269 from ZachHaber/master

Browse Source 
Add ability to use passed in Errors for callstacks and adjust how deeply you want to look for information
This commit is contained in:
Lam Wei Li 2022-09-30 01:00:13 +08:00 committed by GitHub
commit 916eef11f1
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
6 changed files with 278 additions and 31 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

5
docs/api.md
View File

@ -21,7 +21,7 @@ Properties:
- `categories` (object) - a map of named categories (string) to category definitions (object). You must define the `default` category which is used for all log events that do not match a specific category. Category definitions have two properties:
- `appenders` (array of strings) - the list of appender names to be used for this category. A category must have at least one appender.
- `level` (string, case insensitive) - the minimum log level that this category will send to the appenders. For example, if set to 'error' then the appenders will only receive log events of level 'error', 'fatal', 'mark' - log events of 'info', 'warn', 'debug', or 'trace' will be ignored.
- `enableCallStack` (boolean, optional, defaults to `false`) - setting this to `true` will make log events for this category use the call stack to generate line numbers and file names in the event. See [pattern layout](layouts.md) for how to output these values in your appenders.
- `enableCallStack` (boolean, optional, defaults to `false`) - setting this to `true` will make log events for this category use the call stack to generate line numbers and file names in the event. See [pattern layout](layouts.md) for how to output these values in your appenders. If you log an Error object, that Error object (or the first of many) will be used to generate the line numbers and file name instead.
- `pm2` (boolean) (optional) - set this to true if you're running your app using [pm2](http://pm2.keymetrics.io), otherwise logs will not work (you'll also need to install pm2-intercom as pm2 module: `pm2 install pm2-intercom`)
- `pm2InstanceVar` (string) (optional, defaults to 'NODE_APP_INSTANCE') - set this if you're using pm2 and have changed the default name of the NODE_APP_INSTANCE variable.
- `disableClustering` (boolean) (optional) - set this to true if you liked the way log4js used to just ignore clustered environments, or you're having trouble with PM2 logging. Each worker process will do its own logging. Be careful with this if you're logging to files, weirdness can occur.
@ -35,12 +35,13 @@ This function takes a single optional string argument to denote the category to
- `addContext(<key>,<value>)` - where `<key>` is a string, `<value>` can be anything. This stores a key-value pair that is added to all log events generated by the logger. Uses would be to add ids for tracking a user through your application. Currently only the `logFaces` appenders make use of the context values.
- `removeContext(<key>)` - removes a previously defined key-value pair from the context.
- `clearContext()` - removes all context pairs from the logger.
- `setParseCallStackFunction(function)` - Allow to override the default way to parse the callstack data for the layout pattern, a generic javascript Error object is passed to the function. Must return an object with properties : `functionName` / `fileName` / `lineNumber` / `columnNumber` / `callStack`. Can for example be used if all of your log call are made from one "debug" class and you would to "erase" this class from the callstack to only show the function which called your "debug" class.
- `setParseCallStackFunction(function | undefined)` - Allow to override the default way to parse the callstack data for the layout pattern, a generic javascript Error object is passed to the function. Must return an object with properties : `functionName` / `fileName` / `lineNumber` / `columnNumber` / `callStack`. Can for example be used if all of your log call are made from one "debug" class and you would to "erase" this class from the callstack to only show the function which called your "debug" class. If you pass `undefined` as the argument, it will be reset to the default parser.
The `Logger` object has the following properties:
- `level` - where `level` is a log4js level or a string that matches a level (e.g. 'info', 'INFO', etc). This allows overriding the configured level for this logger. Changing this value applies to all loggers of the same category.
- `useCallStack` - where `useCallStack` is a boolean to indicate if log events for this category use the call stack to generate line numbers and file names in the event. This allows overriding the configured useCallStack for this logger. Changing this value applies to all loggers of the same category.
- `callStackLinesToSkip` - where `callStackLinesToSkip` is a number (0 by default) that allows you to customize how many lines of the call stack should be skipped when parsing the Error stack. For example, if you call the logger from within a dedicated logging function, you can use `callStackLinesToSkip = 1` to ignore that function when looking at stack traces.
## Shutdown - `log4js.shutdown([callback])`

47
lib/LoggingEvent.js
View File

@ -12,15 +12,17 @@ class LoggingEvent {
* @param {string} categoryName name of category
* @param {Log4js.Level} level level of message
* @param {Array} data objects to log
* @param {Error} [error]
* @author Seth Chisamore
*/
constructor(categoryName, level, data, context, location) {
constructor(categoryName, level, data, context, location, error) {
this.startTime = new Date();
this.categoryName = categoryName;
this.data = data;
this.level = level;
this.context = Object.assign({}, context); // eslint-disable-line prefer-object-spread
this.pid = process.pid;
this.error = error;
if (location) {
this.fileName = location.fileName;
@ -37,9 +39,8 @@ class LoggingEvent {
serialise() {
return flatted.stringify(this, (key, value) => {
// JSON.stringify(new Error('test')) returns {}, which is not really useful for us.
// The following allows us to serialize errors correctly.
// duck-typing for Error object
if (value && value.message && value.stack) {
// The following allows us to serialize errors (semi) correctly.
if (value instanceof Error) {
// eslint-disable-next-line prefer-object-spread
value = Object.assign(
{ message: value.message, stack: value.stack },
@ -76,26 +77,40 @@ class LoggingEvent {
}
return value;
});
rehydratedEvent.location = {
fileName: rehydratedEvent.fileName,
lineNumber: rehydratedEvent.lineNumber,
columnNumber: rehydratedEvent.columnNumber,
callStack: rehydratedEvent.callStack,
className: rehydratedEvent.className,
functionName: rehydratedEvent.functionName,
functionAlias: rehydratedEvent.functionAlias,
callerName: rehydratedEvent.callerName,
};
if (
rehydratedEvent.fileName ||
rehydratedEvent.lineNumber ||
rehydratedEvent.columnNumber ||
rehydratedEvent.callStack ||
rehydratedEvent.className ||
rehydratedEvent.functionName ||
rehydratedEvent.functionAlias ||
rehydratedEvent.callerName
) {
rehydratedEvent.location = {
fileName: rehydratedEvent.fileName,
lineNumber: rehydratedEvent.lineNumber,
columnNumber: rehydratedEvent.columnNumber,
callStack: rehydratedEvent.callStack,
className: rehydratedEvent.className,
functionName: rehydratedEvent.functionName,
functionAlias: rehydratedEvent.functionAlias,
callerName: rehydratedEvent.callerName,
};
}
event = new LoggingEvent(
rehydratedEvent.categoryName,
levels.getLevel(rehydratedEvent.level.levelStr),
rehydratedEvent.data,
rehydratedEvent.context,
rehydratedEvent.location
rehydratedEvent.location,
rehydratedEvent.error
);
event.startTime = new Date(rehydratedEvent.startTime);
event.pid = rehydratedEvent.pid;
event.cluster = rehydratedEvent.cluster;
if (rehydratedEvent.cluster) {
event.cluster = rehydratedEvent.cluster;
}
} catch (e) {
event = new LoggingEvent('log4js', levels.ERROR, [
'Unable to parse log:',

74
lib/logger.js
View File

@ -8,10 +8,32 @@ const categories = require('./categories');
const configuration = require('./configuration');
const stackReg = /at (?:(.+)\s+\()?(?:(.+?):(\d+)(?::(\d+))?|([^)]+))\)?/;
/**
* The top entry is the Error
*/
const baseCallStackSkip = 1;
/**
* The _log function is 3 levels deep, we need to skip those to make it to the callSite
*/
const defaultErrorCallStackSkip = 3;
function defaultParseCallStack(data, skipIdx = 4) {
/**
*
* @param {Error} data
* @param {number} skipIdx
* @returns {import('../types/log4js').CallStack | null}
*/
function defaultParseCallStack(
data,
skipIdx = defaultErrorCallStackSkip + baseCallStackSkip
) {
try {
const stacklines = data.stack.split('\n').slice(skipIdx);
if (!stacklines.length) {
// There's no stack in this stack
// Should we try a previous index if skipIdx was set?
return null;
}
const lineMatch = stackReg.exec(stacklines[0]);
/* istanbul ignore else: failsafe */
if (lineMatch && lineMatch.length === 6) {
@ -71,6 +93,9 @@ class Logger {
}
this.category = name;
this.context = {};
/** @private */
this.callStackSkipIndex = 0;
/** @private */
this.parseCallStack = defaultParseCallStack;
debug(`Logger created (${this.category}, ${this.level})`);
}
@ -97,6 +122,20 @@ class Logger {
categories.setEnableCallStackForCategory(this.category, bool === true);
}
get callStackLinesToSkip() {
return this.callStackSkipIndex;
}
set callStackLinesToSkip(number) {
if (typeof number !== 'number') {
throw new TypeError('Must be a number');
}
if (number < 0) {
throw new RangeError('Must be >= 0');
}
this.callStackSkipIndex = number;
}
log(level, ...args) {
const logLevel = levels.getLevel(level);
if (!logLevel) {
@ -123,12 +162,35 @@ class Logger {
_log(level, data) {
debug(`sending log data (${level}) to appenders`);
const error = data.find((item) => item instanceof Error);
let callStack;
if (this.useCallStack) {
try {
if (error) {
callStack = this.parseCallStack(
error,
this.callStackSkipIndex + baseCallStackSkip
);
}
} catch (_err) {
// Ignore Error and use the original method of creating a new Error.
}
callStack =
callStack ||
this.parseCallStack(
new Error(),
this.callStackSkipIndex +
defaultErrorCallStackSkip +
baseCallStackSkip
);
}
const loggingEvent = new LoggingEvent(
this.category,
level,
data,
this.context,
this.useCallStack && this.parseCallStack(new Error())
callStack,
error
);
clustering.send(loggingEvent);
}
@ -146,7 +208,13 @@ class Logger {
}
setParseCallStackFunction(parseFunction) {
this.parseCallStack = parseFunction;
if (typeof parseFunction === 'function') {
this.parseCallStack = parseFunction;
} else if (parseFunction === undefined) {
this.parseCallStack = defaultParseCallStack;
} else {
throw new TypeError('Invalid type passed to setParseCallStackFunction');
}
}
}

28
test/tap/LoggingEvent-test.js
View File

@ -152,5 +152,33 @@ test('LoggingEvent', (batch) => {
t.end();
});
batch.test('Should correctly serialize and deserialize', (t) => {
const error = new Error('test');
const location = {
fileName: __filename,
lineNumber: 123,
columnNumber: 52,
callStack: error.stack,
className: 'Foo',
functionName: 'test',
functionAlias: 'baz',
callerName: 'Foo.test [as baz]',
};
const event = new LoggingEvent(
'cheese',
levels.DEBUG,
[error, 'log message'],
{
user: 'bob',
},
location,
error
);
const event2 = LoggingEvent.deserialise(event.serialise());
t.match(event2, event);
t.end();
});
batch.end();
});

114
test/tap/logger-test.js
View File

@ -5,8 +5,16 @@ const callsites = require('callsites');
const levels = require('../../lib/levels');
const categories = require('../../lib/categories');
/** @type {import('../../types/log4js').LoggingEvent[]} */
const events = [];
/** @type {string[]} */
const messages = [];
/**
* @typedef {import('../../types/log4js').Logger} LoggerClass
*/
/** @type {{new (): LoggerClass}} */
const Logger = sandbox.require('../../lib/logger', {
requires: {
'./levels': levels,
@ -147,6 +155,14 @@ test('../../lib/logger', (batch) => {
t.equal(logger.useCallStack, false);
logger.debug('test no callStack');
let event = events.shift();
t.notMatch(event, { functionName: String });
t.notMatch(event, { fileName: String });
t.notMatch(event, { lineNumber: Number });
t.notMatch(event, { columnNumber: Number });
t.notMatch(event, { callStack: String });
logger.useCallStack = false;
t.equal(logger.useCallStack, false);
@ -167,6 +183,15 @@ test('../../lib/logger', (batch) => {
logger.useCallStack = true;
t.equal(logger.useCallStack, true);
logger.debug('test with callStack');
event = events.shift();
t.match(event, {
functionName: String,
fileName: String,
lineNumber: Number,
columnNumber: Number,
callStack: String,
});
t.end();
}
);
@ -250,6 +275,9 @@ test('../../lib/logger', (batch) => {
t.notOk(results);
t.equal(messages.length, 1, 'should have error');
results = logger.parseCallStack(new Error(), 100);
t.equal(results, null);
t.end();
});
@ -309,6 +337,11 @@ test('../../lib/logger', (batch) => {
batch.test('should correctly change the parseCallStack function', (t) => {
const logger = new Logger('stack');
logger.level = 'debug';
logger.useCallStack = true;
logger.info('test defaultParseCallStack');
const initialEvent = events.shift();
const parseFunction = function () {
return {
functionName: 'test function name',
@ -318,8 +351,6 @@ test('../../lib/logger', (batch) => {
callStack: 'test callstack',
};
};
logger.level = 'debug';
logger.useCallStack = true;
logger.setParseCallStackFunction(parseFunction);
t.equal(logger.parseCallStack, parseFunction);
@ -331,6 +362,85 @@ test('../../lib/logger', (batch) => {
t.equal(events[0].columnNumber, 25);
t.equal(events[0].callStack, 'test callstack');
events.shift();
logger.setParseCallStackFunction(undefined);
logger.info('test restoredDefaultParseCallStack');
t.equal(events[0].functionName, initialEvent.functionName);
t.equal(events[0].fileName, initialEvent.fileName);
t.equal(events[0].columnNumber, initialEvent.columnNumber);
t.throws(() => logger.setParseCallStackFunction('not a function'));
t.end();
});
batch.test('should correctly change the stack levels to skip', (t) => {
const logger = new Logger('stack');
logger.level = 'debug';
logger.useCallStack = true;
t.equal(
logger.callStackLinesToSkip,
0,
'initial callStackLinesToSkip changed'
);
logger.info('get initial stack');
const initialEvent = events.shift();
const newStackSkip = 1;
logger.callStackLinesToSkip = newStackSkip;
t.equal(logger.callStackLinesToSkip, newStackSkip);
logger.info('test stack skip');
const event = events.shift();
t.not(event.functionName, initialEvent.functionName);
t.not(event.fileName, initialEvent.fileName);
t.equal(
event.callStack,
initialEvent.callStack.split('\n').slice(newStackSkip).join('\n')
);
t.throws(() => {
logger.callStackLinesToSkip = -1;
});
t.throws(() => {
logger.callStackLinesToSkip = '2';
});
t.end();
});
batch.test('should utilize the first Error data value', (t) => {
const logger = new Logger('stack');
logger.level = 'debug';
logger.useCallStack = true;
const error = new Error();
logger.info(error);
const event = events.shift();
t.equal(event.error, error);
logger.info(error);
t.match(event, events.shift());
logger.callStackLinesToSkip = 1;
logger.info(error);
const event2 = events.shift();
t.equal(event2.callStack, event.callStack.split('\n').slice(1).join('\n'));
logger.callStackLinesToSkip = 0;
logger.info('hi', error);
const event3 = events.shift();
t.equal(event3.callStack, event.callStack);
t.equal(event3.error, error);
logger.info('hi', error, new Error());
const event4 = events.shift();
t.equal(event4.callStack, event.callStack);
t.equal(event4.error, error);
t.end();
});

41
types/log4js.d.ts vendored
View File

@ -74,8 +74,20 @@ export interface Level {
level: number;
levelStr: string;
}
export interface LoggingEvent {
/**
* A parsed CallStack from an `Error.stack` trace
*/
export interface CallStack {
functionName: string;
fileName: string;
lineNumber: number;
columnNumber: number;
/**
* The stack string after the skipped lines
*/
callStack: string;
}
export interface LoggingEvent extends Partial<CallStack> {
categoryName: string; // name of category
level: Level; // level of message
data: any[]; // objects to log
@ -86,11 +98,10 @@ export interface LoggingEvent {
workerId: number;
worker: number;
};
functionName?: string;
fileName?: string;
lineNumber?: number;
columnNumber?: number;
callStack?: string;
/**
* The first Error object in the data if there is one
*/
error?: Error;
serialise(): string;
}
@ -432,7 +443,21 @@ export interface Logger {
clearContext(): void;
setParseCallStackFunction(parseFunction: Function): void;
/**
* Replace the basic parse function with a new custom one
* - Note that linesToSkip will be based on the origin of the Error object in addition to the callStackLinesToSkip (at least 1)
* @param parseFunction the new parseFunction. Use `undefined` to reset to the base implementation
*/
setParseCallStackFunction(
parseFunction: (error: Error, linesToSkip: number) => CallStack | undefined
): void;
/**
* Adjust the value of linesToSkip when the parseFunction is called.
*
* Cannot be less than 0.
*/
callStackLinesToSkip: number;
trace(message: any, ...args: any[]): void;