From 10fd51498c5214d9a73b2cc1cc8c8d66ac9a78ce Mon Sep 17 00:00:00 2001 From: Lars Kiesow Date: Thu, 5 Jan 2023 19:06:36 +0100 Subject: [PATCH 1/2] Add Source to Logging MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The Audiobookshelf logs sometimes contain information about the source of the log statement, but sometimes they don't This really depends on developers adding these information to the log messages. But even then, the information is usually just a hint about the module logging this, like `[Db]` or [Watcher]`, and finding the exact line can be hard. This patch automatically adds the source of the log statement to the logs. This means if someone calls `Logger.info(…)` in line `22` of `foo.js`, the log statement will contain this file and line: ``` [2023-01-05 19:04:12[ (LogManager.js:85:18) DEBUG: Daily Log file found 2023-01-05.txt [2023-01-05 19:04:12] (LogManager.js:59:12) INFO: [LogManager] Init current daily log filename: 2023-01-05.txt ``` This should make it much easier to identify the code where the log statement originated from. Long-term, this also means that we can probably remove the manually set identifiers contained in the log messages, like the `[LogManager]` in the example above. --- server/Logger.js | 23 ++++++++++++++++------- 1 file changed, 16 insertions(+), 7 deletions(-) diff --git a/server/Logger.js b/server/Logger.js index 2bdce9ac..1cf53074 100644 --- a/server/Logger.js +++ b/server/Logger.js @@ -22,6 +22,14 @@ class Logger { return 'UNKNOWN' } + get source() { + try { + throw new Error(); + } catch (error) { + return error.stack.split('\n')[3].replace(/^.*\/([^/]*:[0-9]*:[[0-9]*)\)*/, '$1') + } + } + getLogLevelString(level) { for (const key in LogLevel) { if (LogLevel[key] === level) { @@ -55,6 +63,7 @@ class Logger { handleLog(level, args) { const logObj = { timestamp: this.timestamp, + source: this.source, message: args.join(' '), levelName: this.getLogLevelString(level), level @@ -78,41 +87,41 @@ class Logger { trace(...args) { if (this.logLevel > LogLevel.TRACE) return - console.trace(`[${this.timestamp}] TRACE:`, ...args) + console.trace(`[${this.timestamp}[ (${this.source}) TRACE:`, ...args) this.handleLog(LogLevel.TRACE, args) } debug(...args) { if (this.logLevel > LogLevel.DEBUG) return - console.debug(`[${this.timestamp}] DEBUG:`, ...args) + console.debug(`[${this.timestamp}[ (${this.source}) DEBUG:`, ...args) this.handleLog(LogLevel.DEBUG, args) } info(...args) { if (this.logLevel > LogLevel.INFO) return - console.info(`[${this.timestamp}] INFO:`, ...args) + console.info(`[${this.timestamp}] (${this.source}) INFO:`, ...args) this.handleLog(LogLevel.INFO, args) } warn(...args) { if (this.logLevel > LogLevel.WARN) return - console.warn(`[${this.timestamp}] WARN:`, ...args) + console.warn(`[${this.timestamp}] (${this.source}) WARN:`, ...args) this.handleLog(LogLevel.WARN, args) } error(...args) { if (this.logLevel > LogLevel.ERROR) return - console.error(`[${this.timestamp}] ERROR:`, ...args) + console.error(`[${this.timestamp}] (${this.source}) ERROR:`, ...args) this.handleLog(LogLevel.ERROR, args) } fatal(...args) { - console.error(`[${this.timestamp}] FATAL:`, ...args) + console.error(`[${this.timestamp}] (${this.source}) FATAL:`, ...args) this.handleLog(LogLevel.FATAL, args) } note(...args) { - console.log(`[${this.timestamp}] NOTE:`, ...args) + console.log(`[${this.timestamp}] (${this.source}) NOTE:`, ...args) this.handleLog(LogLevel.NOTE, args) } } From 3426832f2ba57b0886fdd543642b6201d36ec004 Mon Sep 17 00:00:00 2001 From: advplyr Date: Thu, 5 Jan 2023 16:44:34 -0600 Subject: [PATCH 2/2] Fix for windows, update regex to only include line number, move to end of log --- server/Logger.js | 19 ++++++++++--------- server/Server.js | 1 + 2 files changed, 11 insertions(+), 9 deletions(-) diff --git a/server/Logger.js b/server/Logger.js index 1cf53074..bea91553 100644 --- a/server/Logger.js +++ b/server/Logger.js @@ -24,9 +24,10 @@ class Logger { get source() { try { - throw new Error(); + throw new Error() } catch (error) { - return error.stack.split('\n')[3].replace(/^.*\/([^/]*:[0-9]*:[[0-9]*)\)*/, '$1') + const regex = global.isWin ? /^.*\\([^\\:]*:[0-9]*):[0-9]*\)*/ : /^.*\/([^/:]*:[0-9]*):[0-9]*\)*/ + return error.stack.split('\n')[3].replace(regex, '$1') } } @@ -87,41 +88,41 @@ class Logger { trace(...args) { if (this.logLevel > LogLevel.TRACE) return - console.trace(`[${this.timestamp}[ (${this.source}) TRACE:`, ...args) + console.trace(`[${this.timestamp}[ TRACE:`, ...args) this.handleLog(LogLevel.TRACE, args) } debug(...args) { if (this.logLevel > LogLevel.DEBUG) return - console.debug(`[${this.timestamp}[ (${this.source}) DEBUG:`, ...args) + console.debug(`[${this.timestamp}] DEBUG:`, ...args, `(${this.source})`) this.handleLog(LogLevel.DEBUG, args) } info(...args) { if (this.logLevel > LogLevel.INFO) return - console.info(`[${this.timestamp}] (${this.source}) INFO:`, ...args) + console.info(`[${this.timestamp}] INFO:`, ...args) this.handleLog(LogLevel.INFO, args) } warn(...args) { if (this.logLevel > LogLevel.WARN) return - console.warn(`[${this.timestamp}] (${this.source}) WARN:`, ...args) + console.warn(`[${this.timestamp}] WARN:`, ...args, `(${this.source})`) this.handleLog(LogLevel.WARN, args) } error(...args) { if (this.logLevel > LogLevel.ERROR) return - console.error(`[${this.timestamp}] (${this.source}) ERROR:`, ...args) + console.error(`[${this.timestamp}] ERROR:`, ...args, `(${this.source})`) this.handleLog(LogLevel.ERROR, args) } fatal(...args) { - console.error(`[${this.timestamp}] (${this.source}) FATAL:`, ...args) + console.error(`[${this.timestamp}] FATAL:`, ...args, `(${this.source})`) this.handleLog(LogLevel.FATAL, args) } note(...args) { - console.log(`[${this.timestamp}] (${this.source}) NOTE:`, ...args) + console.log(`[${this.timestamp}] NOTE:`, ...args) this.handleLog(LogLevel.NOTE, args) } } diff --git a/server/Server.js b/server/Server.js index 4038b776..1de00f98 100644 --- a/server/Server.js +++ b/server/Server.js @@ -41,6 +41,7 @@ class Server { this.Port = PORT this.Host = HOST global.Source = SOURCE + global.isWin = process.platform === 'win32' global.Uid = isNaN(UID) ? 0 : Number(UID) global.Gid = isNaN(GID) ? 0 : Number(GID) global.ConfigPath = Path.normalize(CONFIG_PATH)