Skip to content

Commit

Permalink
fix(core): Reduce logging overhead for levels that do not output (#7479)
Browse files Browse the repository at this point in the history
all current logging calls execute `callsites()` to figure out what code
tried to log. This happens even for logging methods that aren't supposed
to create any output. Under moderate load, this can take up quite a lot
of resources. This PR changes the logger to make all ignorable logging
methods a No-Op.

In a small benchmark with a simple webhook, with log-level set to
`warn`, and using `ab -c 50 -n 500
http://localhost:5678/webhook/testing`, these were the response times:

### Before

![Before](https://github.com/n8n-io/n8n/assets/196144/01680fd9-3d2a-4f7f-bb1c-5b03bd7d5bc3)

### After

![After](https://github.com/n8n-io/n8n/assets/196144/ccacb20a-48ca-455a-a8cb-098c9c0e352e)
  • Loading branch information
netroy committed Oct 20, 2023
1 parent 0b42d1a commit 76c0481
Show file tree
Hide file tree
Showing 4 changed files with 22 additions and 18 deletions.
20 changes: 15 additions & 5 deletions packages/cli/src/Logger.ts
Original file line number Diff line number Diff line change
Expand Up @@ -9,22 +9,32 @@ import callsites from 'callsites';
import { basename } from 'path';
import config from '@/config';

const noOp = () => {};
const levelNames = ['debug', 'verbose', 'info', 'warn', 'error'] as const;

export class Logger implements ILogger {
private logger: winston.Logger;

constructor() {
const level = config.getEnv('logs.level');

const output = config
.getEnv('logs.output')
.split(',')
.map((output) => output.trim());

this.logger = winston.createLogger({
level,
silent: level === 'silent',
});

// Change all methods with higher log-level to no-op
for (const levelName of levelNames) {
if (this.logger.levels[levelName] > this.logger.levels[level]) {
Object.defineProperty(this, levelName, { value: noOp });
}
}

const output = config
.getEnv('logs.output')
.split(',')
.map((output) => output.trim());

if (output.includes('console')) {
let format: winston.Logform.Format;
if (['debug', 'verbose'].includes(level)) {
Expand Down
5 changes: 1 addition & 4 deletions packages/core/bin/generate-known
Original file line number Diff line number Diff line change
Expand Up @@ -6,10 +6,7 @@ const { LoggerProxy } = require('n8n-workflow');
const { packageDir, writeJSON } = require('./common');
const { loadClassInIsolation } = require('../dist/ClassLoader');

LoggerProxy.init({
log: console.log.bind(console),
warn: console.warn.bind(console),
});
LoggerProxy.init(console);

const loadClass = (sourcePath) => {
try {
Expand Down
5 changes: 1 addition & 4 deletions packages/core/bin/generate-ui-types
Original file line number Diff line number Diff line change
Expand Up @@ -4,10 +4,7 @@ const { LoggerProxy, NodeHelpers } = require('n8n-workflow');
const { PackageDirectoryLoader } = require('../dist/DirectoryLoader');
const { packageDir, writeJSON } = require('./common');

LoggerProxy.init({
log: console.log.bind(console),
warn: console.warn.bind(console),
});
LoggerProxy.init(console);

function findReferencedMethods(obj, refs = {}, latestName = '') {
for (const key in obj) {
Expand Down
10 changes: 5 additions & 5 deletions packages/workflow/src/LoggerProxy.ts
Original file line number Diff line number Diff line change
Expand Up @@ -22,21 +22,21 @@ export function log(type: LogTypes, message: string, meta: object = {}) {
// Convenience methods below

export function debug(message: string, meta: object = {}) {
getInstance().log('debug', message, meta);
getInstance().debug(message, meta);
}

export function info(message: string, meta: object = {}) {
getInstance().log('info', message, meta);
getInstance().info(message, meta);
}

export function error(message: string, meta: object = {}) {
getInstance().log('error', message, meta);
getInstance().error(message, meta);
}

export function verbose(message: string, meta: object = {}) {
getInstance().log('verbose', message, meta);
getInstance().verbose(message, meta);
}

export function warn(message: string, meta: object = {}) {
getInstance().log('warn', message, meta);
getInstance().warn(message, meta);
}

0 comments on commit 76c0481

Please sign in to comment.