feat(logging): support logger instances

Problem:
`getLogger('foo')` returns a global singleton, so the "current topic"
only is stored until the next `getLogger` call.

Solution:
Modify `getLogger('foo')` to return a wrapper which stores its topic.
This allows modules to declare their own module-local shared logger:

    const logger = getLogger('foo')

Author: justinmk3

packages/core/src/shared/logger/logger.ts

@@ -7,6 +7,13 @@ import * as vscode from 'vscode'
 
 export type LogTopic = 'crashReport' | 'notifications' | 'test' | 'unknown'
 
+class ErrorLog {
+    constructor(
+        public topic: string,
+        public error: Error
+    ) {}
+}
+
 const toolkitLoggers: {
     main: Logger | undefined
     debugConsole: Logger | undefined
@@ -30,16 +37,17 @@ export interface Logger {
     getLogById(logID: number, file: vscode.Uri): string | undefined
     /** HACK: Enables logging to vscode Debug Console. */
     enableDebugConsole(): void
+    sendToLog(
+        logLevel: 'debug' | 'verbose' | 'info' | 'warn' | 'error',
+        message: string | Error,
+        ...meta: any[]
+    ): number
 }
 
 export abstract class BaseLogger implements Logger {
     logFile?: vscode.Uri
     topic: LogTopic = 'unknown'
 
-    setTopic(topic: LogTopic = 'unknown') {
-        this.topic = topic
-    }
-
     debug(message: string | Error, ...meta: any[]): number {
         return this.sendToLog('debug', message, ...meta)
     }
@@ -58,17 +66,16 @@ export abstract class BaseLogger implements Logger {
     log(logLevel: LogLevel, message: string | Error, ...meta: any[]): number {
         return this.sendToLog(logLevel, message, ...meta)
     }
-    abstract setLogLevel(logLevel: LogLevel): void
-    abstract logLevelEnabled(logLevel: LogLevel): boolean
-    abstract getLogById(logID: number, file: vscode.Uri): string | undefined
-    /** HACK: Enables logging to vscode Debug Console. */
-    abstract enableDebugConsole(): void
-
     abstract sendToLog(
         logLevel: 'debug' | 'verbose' | 'info' | 'warn' | 'error',
         message: string | Error,
         ...meta: any[]
     ): number
+    abstract setLogLevel(logLevel: LogLevel): void
+    abstract logLevelEnabled(logLevel: LogLevel): boolean
+    abstract getLogById(logID: number, file: vscode.Uri): string | undefined
+    /** HACK: Enables logging to vscode Debug Console. */
+    abstract enableDebugConsole(): void
 }
 
 /**
@@ -121,6 +128,20 @@ export function compareLogLevel(l1: LogLevel, l2: LogLevel): number {
     return logLevels.get(l1)! - logLevels.get(l2)!
 }
 
+/* Format the message with topic header */
+function prependTopic(topic: string, message: string | Error): string | ErrorLog {
+    if (typeof message === 'string') {
+        // TODO: remove this after all calls are migrated and topic is a required param.
+        if (topic === 'unknown') {
+            return message
+        }
+        return `${topic}: ` + message
+    } else if (message instanceof Error) {
+        return new ErrorLog(topic, message)
+    }
+    return message
+}
+
 /**
  * Gets the logger if it has been initialized
  * the logger is of `'main'` or `undefined`: Main logger; default impl: logs to log file and log output channel
@@ -131,17 +152,15 @@ export function getLogger(topic?: LogTopic): Logger {
     if (!logger) {
         return new ConsoleLogger()
     }
-    ;(logger as BaseLogger).setTopic?.(topic)
-    return logger
+    return new TopicLogger(topic ?? 'unknown', logger)
 }
 
 export function getDebugConsoleLogger(topic?: LogTopic): Logger {
     const logger = toolkitLoggers['debugConsole']
     if (!logger) {
         return new ConsoleLogger()
     }
-    ;(logger as BaseLogger).setTopic?.(topic)
-    return logger
+    return new TopicLogger(topic ?? 'unknown', logger)
 }
 
 // jscpd:ignore-start
@@ -194,6 +213,46 @@ export class ConsoleLogger extends BaseLogger {
         return 0
     }
 }
+
+/**
+ * Wraps a `ToolkitLogger` and defers to it for everything except `topic`.
+ */
+export class TopicLogger extends BaseLogger implements vscode.Disposable {
+    /**
+     * Wraps a `ToolkitLogger` and defers to it for everything except `topic`.
+     */
+    public constructor(
+        public override topic: LogTopic,
+        public readonly logger: Logger
+    ) {
+        super()
+    }
+
+    override setLogLevel(logLevel: LogLevel): void {
+        this.logger.setLogLevel(logLevel)
+    }
+
+    override logLevelEnabled(logLevel: LogLevel): boolean {
+        return this.logger.logLevelEnabled(logLevel)
+    }
+
+    override getLogById(logID: number, file: vscode.Uri): string | undefined {
+        return this.logger.getLogById(logID, file)
+    }
+
+    override enableDebugConsole(): void {
+        this.logger.enableDebugConsole()
+    }
+
+    override sendToLog(level: LogLevel, message: string | Error, ...meta: any[]): number {
+        if (typeof message === 'string') {
+            message = prependTopic(this.topic, message) as string
+        }
+        return this.logger.sendToLog(level, message, meta)
+    }
+
+    public async dispose(): Promise<void> {}
+}
 // jscpd:ignore-end
 
 export function getNullLogger(type?: 'debugConsole' | 'main'): Logger {

packages/core/src/shared/logger/toolkitLogger.ts

@@ -14,19 +14,12 @@ import { SharedFileTransport } from './sharedFileTransport'
 import { ConsoleLogTransport } from './consoleLogTransport'
 import { isWeb } from '../extensionGlobals'
 
-class ErrorLog {
-    constructor(
-        public topic: string,
-        public error: Error
-    ) {}
-}
-
 // Need to limit how many logs are actually tracked
 // LRU cache would work well, currently it just dumps the least recently added log
 const logmapSize: number = 1000
+
 export class ToolkitLogger extends BaseLogger implements vscode.Disposable {
     private readonly logger: winston.Logger
-    /* topic is used for header in log messages, default is 'Unknown' */
     private disposed: boolean = false
     private idCounter: number = 0
     private logMap: { [logID: number]: { [filePath: string]: string } } = {}
@@ -111,20 +104,6 @@ export class ToolkitLogger extends BaseLogger implements vscode.Disposable {
               })
     }
 
-    /* Format the message with topic header */
-    private addTopicToMessage(message: string | Error): string | ErrorLog {
-        if (typeof message === 'string') {
-            // TODO: remove this after all calls are migrated and topic is a required param.
-            if (this.topic === 'unknown') {
-                return message
-            }
-            return `${this.topic}: ` + message
-        } else if (message instanceof Error) {
-            return new ErrorLog(this.topic, message)
-        }
-        return message
-    }
-
     private mapError(level: LogLevel, err: Error): Error | string {
         // Use ToolkitError.trace even if we have source mapping (see below), because:
         // 1. it is what users will see, we want visibility into that when debugging
@@ -141,17 +120,16 @@ export class ToolkitLogger extends BaseLogger implements vscode.Disposable {
     }
 
     override sendToLog(level: LogLevel, message: string | Error, ...meta: any[]): number {
-        const messageWithTopic = this.addTopicToMessage(message)
         if (this.disposed) {
             throw new Error('Cannot write to disposed logger')
         }
 
         meta = meta.map((o) => (o instanceof Error ? this.mapError(level, o) : o))
 
-        if (messageWithTopic instanceof ErrorLog) {
-            this.logger.log(level, '%O', messageWithTopic, ...meta, { logID: this.idCounter })
+        if (message instanceof Error) {
+            this.logger.log(level, '%O', message, ...meta, { logID: this.idCounter })
         } else {
-            this.logger.log(level, messageWithTopic, ...meta, { logID: this.idCounter })
+            this.logger.log(level, message, ...meta, { logID: this.idCounter })
         }
 
         this.logMap[this.idCounter % logmapSize] = {}

packages/core/src/test/globalSetup.test.ts

@@ -14,7 +14,7 @@ import globals from '../shared/extensionGlobals'
 import { CodelensRootRegistry } from '../shared/fs/codelensRootRegistry'
 import { CloudFormationTemplateRegistry } from '../shared/fs/templateRegistry'
 import { getLogger, LogLevel } from '../shared/logger'
-import { setLogger } from '../shared/logger/logger'
+import { setLogger, TopicLogger } from '../shared/logger/logger'
 import { FakeExtensionContext } from './fakeExtensionContext'
 import { TestLogger } from './testLogger'
 import * as testUtil from './testUtil'
@@ -136,7 +136,7 @@ export const mochaHooks = {
  * Verifies that the TestLogger instance is still the one set as the toolkit's logger.
  */
 export function getTestLogger(): TestLogger {
-    const logger = getLogger()
+    const logger = getLogger() instanceof TopicLogger ? (getLogger() as TopicLogger).logger : getLogger()
     assert.strictEqual(logger, testLogger, 'The expected test logger is not the current logger')
     assert.ok(testLogger, 'TestLogger was expected to exist')
 

packages/core/src/test/shared/logger/toolkitLogger.test.ts

@@ -10,7 +10,8 @@ import * as vscode from 'vscode'
 import { ToolkitLogger } from '../../../shared/logger/toolkitLogger'
 import { MockOutputChannel } from '../../mockOutputChannel'
 import { sleep, waitUntil } from '../../../shared/utilities/timeoutUtils'
-import { ToolkitError } from '../../../shared/errors'
+import { getLogger } from '../../../shared/logger'
+import { assertLogsContain } from '../../globalSetup.test'
 
 /**
  * Disposes the logger then waits for the write streams to flush. The `expected` and `unexpected` arrays just look
@@ -240,55 +241,20 @@ describe('ToolkitLogger', function () {
         })
 
         it('prepends topic to message', async function () {
-            testLogger = new ToolkitLogger('info')
-            testLogger.logToOutputChannel(outputChannel, false)
-            testLogger.setTopic('test')
-            testLogger.setLogLevel('verbose')
-
-            const testMessageWithHeader = 'test: This is a test message'
-            testLogger.verbose('This is a test message')
-            assert.ok(
-                (await waitForLoggedTextByContents(testMessageWithHeader)).includes(testMessageWithHeader),
-                'Expected header added'
-            )
-
-            const msg = "topic: 'test'"
-            testLogger.verbose(new ToolkitError('root error', { code: 'something went wrong' }))
-            assert.ok((await waitForLoggedTextByContents(msg)).includes(msg), 'Expected header added')
-
-            const msg2 = "topic: 'test'"
-            testLogger.verbose(new ToolkitError('root error', { code: 'something went wrong' }))
-            assert.ok((await waitForLoggedTextByContents(msg2)).includes(msg2), 'Expected header added')
-        })
-
-        it('unknown topic header ignored in message', async function () {
-            const testMessage = 'This is a test message'
-            const unknowntestMessage = 'unknown: This is a test message'
+            const logger = getLogger('notifications')
+            logger.setLogLevel('verbose')
 
-            testLogger = new ToolkitLogger('info')
-            testLogger.logToOutputChannel(outputChannel, false)
-            testLogger.setTopic('unknown')
-            testLogger.setLogLevel('verbose')
-            testLogger.verbose(testMessage)
-
-            const waitForMessage = waitForLoggedTextByContents(testMessage)
-            assert.ok((await waitForMessage).includes(testMessage), 'Expected message logged')
-            assert.ok(!(await waitForMessage).includes(unknowntestMessage), 'unexpected header in log')
-        })
+            logger.verbose('This is a test message')
+            assertLogsContain('notifications: This is a test message', true, 'verbose')
 
-        it('switch topic on same logger', async function () {
-            const testMessage = 'This is a test message'
-            const testMessageWithHeader = 'test: This is a test message'
-
-            testLogger = new ToolkitLogger('info')
-            testLogger.logToOutputChannel(outputChannel, false)
-            testLogger.setTopic('unknown')
-            testLogger.setTopic('test')
-            testLogger.setLogLevel('verbose')
-            testLogger.verbose(testMessage)
+            // const msg2 = "topic: 'test'"
+            // logger.verbose(new ToolkitError('root error', { code: 'something went wrong' }))
+            // assertLogsContain("topic: 'something went wrong'", true, 'verbose')
 
-            const waitForMessage = waitForLoggedTextByContents(testMessageWithHeader)
-            assert.ok((await waitForMessage).includes(testMessageWithHeader), 'Expected header added')
+            // 'unknown' is not prepended
+            const logger3 = getLogger('unknown')
+            logger3.verbose('This is a test message')
+            assertLogsContain('This is a test message', true, 'verbose')
         })
 
         happyLogScenarios.forEach((scenario) => {

packages/core/src/test/testLogger.ts

@@ -17,6 +17,7 @@ export class TestLogger implements Logger {
     }[] = []
     private count: number = 0
     public constructor(private logLevel: LogLevel = 'debug') {}
+    logFile?: Uri | undefined
 
     public enableDebugConsole(): void {}
 
@@ -50,6 +51,10 @@ export class TestLogger implements Logger {
             .map((loggedEntry) => loggedEntry.entry)
     }
 
+    public sendToLog(logLevel: LogLevel, msg: string, entries: Loggable[]): number {
+        return this.addLoggedEntries(logLevel, [msg, ...entries])
+    }
+
     private addLoggedEntries(logLevel: LogLevel, entries: Loggable[]): number {
         entries.forEach((entry) => {
             this.loggedEntries.push({