fix(core): Reduce logging overhead for levels that do not output (#7479)

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)
This commit is contained in:
कारतोफ्फेलस्क्रिप्ट™ 2023-10-20 18:26:33 +02:00 committed by GitHub
parent 0b42d1aa71
commit 76c04815f7
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
4 changed files with 22 additions and 18 deletions

View file

@ -9,22 +9,32 @@ import callsites from 'callsites';
import { basename } from 'path'; import { basename } from 'path';
import config from '@/config'; import config from '@/config';
const noOp = () => {};
const levelNames = ['debug', 'verbose', 'info', 'warn', 'error'] as const;
export class Logger implements ILogger { export class Logger implements ILogger {
private logger: winston.Logger; private logger: winston.Logger;
constructor() { constructor() {
const level = config.getEnv('logs.level'); const level = config.getEnv('logs.level');
const output = config
.getEnv('logs.output')
.split(',')
.map((output) => output.trim());
this.logger = winston.createLogger({ this.logger = winston.createLogger({
level, level,
silent: level === 'silent', 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')) { if (output.includes('console')) {
let format: winston.Logform.Format; let format: winston.Logform.Format;
if (['debug', 'verbose'].includes(level)) { if (['debug', 'verbose'].includes(level)) {

View file

@ -6,10 +6,7 @@ const { LoggerProxy } = require('n8n-workflow');
const { packageDir, writeJSON } = require('./common'); const { packageDir, writeJSON } = require('./common');
const { loadClassInIsolation } = require('../dist/ClassLoader'); const { loadClassInIsolation } = require('../dist/ClassLoader');
LoggerProxy.init({ LoggerProxy.init(console);
log: console.log.bind(console),
warn: console.warn.bind(console),
});
const loadClass = (sourcePath) => { const loadClass = (sourcePath) => {
try { try {

View file

@ -4,10 +4,7 @@ const { LoggerProxy, NodeHelpers } = require('n8n-workflow');
const { PackageDirectoryLoader } = require('../dist/DirectoryLoader'); const { PackageDirectoryLoader } = require('../dist/DirectoryLoader');
const { packageDir, writeJSON } = require('./common'); const { packageDir, writeJSON } = require('./common');
LoggerProxy.init({ LoggerProxy.init(console);
log: console.log.bind(console),
warn: console.warn.bind(console),
});
function findReferencedMethods(obj, refs = {}, latestName = '') { function findReferencedMethods(obj, refs = {}, latestName = '') {
for (const key in obj) { for (const key in obj) {

View file

@ -22,21 +22,21 @@ export function log(type: LogTypes, message: string, meta: object = {}) {
// Convenience methods below // Convenience methods below
export function debug(message: string, meta: object = {}) { export function debug(message: string, meta: object = {}) {
getInstance().log('debug', message, meta); getInstance().debug(message, meta);
} }
export function info(message: string, meta: object = {}) { export function info(message: string, meta: object = {}) {
getInstance().log('info', message, meta); getInstance().info(message, meta);
} }
export function error(message: string, meta: object = {}) { export function error(message: string, meta: object = {}) {
getInstance().log('error', message, meta); getInstance().error(message, meta);
} }
export function verbose(message: string, meta: object = {}) { export function verbose(message: string, meta: object = {}) {
getInstance().log('verbose', message, meta); getInstance().verbose(message, meta);
} }
export function warn(message: string, meta: object = {}) { export function warn(message: string, meta: object = {}) {
getInstance().log('warn', message, meta); getInstance().warn(message, meta);
} }