test(logger): test logger does not format objects as expected

packages/core/src/test/awsService/appBuilder/explorer/samProject.test.ts

@@ -64,21 +64,21 @@ describe('samProject', () => {
             assert.equal(region, undefined)
         })
 
-        it('returns {} when (unlikely) given an undefind project root uri', async () => {
+        it('returns {} when (unlikely) given an undefined project root uri', async () => {
             const wrapperCall = async (projectRootUri: any) => {
                 return await getStackName(projectRootUri)
             }
 
             const result = await wrapperCall(undefined)
             assert.deepStrictEqual(result, {})
-            assertLogsContain('Error getting stack name or region information: No project folder found', true, 'warn')
+            assertLogsContain('Error getting stack name or region information: No project folder found', false, 'warn')
         })
 
         it('returns empty object give no samconfig file found', async () => {
             // simulate error when no samconfig.toml file in directory
             const result = await getStackName(projectRoot)
             assert.deepStrictEqual(result, {})
-            assertLogsContain('No stack name or region information available in samconfig.toml: %O', true, 'info')
+            assertLogsContain('No stack name or region information available in samconfig.toml', false, 'info')
         })
 
         it('returns empty object give error parsing samconfig file', async () => {

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

@@ -194,7 +194,7 @@ describe('RemoteInvokeWebview', () => {
                 async () => await remoteInvokeWebview.promptFile(),
                 new Error('Failed to read selected file')
             )
-            assertLogsContain('readFileSync: Failed to read file at path %s %O', true, 'error')
+            assertLogsContain('readFileSync: Failed to read file at path', false, 'error')
         })
     })
 

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

@@ -443,7 +443,7 @@ describe('SamInvokeWebview', () => {
                     async () => await samInvokeWebview.promptFile(),
                     new Error('Failed to read selected file')
                 )
-                assertLogsContain('readFileSync: Failed to read file at path %s %O', true, 'error')
+                assertLogsContain('readFileSync: Failed to read file at path', false, 'error')
             } finally {
                 await fs.delete(tempFolder, { recursive: true })
             }

packages/core/src/test/shared/applicationBuilder/explorer/nodes/deployedNode.test.ts

@@ -214,7 +214,7 @@ describe('generateDeployedNode', () => {
                 lambdaDeployedNodeInput.resourceTreeEntity
             )
 
-            assertLogsContain('Error getting Lambda configuration %O', true, 'error')
+            assertLogsContain('Error getting Lambda configuration', false, 'error')
             assert(deployedResourceNodes.length === 1)
 
             // Check placeholder propertries

packages/core/src/test/shared/schemas.test.ts

@@ -42,32 +42,35 @@ describe('SchemaService', function () {
 
     it('assigns schemas to the yaml extension', async function () {
         const stub = sinon.stub()
+        const fooUri = vscode.Uri.parse('/foo')
+        const barUri = vscode.Uri.parse('/bar')
         fakeYamlExtension.assignSchema = stub
         service.registerMapping({
-            uri: vscode.Uri.parse('/foo'),
+            uri: fooUri,
             type: 'yaml',
             schema: 'cfn',
         })
         service.registerMapping({
-            uri: vscode.Uri.parse('/bar'),
+            uri: barUri,
             type: 'yaml',
             schema: 'sam',
         })
         await service.processUpdates()
-        assert(stub.firstCall.calledWithExactly(vscode.Uri.file('/foo'), cfnSchema))
-        assert(stub.secondCall.calledWithExactly(vscode.Uri.file('/bar'), samSchema))
+        assert(stub.firstCall.calledWithExactly(fooUri, cfnSchema))
+        assert(stub.secondCall.calledWithExactly(barUri, samSchema))
     })
 
     it('removes schemas from the yaml extension', async function () {
         const stub = sinon.stub()
+        const fooUri = vscode.Uri.parse('/foo')
         fakeYamlExtension.removeSchema = stub
         service.registerMapping({
-            uri: vscode.Uri.parse('/foo'),
+            uri: fooUri,
             type: 'yaml',
             schema: undefined,
         })
         await service.processUpdates()
-        assert(stub.calledOnceWithExactly(vscode.Uri.file('/foo')))
+        assert(stub.calledOnceWithExactly(fooUri))
     })
 
     it('registers schemas to json configuration', async function () {

packages/core/src/test/testLogger.test.ts

@@ -0,0 +1,61 @@
+/*!
+ * Copyright Amazon.com, Inc. or its affiliates. All Rights Reserved.
+ * SPDX-License-Identifier: Apache-2.0
+ */
+
+import assert from 'assert'
+import { getLogger } from '../shared'
+import { assertLogsContain, getTestLogger } from './globalSetup.test'
+
+describe('TestLogger', function () {
+    describe('assertLogsContain', function () {
+        it('checks only at specified log level', function () {
+            const logger = getLogger()
+            logger.info('here is some info')
+            logger.debug('here is some debug')
+
+            assertLogsContain('here is some info', true, 'info')
+            assert.throws(() => assertLogsContain('here is some info', true, 'debug'))
+
+            assertLogsContain('here is some debug', true, 'debug')
+            assert.throws(() => assertLogsContain('here is some debug', true, 'info'))
+        })
+
+        it('only requires substring without exactMatch=true', function () {
+            const logger = getLogger()
+            logger.info('here is some info')
+            logger.debug('here is some debug')
+
+            assertLogsContain('some info', false, 'info')
+            assertLogsContain('some debug', false, 'debug')
+        })
+    })
+
+    it('formats objects into logs', function () {
+        const testObj = {
+            info: 'some info',
+        }
+
+        getLogger().debug('here is my testObj: %O', testObj)
+        assertLogsContain(`here is my testObj: { info: 'some info' }`, true, 'debug')
+    })
+
+    it('has one logging entry for each logging statement', function () {
+        const logger = getLogger()
+        const startingEntries = getTestLogger().getLoggedEntries().length
+        logger.info('here is some info %O', { info: 'this is info' })
+        logger.debug('here is some debug %O', { debug: 'this is debug' })
+        assert.strictEqual(getTestLogger().getLoggedEntries().length - startingEntries, 2)
+    })
+
+    it('returns entry number on each log statement', function () {
+        const logger = getLogger()
+        const startingEntryNumber = getTestLogger().getLoggedEntries().length
+        const entry1 = logger.info('here is some info %O', { info: 'this is info' })
+        const entry2 = logger.debug('here is some debug %O', { debug: 'this is debug' })
+        const entry3 = logger.debug('here is some warn %O', { warn: 'this is warn' })
+        assert.strictEqual(entry1, startingEntryNumber)
+        assert.strictEqual(entry2, startingEntryNumber + 1)
+        assert.strictEqual(entry3, startingEntryNumber + 2)
+    })
+})

packages/core/src/test/testLogger.ts

@@ -3,64 +3,48 @@
  * SPDX-License-Identifier: Apache-2.0
  */
 
-import { Loggable, Logger, LogLevel } from '../shared/logger'
-import { compareLogLevel } from '../shared/logger/logger'
+import { Loggable, LogLevel } from '../shared/logger'
+import { BaseLogger, compareLogLevel } from '../shared/logger/logger'
 import { Uri } from 'vscode'
+import util from 'util'
+import { isWeb } from '../shared'
+import { inspect } from '../shared/utilities/collectionUtils'
 
 /**
  * In-memory Logger implementation suitable for use by tests.
  */
-export class TestLogger implements Logger {
+export class TestLogger extends BaseLogger {
     private readonly loggedEntries: {
         logLevel: LogLevel
         entry: Loggable
     }[] = []
     private count: number = 0
-    public constructor(private logLevel: LogLevel = 'debug') {}
-    logFile?: Uri | undefined
-
-    public enableDebugConsole(): void {}
-
-    public log(logLevel: LogLevel, ...message: Loggable[]): number {
-        return this.addLoggedEntries(logLevel, message)
-    }
-
-    public debug(...message: Loggable[]): number {
-        return this.addLoggedEntries('debug', message)
-    }
-
-    public verbose(...message: Loggable[]): number {
-        return this.addLoggedEntries('verbose', message)
+    public constructor(private logLevel: LogLevel = 'debug') {
+        super()
     }
 
-    public info(...message: Loggable[]): number {
-        return this.addLoggedEntries('info', message)
-    }
-
-    public warn(...message: Loggable[]): number {
-        return this.addLoggedEntries('warn', message)
-    }
-
-    public error(...message: Loggable[]): number {
-        return this.addLoggedEntries('error', message)
-    }
+    public enableDebugConsole(): void {}
 
     public getLoggedEntries(...logLevels: LogLevel[]): Loggable[] {
         return this.loggedEntries
             .filter((loggedEntry) => logLevels.length === 0 || logLevels.includes(loggedEntry.logLevel))
             .map((loggedEntry) => loggedEntry.entry)
     }
 
-    public sendToLog(logLevel: LogLevel, msg: string, ...entries: Loggable[]): number {
-        return this.addLoggedEntries(logLevel, [msg, ...entries])
+    public sendToLog(logLevel: LogLevel, msg: string, ...meta: any[]): number {
+        return this.addLoggedEntries(logLevel, msg, ...meta)
+    }
+
+    private formatString(message: string, ...meta: any[]): string {
+        // Want to avoid reimplementing nodes `format` so instead concat to end of string
+        // Node's format implementation: https://github.com/nodejs/node/blob/3178a762d6a2b1a37b74f02266eea0f3d86603be/lib/internal/util/inspect.js#L2191-L2315
+        return isWeb() ? [message, meta.map((s) => inspect(s))].join(' ') : util.format(message, ...meta)
     }
 
-    private addLoggedEntries(logLevel: LogLevel, entries: Loggable[]): number {
-        entries.forEach((entry) => {
-            this.loggedEntries.push({
-                logLevel,
-                entry,
-            })
+    private addLoggedEntries(logLevel: LogLevel, message: Loggable, ...meta: any[]): number {
+        this.loggedEntries.push({
+            logLevel,
+            entry: typeof message === 'string' && meta.length > 0 ? this.formatString(message, ...meta) : message,
         })
 
         return this.count++