From 76c04815f7f53bf6b4c06bbe5afa52f51f28750d Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?=E0=A4=95=E0=A4=BE=E0=A4=B0=E0=A4=A4=E0=A5=8B=E0=A4=AB?=
 =?UTF-8?q?=E0=A5=8D=E0=A4=AB=E0=A5=87=E0=A4=B2=E0=A4=B8=E0=A5=8D=E0=A4=95?=
 =?UTF-8?q?=E0=A5=8D=E0=A4=B0=E0=A4=BF=E0=A4=AA=E0=A5=8D=E0=A4=9F=E2=84=A2?=
 <netroy@users.noreply.github.com>
Date: Fri, 20 Oct 2023 18:26:33 +0200
Subject: [PATCH] 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)
---
 packages/cli/src/Logger.ts           | 20 +++++++++++++++-----
 packages/core/bin/generate-known     |  5 +----
 packages/core/bin/generate-ui-types  |  5 +----
 packages/workflow/src/LoggerProxy.ts | 10 +++++-----
 4 files changed, 22 insertions(+), 18 deletions(-)

diff --git a/packages/cli/src/Logger.ts b/packages/cli/src/Logger.ts
index 2a113cb8cc..0395946f62 100644
--- a/packages/cli/src/Logger.ts
+++ b/packages/cli/src/Logger.ts
@@ -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)) {
diff --git a/packages/core/bin/generate-known b/packages/core/bin/generate-known
index 5cabfa9b80..df38a7ecc6 100755
--- a/packages/core/bin/generate-known
+++ b/packages/core/bin/generate-known
@@ -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 {
diff --git a/packages/core/bin/generate-ui-types b/packages/core/bin/generate-ui-types
index f320dea390..317c0e121e 100755
--- a/packages/core/bin/generate-ui-types
+++ b/packages/core/bin/generate-ui-types
@@ -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) {
diff --git a/packages/workflow/src/LoggerProxy.ts b/packages/workflow/src/LoggerProxy.ts
index 24df176fff..875e1e50a0 100644
--- a/packages/workflow/src/LoggerProxy.ts
+++ b/packages/workflow/src/LoggerProxy.ts
@@ -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);
 }