feat(logging): support logger instances #5941

## 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/codewhisperer/activation.ts

@@ -114,7 +114,7 @@ export async function activate(context: ExtContext): Promise<void> {
 
     // TODO: this is already done in packages/core/src/extensionCommon.ts, why doesn't amazonq use that?
     registerWebviewErrorHandler((error: unknown, webviewId: string, command: string) => {
-        logAndShowWebviewError(localize, error, webviewId, command)
+        return logAndShowWebviewError(localize, error, webviewId, command)
     })
 
     /**

packages/core/src/extension.ts

@@ -83,7 +83,7 @@ export async function activateCommon(
     })
 
     registerWebviewErrorHandler((error: unknown, webviewId: string, command: string) => {
-        logAndShowWebviewError(localize, error, webviewId, command)
+        return logAndShowWebviewError(localize, error, webviewId, command)
     })
 
     // Setup the logger

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/shared/utilities/logAndShowUtils.ts

@@ -52,6 +52,8 @@ export async function logAndShowError(
  * @param err The error that was thrown in the backend
  * @param webviewId Arbitrary value that identifies which webview had the error
  * @param command The high level command/function that was run which triggered the error
+ *
+ * @returns user-facing error
  */
 export function logAndShowWebviewError(localize: nls.LocalizeFunc, err: unknown, webviewId: string, command: string) {
     // HACK: The following implementation is a hack, influenced by the implementation of handleError().
@@ -62,4 +64,6 @@ export function logAndShowWebviewError(localize: nls.LocalizeFunc, err: unknown,
     logAndShowError(localize, userFacingError, `webviewId="${webviewId}"`, 'Webview error').catch((e) => {
         getLogger().error('logAndShowError failed: %s', (e as Error).message)
     })
+
+    return userFacingError
 }

packages/core/src/test/codewhisperer/commands/basicCommands.test.ts

@@ -28,7 +28,6 @@ import { stub } from '../../utilities/stubber'
 import { AuthUtil } from '../../../codewhisperer/util/authUtil'
 import { getTestWindow } from '../../shared/vscode/window'
 import { ExtContext } from '../../../shared/extensions'
-import { getLogger } from '../../../shared/logger/logger'
 import {
     createAutoScans,
     createAutoSuggestions,
@@ -57,6 +56,7 @@ import * as diagnosticsProvider from '../../../codewhisperer/service/diagnostics
 import { SecurityIssueHoverProvider } from '../../../codewhisperer/service/securityIssueHoverProvider'
 import { SecurityIssueCodeActionProvider } from '../../../codewhisperer/service/securityIssueCodeActionProvider'
 import { randomUUID } from '../../../shared/crypto'
+import { assertLogsContain } from '../../globalSetup.test'
 
 describe('CodeWhisperer-basicCommands', function () {
     let targetCommand: Command<any> & vscode.Disposable
@@ -636,7 +636,6 @@ describe('CodeWhisperer-basicCommands', function () {
             openTextDocumentMock.resolves(textDocumentMock)
 
             sandbox.stub(vscode.workspace, 'openTextDocument').value(openTextDocumentMock)
-            const loggerStub = sinon.stub(getLogger(), 'error')
 
             sinon.stub(vscode.WorkspaceEdit.prototype, 'replace').value(replaceMock)
             applyEditMock.resolves(false)
@@ -652,9 +651,7 @@ describe('CodeWhisperer-basicCommands', function () {
             await targetCommand.execute(codeScanIssue, fileName, 'quickfix')
 
             assert.ok(replaceMock.calledOnce)
-            assert.ok(loggerStub.calledOnce)
-            const actual = loggerStub.getCall(0).args[0]
-            assert.strictEqual(actual, 'Apply fix command failed. Error: Failed to apply edit to the workspace.')
+            assertLogsContain('Apply fix command failed. Error: Failed to apply edit to the workspace.', true, 'error')
             assertTelemetry('codewhisperer_codeScanIssueApplyFix', {
                 detectorId: codeScanIssue.detectorId,
                 findingId: codeScanIssue.findingId,

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')
 
@@ -169,18 +169,17 @@ async function writeLogsToFile(testName: string) {
 
 // TODO: merge this with `toolkitLogger.test.ts:checkFile`
 export function assertLogsContain(text: string, exactMatch: boolean, severity: LogLevel) {
+    const logs = getTestLogger().getLoggedEntries(severity)
     assert.ok(
-        getTestLogger()
-            .getLoggedEntries(severity)
-            .some((e) =>
-                e instanceof Error
-                    ? exactMatch
-                        ? e.message === text
-                        : e.message.includes(text)
-                    : exactMatch
-                      ? e === text
-                      : e.includes(text)
-            ),
+        logs.some((e) =>
+            e instanceof Error
+                ? exactMatch
+                    ? e.message === text
+                    : e.message.includes(text)
+                : exactMatch
+                  ? e === text
+                  : e.includes(text)
+        ),
         `Expected to find "${text}" in the logs as type "${severity}"`
     )
 }

packages/core/src/test/lambda/vue/remoteInvoke/invokeLambda.test.ts

@@ -16,11 +16,11 @@ import { getTestWindow } from '../../../shared/vscode/window'
 import { LambdaFunctionNode } from '../../../../lambda/explorer/lambdaFunctionNode'
 import * as utils from '../../../../lambda/utils'
 import { HttpResourceFetcher } from '../../../../shared/resourcefetcher/httpResourceFetcher'
-import { getLogger } from '../../../../shared/logger'
 import { ExtContext } from '../../../../shared/extensions'
 import { FakeExtensionContext } from '../../../fakeExtensionContext'
 import * as samCliRemoteTestEvent from '../../../../shared/sam/cli/samCliRemoteTestEvent'
 import { TestEventsOperation, SamCliRemoteTestEventsParameters } from '../../../../shared/sam/cli/samCliRemoteTestEvent'
+import { assertLogsContain } from '../../../globalSetup.test'
 
 describe('RemoteInvokeWebview', () => {
     let outputChannel: vscode.OutputChannel
@@ -190,20 +190,11 @@ describe('RemoteInvokeWebview', () => {
 
             getTestWindow().onDidShowDialog((d) => d.selectItem(fileUri))
 
-            const loggerErrorStub = sinon.stub(getLogger(), 'error')
-
-            try {
-                await assert.rejects(
-                    async () => await remoteInvokeWebview.promptFile(),
-                    new Error('Failed to read selected file')
-                )
-                assert.strictEqual(loggerErrorStub.calledOnce, true)
-                assert.strictEqual(loggerErrorStub.firstCall.args[0], 'readFileSync: Failed to read file at path %s %O')
-                assert.strictEqual(loggerErrorStub.firstCall.args[1], fileUri.fsPath)
-                assert(loggerErrorStub.firstCall.args[2] instanceof Error)
-            } finally {
-                loggerErrorStub.restore()
-            }
+            await assert.rejects(
+                async () => await remoteInvokeWebview.promptFile(),
+                new Error('Failed to read selected file')
+            )
+            assertLogsContain('readFileSync: Failed to read file at path %s %O', true, 'error')
         })
     })
 

packages/core/src/test/lambda/vue/samInvokeBackend.test.ts

@@ -22,12 +22,12 @@ import path from 'path'
 import { addCodiconToString, fs, makeTemporaryToolkitFolder } from '../../../shared'
 import { LaunchConfiguration } from '../../../shared/debug/launchConfiguration'
 import { getTestWindow } from '../..'
-import { getLogger } from '../../../shared/logger'
 import * as extensionUtilities from '../../../shared/extensionUtilities'
 import * as samInvokeBackend from '../../../lambda/vue/configEditor/samInvokeBackend'
 import { SamDebugConfigProvider } from '../../../shared/sam/debugger/awsSamDebugger'
 import sinon from 'sinon'
 import * as nls from 'vscode-nls'
+import { assertLogsContain } from '../../../test/globalSetup.test'
 
 const localize = nls.loadMessageBundle()
 
@@ -438,19 +438,13 @@ describe('SamInvokeWebview', () => {
 
             getTestWindow().onDidShowDialog((window) => window.selectItem(fileUri))
 
-            const loggerErrorStub = sinon.stub(getLogger(), 'error')
-
             try {
                 await assert.rejects(
                     async () => await samInvokeWebview.promptFile(),
                     new Error('Failed to read selected file')
                 )
-                assert.strictEqual(loggerErrorStub.calledOnce, true)
-                assert.strictEqual(loggerErrorStub.firstCall.args[0], 'readFileSync: Failed to read file at path %s %O')
-                assert.strictEqual(loggerErrorStub.firstCall.args[1], fileUri.fsPath)
-                assert(loggerErrorStub.firstCall.args[2] instanceof Error)
+                assertLogsContain('readFileSync: Failed to read file at path %s %O', true, 'error')
             } finally {
-                loggerErrorStub.restore()
                 await fs.delete(tempFolder, { recursive: true })
             }
         })