build(lint): throw error on JSON.stringify within a logging statement

.eslintrc.js

@@ -162,7 +162,7 @@ module.exports = {
         'aws-toolkits/no-incorrect-once-usage': 'error',
         'aws-toolkits/no-string-exec-for-child-process': 'error',
         'aws-toolkits/no-console-log': 'error',
-
+        'aws-toolkits/no-json-stringify-in-log': 'error',
         'no-restricted-imports': [
             'error',
             {

packages/amazonq/src/inlineChat/provider/inlineChatProvider.ts

@@ -111,20 +111,15 @@ export class InlineChatProvider {
 
         const request = triggerPayloadToChatRequest(triggerPayload)
         const session = this.sessionStorage.getSession(tabID)
-        getLogger().info(
-            `request from tab: ${tabID} conversationID: ${session.sessionIdentifier} request: ${JSON.stringify(
-                request
-            )}`
-        )
+        getLogger().info(`request from tab: ${tabID} conversationID: ${session.sessionIdentifier} request: %O`, request)
 
         let response: GenerateAssistantResponseCommandOutput | undefined = undefined
         session.createNewTokenSource()
         try {
             response = await session.chatSso(request)
             getLogger().info(
-                `response to tab: ${tabID} conversationID: ${session.sessionIdentifier} requestID: ${response.$metadata.requestId} metadata: ${JSON.stringify(
-                    response.$metadata
-                )}`
+                `response to tab: ${tabID} conversationID: ${session.sessionIdentifier} requestID: ${response.$metadata.requestId} metadata: %O`,
+                response.$metadata
             )
         } catch (e: any) {
             this.processException(e, tabID)

packages/core/src/applicationcomposer/messageHandlers/generateResourceHandler.ts

@@ -86,13 +86,13 @@ async function generateResource(cfnType: string) {
         // TODO-STARLING - Revisit to see if timeout still needed prior to launch
         const data = await timeout(amazonqApi.chatApi.chat(request), TIMEOUT)
         const initialResponseTime = globals.clock.Date.now() - startTime
-        getLogger().debug(`CW Chat initial response: ${JSON.stringify(data, undefined, 2)}, ${initialResponseTime} ms`)
+        getLogger().debug(`CW Chat initial response: %O, ${initialResponseTime} ms`, data)
         if (data['$metadata']) {
             metadata = data['$metadata']
         }
 
         if (data.generateAssistantResponseResponse === undefined) {
-            getLogger().debug(`Error: Unexpected model response: ${JSON.stringify(data, undefined, 2)}`)
+            getLogger().debug(`Error: Unexpected model response: %O`, data)
             throw new Error('No model response')
         }
 
@@ -141,12 +141,15 @@ async function generateResource(cfnType: string) {
             `CW Chat Debug message:
              cfnType = "${cfnType}",
              conversationId = ${conversationId},
-             metadata = \n${JSON.stringify(metadata, undefined, 2)},
-             supplementaryWebLinks = \n${JSON.stringify(supplementaryWebLinks, undefined, 2)},
-             references = \n${JSON.stringify(references, undefined, 2)},
+             metadata = %O,
+             supplementaryWebLinks = %O,
+             references = %O,
              response = "${response}",
              initialResponse = ${initialResponseTime} ms,
-             elapsed time = ${elapsedTime} ms`
+             elapsed time = ${elapsedTime} ms`,
+            metadata,
+            supplementaryWebLinks,
+            references
         )
 
         return {
@@ -163,7 +166,7 @@ async function generateResource(cfnType: string) {
         getLogger().debug(`CW Chat error: ${error.name} - ${error.message}`)
         if (error.$metadata) {
             const { requestId, cfId, extendedRequestId } = error.$metadata
-            getLogger().debug(JSON.stringify({ requestId, cfId, extendedRequestId }, undefined, 2))
+            getLogger().debug('%O', { requestId, cfId, extendedRequestId })
         }
 
         throw error

packages/core/src/codewhisperer/service/recommendationHandler.ts

@@ -220,10 +220,7 @@ export class RecommendationHandler {
              * Validate request
              */
             if (!EditorContext.validateRequest(request)) {
-                getLogger().verbose(
-                    'Invalid Request : ',
-                    JSON.stringify(request, undefined, EditorContext.getTabSize())
-                )
+                getLogger().verbose('Invalid Request: %O', request)
                 const languageName = request.fileContext.programmingLanguage.languageName
                 if (!runtimeLanguageContext.isLanguageSupported(languageName)) {
                     errorMessage = `${languageName} is currently not supported by Amazon Q inline suggestions`

packages/core/src/codewhispererChat/controllers/chat/controller.ts

@@ -650,11 +650,7 @@ export class ChatController {
 
         const request = triggerPayloadToChatRequest(triggerPayload)
         const session = this.sessionStorage.getSession(tabID)
-        getLogger().info(
-            `request from tab: ${tabID} conversationID: ${session.sessionIdentifier} request: ${JSON.stringify(
-                request
-            )}`
-        )
+        getLogger().info(`request from tab: ${tabID} conversationID: ${session.sessionIdentifier} request: %O`, request)
         let response: MessengerResponseType | undefined = undefined
         session.createNewTokenSource()
         try {
@@ -679,7 +675,8 @@ export class ChatController {
             getLogger().info(
                 `response to tab: ${tabID} conversationID: ${session.sessionIdentifier} requestID: ${
                     response.$metadata.requestId
-                } metadata: ${JSON.stringify(response.$metadata)}`
+                } metadata: %O`,
+                response.$metadata
             )
             await this.messenger.sendAIResponse(response, session, tabID, triggerID, triggerPayload)
         } catch (e: any) {

packages/core/src/shared/crashMonitoring.ts

@@ -297,7 +297,7 @@ class CrashChecker {
                     // Example is if I hit the red square in the debug menu, it is a non-graceful shutdown. But the regular
                     // 'x' button in the Debug IDE instance is a graceful shutdown.
                     if (ext.isDebug) {
-                        devLogger?.debug(`crashMonitoring: DEBUG instance crashed: ${JSON.stringify(ext)}`)
+                        devLogger?.debug(`crashMonitoring: DEBUG instance crashed: %O`, ext)
                         return
                     }
 
@@ -318,7 +318,10 @@ class CrashChecker {
                 // Sanity check: ENSURE THAT AFTER === ACTUAL or this implies that our data is out of sync
                 const afterActual = (await state.getAllExts()).map((i) => truncateUuid(i.sessionId))
                 devLogger?.debug(
-                    `crashMonitoring: CHECKED: Result of cleaning up crashed instances\nBEFORE: ${JSON.stringify(before)}\nAFTER:  ${JSON.stringify(after)}\nACTUAL: ${JSON.stringify(afterActual)}`
+                    `crashMonitoring: CHECKED: Result of cleaning up crashed instances\nBEFORE: %O \nAFTER:  %O \nACTUAL: %O`,
+                    before,
+                    after,
+                    afterActual
                 )
             }
 

packages/core/src/shared/env/resolveEnv.ts

@@ -246,7 +246,7 @@ async function doResolveUnixShellEnv(timeout: Timeout): Promise<typeof process.e
             }
         }
 
-        getLogger().debug(`getUnixShellEnvironment#spawn:${JSON.stringify(shellArgs)}, command:${command}`)
+        getLogger().debug(`getUnixShellEnvironment#spawn:%O, command:${command}`, shellArgs)
 
         const child = new ChildProcess(systemShellUnix, [...shellArgs, command], {
             spawnOptions: {

packages/core/src/shared/featureConfig.ts

@@ -110,7 +110,7 @@ export class FeatureConfigProvider {
                     })
                 })
             })
-            getLogger().info('AB Testing Cohort Assignments %s', JSON.stringify(response.featureEvaluations))
+            getLogger().info('AB Testing Cohort Assignments %O', response.featureEvaluations)
 
             const customizationArnOverride = this.featureConfigs.get(Features.customizationArnOverride)?.value
                 ?.stringValue

packages/core/src/shared/sam/debugger/awsSamDebugger.ts

@@ -308,7 +308,7 @@ export class SamDebugConfigProvider implements vscode.DebugConfigurationProvider
                     }
                 }
             }
-            getLogger().verbose(`provideDebugConfigurations: debugconfigs: ${JSON.stringify(configs)}`)
+            getLogger().verbose(`provideDebugConfigurations: debugconfigs: %O`, configs)
         }
 
         return configs
@@ -449,7 +449,7 @@ export class SamDebugConfigProvider implements vscode.DebugConfigurationProvider
             } else if (rv.message) {
                 void vscode.window.showInformationMessage(rv.message)
             }
-            getLogger().verbose(`SAM debug: config: ${JSON.stringify(config.name)}`)
+            getLogger().verbose(`SAM debug: config %s:`, config.name)
         }
 
         const editor = vscode.window.activeTextEditor

packages/core/src/shared/sam/debugger/pythonSamDebug.ts

@@ -49,7 +49,7 @@ async function makePythonDebugManifest(params: {
     if (await fileExists(manfestPath)) {
         manifestText = await readFileAsString(manfestPath)
     }
-    getLogger().debug(`pythonCodeLensProvider.makePythonDebugManifest params: ${JSON.stringify(params, undefined, 2)}`)
+    getLogger().debug(`pythonCodeLensProvider.makePythonDebugManifest params: %O`, params)
     // TODO: If another module name includes the string "ikp3db", this will be skipped...
     // HACK: Cloud9-created Lambdas hardcode ikp3db 1.1.4, which only functions with Python 3.6 (which we don't support)
     //       Remove any ikp3db dependency if it exists and manually add a non-pinned ikp3db dependency.

packages/core/src/shared/sam/localLambdaRunner.ts

@@ -453,16 +453,11 @@ export async function attachDebugger({
     },
     ...params
 }: AttachDebuggerContext): Promise<void> {
-    getLogger().debug(
-        `localLambdaRunner.attachDebugger: startDebugging with config: ${JSON.stringify(
-            {
-                name: params.debugConfig.name,
-                invokeTarget: params.debugConfig.invokeTarget,
-            },
-            undefined,
-            2
-        )}`
-    )
+    const obj = {
+        name: params.debugConfig.name,
+        invokeTarget: params.debugConfig.invokeTarget,
+    }
+    getLogger().debug(`localLambdaRunner.attachDebugger: startDebugging with config: %O`, obj)
 
     getLogger().info(localize('AWS.output.sam.local.attaching', 'Attaching debugger to SAM application...'))
 

packages/core/src/shared/sam/sync.ts

@@ -716,7 +716,7 @@ export async function runSync(
 
         await confirmDevStack()
         const params = syncParam ?? (await (await getSyncWizard(deployType, arg, validate)).run())
-        getLogger().info(JSON.stringify(params))
+        getLogger().info('%O', params)
 
         if (params === undefined) {
             throw new CancellationError('user')

packages/core/src/shared/telemetry/telemetryService.ts

@@ -470,7 +470,7 @@ export function filterTelemetryCacheEvents(input: any): MetricDatum[] {
                 !Object.prototype.hasOwnProperty.call(item, 'EpochTimestamp') ||
                 !Object.prototype.hasOwnProperty.call(item, 'Unit')
             ) {
-                getLogger().warn(`skipping invalid item in telemetry cache: ${JSON.stringify(item)}\n`)
+                getLogger().warn(`skipping invalid item in telemetry cache: %O\n`, item)
 
                 return false
             }

packages/core/src/shared/utilities/map.ts

@@ -43,7 +43,7 @@ export abstract class NestedMap<Key, Value = { [key: string]: any }> implements
     delete(key: Key, reason?: string): void {
         delete this.data[this.hash(key)]
         if (reason) {
-            getLogger().debug(`${this.name}: cleared cache, key: ${JSON.stringify(key)}, reason: ${reason}`)
+            getLogger().debug(`${this.name}: cleared cache, key: %O, reason: ${reason}`, key)
         }
     }
 

packages/core/src/ssmDocument/commands/publishDocument.ts

@@ -83,7 +83,7 @@ export async function createDocument(
         }
 
         const createResult = await client.createDocument(request)
-        logger.info(`Created Systems Manager Document: ${JSON.stringify(createResult.DocumentDescription)}`)
+        logger.info(`Created Systems Manager Document: %O`, createResult.DocumentDescription)
         void vscode.window.showInformationMessage(`Created Systems Manager Document: ${wizardResponse.name}`)
     } catch (err) {
         const error = err as Error
@@ -118,7 +118,7 @@ export async function updateDocument(
 
         const updateResult = await client.updateDocument(request)
 
-        logger.info(`Updated Systems Manager Document: ${JSON.stringify(updateResult.DocumentDescription)}`)
+        logger.info(`Updated Systems Manager Document: %O`, updateResult.DocumentDescription)
         void vscode.window.showInformationMessage(`Updated Systems Manager Document: ${wizardResponse.name}`)
 
         const isConfirmed = await showConfirmationMessage({

packages/core/src/test/codewhisperer/testUtil.ts

@@ -76,7 +76,7 @@ export function createMockTextEditor(
                     insert: sinon.spy(),
                     setEndOfLine: sinon.spy(),
                     delete: function (_location: vscode.Selection | vscode.Range): void {
-                        getLogger().info(`delete ${JSON.stringify(_location)}`)
+                        getLogger().info(`delete %O`, _location)
                     },
                 }
                 resolve(editor)

plugins/eslint-plugin-aws-toolkits/index.ts

@@ -9,6 +9,7 @@ import NoIncorrectOnceUsage from './lib/rules/no-incorrect-once-usage'
 import NoOnlyInTests from './lib/rules/no-only-in-tests'
 import NoStringExecForChildProcess from './lib/rules/no-string-exec-for-child-process'
 import NoConsoleLog from './lib/rules/no-console-log'
+import noJsonStringifyInLog from './lib/rules/no-json-stringify-in-log'
 
 const rules = {
     'no-await-on-vscode-msg': NoAwaitOnVscodeMsg,
@@ -17,6 +18,7 @@ const rules = {
     'no-only-in-tests': NoOnlyInTests,
     'no-string-exec-for-child-process': NoStringExecForChildProcess,
     'no-console-log': NoConsoleLog,
+    'no-json-stringify-in-log': noJsonStringifyInLog,
 }
 
 export { rules }

plugins/eslint-plugin-aws-toolkits/lib/rules/no-json-stringify-in-log.ts

@@ -0,0 +1,101 @@
+/*!
+ * Copyright Amazon.com, Inc. or its affiliates. All Rights Reserved.
+ * SPDX-License-Identifier: Apache-2.0
+ */
+
+import { AST_NODE_TYPES, ESLintUtils, TSESTree } from '@typescript-eslint/utils'
+import { Rule } from 'eslint'
+
+export const errMsg =
+    'Avoid using JSON.stringify within logging and error messages, prefer %O. Note: %O has a depth limit of 2'
+
+/**
+ * Check if a given expression is a JSON.stringify call.
+ */
+function isJsonStringifyCall(node: TSESTree.CallExpressionArgument): boolean {
+    return (
+        node.type === AST_NODE_TYPES.CallExpression &&
+        node.callee.type === AST_NODE_TYPES.MemberExpression &&
+        node.callee.object.type === AST_NODE_TYPES.Identifier &&
+        node.callee.object.name === 'JSON' &&
+        node.callee.property.type === AST_NODE_TYPES.Identifier &&
+        node.callee.property.name === 'stringify'
+    )
+}
+
+function isTemplateWithStringifyCall(node: TSESTree.CallExpressionArgument): boolean {
+    return (
+        node.type === AST_NODE_TYPES.TemplateLiteral &&
+        node.expressions.some((e: TSESTree.Expression) => isJsonStringifyCall(e))
+    )
+}
+
+/**
+ * Check if node is representing syntax of the form getLogger().f(msg) for some f and msg or
+ * if it is doing so indirectly via a logger variable.
+ */
+function isLoggerCall(node: TSESTree.CallExpression): boolean {
+    return (
+        node.callee.type === AST_NODE_TYPES.MemberExpression &&
+        (isGetLoggerCall(node.callee.object) || isDisguisedGetLoggerCall(node.callee.object)) &&
+        node.callee.property.type === AST_NODE_TYPES.Identifier &&
+        ['debug', 'verbose', 'info', 'warn', 'error'].includes(node.callee.property.name)
+    )
+}
+
+function isGetLoggerCall(node: TSESTree.Expression): boolean {
+    return (
+        node.type === AST_NODE_TYPES.CallExpression &&
+        node.callee.type === AST_NODE_TYPES.Identifier &&
+        node.callee.name === 'getLogger'
+    )
+}
+
+/**
+ * Use two simple heuristics to detect `disguised` logger calls. This is when we log without getLogger in the same statement.
+ * Ex.
+ *      const logger = getLogger()
+ *      logger.debug(m)
+ * To catch these we try two checks:
+ *  1) If the left side is an identifier including the word logger
+ *  2) If the left side is a property of some object, including the word logger.
+ */
+function isDisguisedGetLoggerCall(node: TSESTree.Expression): boolean {
+    return (
+        (node.type === AST_NODE_TYPES.Identifier && node.name.toLowerCase().includes('logger')) ||
+        (node.type === AST_NODE_TYPES.MemberExpression &&
+            node.property.type === AST_NODE_TYPES.Identifier &&
+            node.property.name.toLowerCase().includes('logger'))
+    )
+}
+
+export default ESLintUtils.RuleCreator.withoutDocs({
+    meta: {
+        docs: {
+            description: 'disallow use of JSON.stringify in logs and errors, to encourage use %O',
+            recommended: 'recommended',
+        },
+        messages: {
+            errMsg,
+        },
+        type: 'problem',
+        fixable: 'code',
+        schema: [],
+    },
+    defaultOptions: [],
+    create(context) {
+        return {
+            CallExpression(node: TSESTree.CallExpression) {
+                if (
+                    isLoggerCall(node) &&
+                    node.arguments.some((arg) => isJsonStringifyCall(arg) || isTemplateWithStringifyCall(arg))
+                ) {
+                    return context.report({
+                        node: node,
+                        messageId: 'errMsg',
+                    })
+                }
+            },
+        }
+    },
+}) as unknown as Rule.RuleModule