Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

fix(logger): avoid creating new winston instance for each child #5597

Merged
merged 1 commit into from
Jun 1, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
61 changes: 26 additions & 35 deletions packages/logger/src/node.ts
Original file line number Diff line number Diff line change
Expand Up @@ -2,20 +2,13 @@ import path from "node:path";
import DailyRotateFile from "winston-daily-rotate-file";
import TransportStream from "winston-transport";
import winston from "winston";
import {Logger, LogLevel, logLevelNum, TimestampFormat} from "./interface.js";
import type {Logger as Winston} from "winston";
import {Logger, LogLevel, TimestampFormat} from "./interface.js";
import {ConsoleDynamicLevel} from "./utils/consoleTransport.js";
import {getFormat} from "./utils/format.js";
import {WinstonLogger} from "./winston.js";

const DATE_PATTERN = "YYYY-MM-DD";

/**
* Increase max listeners of file transports to prevent `MaxListenersExceededWarning` warnings.
* Each child logger (`logger.child`) adds a new listener. Setting a reasonable limit to still
* detect potential memory leaks. See https://github.com/ChainSafe/lodestar/issues/5529 for details.
*/
const FILE_TRANSPORT_MAX_LISTENERS = 20;

export type LoggerNodeOpts = {
level: LogLevel;
/**
Expand Down Expand Up @@ -111,12 +104,12 @@ function getNodeLoggerTransports(opts: LoggerNodeOpts): winston.transport[] {
handleExceptions: true,
maxFiles: opts.file.dailyRotate,
auditFile: path.join(path.dirname(filename), ".log_rotate_audit.json"),
}).setMaxListeners(FILE_TRANSPORT_MAX_LISTENERS)
})
: new winston.transports.File({
level: opts.file.level,
filename: filename,
handleExceptions: true,
}).setMaxListeners(FILE_TRANSPORT_MAX_LISTENERS)
})
);
}

Expand All @@ -128,36 +121,34 @@ interface DefaultMeta {
}

export class WinstonLoggerNode extends WinstonLogger implements LoggerNode {
constructor(private readonly opts: LoggerNodeOpts, private readonly transports: winston.transport[]) {
const defaultMeta: DefaultMeta = {module: opts?.module || ""};
super(
winston.createLogger({
// Do not set level at the logger level. Always control by Transport, unless for testLogger
level: opts.level,
defaultMeta,
format: getFormat(opts),
transports,
exitOnError: false,
levels: logLevelNum,
})
);
constructor(protected readonly winston: Winston, private readonly opts: LoggerNodeOpts) {
super(winston);
}

static fromOpts(opts: LoggerNodeOpts, transports: winston.transport[]): WinstonLoggerNode {
return new WinstonLoggerNode(this.createWinstonInstance(opts, transports), opts);
}

static fromNewTransports(opts: LoggerNodeOpts): WinstonLoggerNode {
return new WinstonLoggerNode(opts, getNodeLoggerTransports(opts));
return WinstonLoggerNode.fromOpts(opts, getNodeLoggerTransports(opts));
}

// Return a new logger instance with different module and log level
// but a reference to the same transports, such that there's only one
// transport instance per tree of child loggers
nflaig marked this conversation as resolved.
Show resolved Hide resolved
child(opts: LoggerNodeChildOpts): LoggerNode {
return new WinstonLoggerNode(
{
...this.opts,
module: [this.opts?.module, opts.module].filter(Boolean).join("/"),
},
this.transports
);
const parentMeta = this.winston.defaultMeta as DefaultMeta | undefined;
const childModule = [parentMeta?.module, opts.module].filter(Boolean).join("/");
const childOpts: LoggerNodeOpts = {...this.opts, module: childModule};
const defaultMeta: DefaultMeta = {module: childModule};

// Same strategy as Winston's source .child.
// However, their implementation of child is to merge info objects where parent takes precedence, so it's
// impossible for child to overwrite 'module' field. Instead the winston class is cloned as defaultMeta
// overwritten completely.
// https://github.com/winstonjs/winston/blob/3f1dcc13cda384eb30fe3b941764e47a5a5efc26/lib/winston/logger.js#L47
const childWinston = Object.create(this.winston) as typeof this.winston;

childWinston.defaultMeta = defaultMeta;

return new WinstonLoggerNode(childWinston, childOpts);
}

toOpts(): LoggerNodeOpts {
Expand Down
24 changes: 13 additions & 11 deletions packages/logger/src/winston.ts
Original file line number Diff line number Diff line change
Expand Up @@ -40,19 +40,21 @@ export class WinstonLogger implements Logger {
constructor(protected readonly winston: Winston) {}

static fromOpts(options: Partial<LoggerOptions> = {}, transports?: winston.transport[]): WinstonLogger {
return new WinstonLogger(this.createWinstonInstance(options, transports));
}

static createWinstonInstance(options: Partial<LoggerOptions> = {}, transports?: winston.transport[]): Winston {
const defaultMeta: DefaultMeta = {module: options?.module || ""};

return new WinstonLogger(
winston.createLogger({
// Do not set level at the logger level. Always control by Transport, unless for testLogger
level: options.level,
defaultMeta,
format: getFormat(options),
transports,
exitOnError: false,
levels: logLevelNum,
})
);
return winston.createLogger({
// Do not set level at the logger level. Always control by Transport, unless for testLogger
level: options.level,
defaultMeta,
format: getFormat(options),
transports,
exitOnError: false,
levels: logLevelNum,
});
}

error(message: string, context?: LogData, error?: Error): void {
Expand Down
4 changes: 2 additions & 2 deletions packages/logger/test/unit/logger/winston.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -79,7 +79,7 @@ describe("winston logger", () => {
for (const format of logFormats) {
it(`${id} ${format} output`, async () => {
const memoryTransport = new MemoryTransport();
const logger = new WinstonLoggerNode(
const logger = WinstonLoggerNode.fromOpts(
{level: LogLevel.info, format, timestampFormat: {format: TimestampFormatCode.Hidden}},
[memoryTransport]
);
Expand All @@ -94,7 +94,7 @@ describe("winston logger", () => {
describe("child logger", () => {
it("Should parse child module", async () => {
const memoryTransport = new MemoryTransport();
const loggerA = new WinstonLoggerNode(
const loggerA = WinstonLoggerNode.fromOpts(
{level: LogLevel.info, timestampFormat: {format: TimestampFormatCode.Hidden}, module: "a"},
[memoryTransport]
);
Expand Down