From ef135ef10247ec0969bbc3cec4636d4536cdfeff Mon Sep 17 00:00:00 2001 From: Hogan Bobertz Date: Mon, 13 Jan 2025 21:01:41 -0500 Subject: [PATCH] chore(cli): use CliIoHost as logger everywhere (#32708) ### Related to #32346 ### Reason for this change Capture all logs across the CLI as IoMessages so that when we allow customers to use the CDK Core functionality programmatically, these logs are delivered to the customers as messages and now just swallowed across the CLI. ### Description of changes Prevented access to `log()` and `formatLogMessage()`. Now the only ways to log something properly are either through the exported log functions (which is how everyone was doing it anyway), or through `CliIoHost.notify()` directly. CliIoHost is now exposed as a global singleton which is currently only directly exclusively used in `logging.ts` but is effectively used everywhere as all logging functions inevitably call `CliIoHost.notify()` All logging functions now optionally support the following input types ```ts error(`operation failed: ${e}`) // infers default error code `TOOLKIT_0000` error('operation failed: %s', e) // infers default error code `TOOLKIT_0000` error({ message: 'operation failed', code: 'SDK_0001' }) // specifies error code `SDK_0001` error({ message: 'operation failed: %s', code: 'SDK_0001' }, e) // specifies error code `SDK_0001` ``` and everything is now translated into an `IoMessage` and calls `CliIoHost.notify()` from these logging functions. Nothing currently specifies any message code so it's all the generic _0000, _1000, _2000 ### Description of how you validated changes added and updated unit tests ### Checklist - [x] My code adheres to the [CONTRIBUTING GUIDE](https://github.com/aws/aws-cdk/blob/main/CONTRIBUTING.md) and [DESIGN GUIDELINES](https://github.com/aws/aws-cdk/blob/main/docs/DESIGN_GUIDELINES.md) ---- *By submitting this pull request, I confirm that my contribution is made under the terms of the Apache-2.0 license* --------- Co-authored-by: Kaizen Conroy <36202692+kaizencc@users.noreply.github.com> Co-authored-by: Momo Kornher --- .../lib/api/aws-auth/credential-plugins.ts | 7 +- .../aws-cdk/lib/api/cxapp/cloud-assembly.ts | 8 +- packages/aws-cdk/lib/api/deploy-stack.ts | 16 +- packages/aws-cdk/lib/api/deployments.ts | 1 - .../garbage-collection/garbage-collector.ts | 18 +- .../garbage-collection/progress-printer.ts | 6 +- .../aws-cdk/lib/api/hotswap-deployments.ts | 18 +- packages/aws-cdk/lib/api/logs/logs-monitor.ts | 4 +- packages/aws-cdk/lib/api/plugin/plugin.ts | 2 +- .../aws-cdk/lib/api/util/cloudformation.ts | 1 - .../cloudformation/stack-activity-monitor.ts | 32 +- packages/aws-cdk/lib/cdk-toolkit.ts | 58 ++- packages/aws-cdk/lib/cli.ts | 21 +- packages/aws-cdk/lib/commands/context.ts | 40 +- packages/aws-cdk/lib/commands/docs.ts | 4 +- packages/aws-cdk/lib/commands/doctor.ts | 18 +- packages/aws-cdk/lib/commands/migrate.ts | 32 +- packages/aws-cdk/lib/context-providers/ami.ts | 4 +- packages/aws-cdk/lib/diff.ts | 6 +- packages/aws-cdk/lib/import.ts | 12 +- packages/aws-cdk/lib/init.ts | 36 +- packages/aws-cdk/lib/logging.ts | 382 +++++++++++------- packages/aws-cdk/lib/notices.ts | 18 +- packages/aws-cdk/lib/toolkit/cli-io-host.ts | 138 +++++-- packages/aws-cdk/lib/util/asset-publishing.ts | 6 +- packages/aws-cdk/lib/version.ts | 4 +- packages/aws-cdk/test/api/exec.test.ts | 6 +- .../aws-cdk/test/api/logs/cli-logging.test.ts | 162 -------- .../aws-cdk/test/api/logs/logging.test.ts | 333 +++++++++++++++ .../aws-cdk/test/api/sdk-provider.test.ts | 4 +- .../test/api/stack-activity-monitor.test.ts | 30 +- packages/aws-cdk/test/cli.test.ts | 16 +- packages/aws-cdk/test/notices.test.ts | 26 +- .../aws-cdk/test/toolkit/cli-io-host.test.ts | 299 +++++--------- packages/aws-cdk/test/util/silent.ts | 2 +- packages/aws-cdk/test/version.test.ts | 8 +- 36 files changed, 983 insertions(+), 795 deletions(-) delete mode 100644 packages/aws-cdk/test/api/logs/cli-logging.test.ts create mode 100644 packages/aws-cdk/test/api/logs/logging.test.ts diff --git a/packages/aws-cdk/lib/api/aws-auth/credential-plugins.ts b/packages/aws-cdk/lib/api/aws-auth/credential-plugins.ts index 1540cf66e1922..84303ffb4c5ca 100644 --- a/packages/aws-cdk/lib/api/aws-auth/credential-plugins.ts +++ b/packages/aws-cdk/lib/api/aws-auth/credential-plugins.ts @@ -1,8 +1,8 @@ -import { inspect } from 'util'; +import { inspect, format } from 'util'; import type { CredentialProviderSource, ForReading, ForWriting, PluginProviderResult, SDKv2CompatibleCredentials, SDKv3CompatibleCredentialProvider, SDKv3CompatibleCredentials } from '@aws-cdk/cli-plugin-contract'; import type { AwsCredentialIdentity, AwsCredentialIdentityProvider } from '@smithy/types'; import { credentialsAboutToExpire, makeCachingProvider } from './provider-caching'; -import { debug, warning } from '../../logging'; +import { debug, warning, info } from '../../logging'; import { AuthenticationError } from '../../toolkit/error'; import { formatErrorMessage } from '../../util/error'; import { Mode } from '../plugin/mode'; @@ -151,8 +151,7 @@ function v3ProviderFromV2Credentials(x: SDKv2CompatibleCredentials): AwsCredenti function refreshFromPluginProvider(current: AwsCredentialIdentity, producer: () => Promise): AwsCredentialIdentityProvider { return async () => { - // eslint-disable-next-line no-console - console.error(current, Date.now()); + info(format(current), Date.now()); if (credentialsAboutToExpire(current)) { const newCreds = await producer(); if (!isV3Credentials(newCreds)) { diff --git a/packages/aws-cdk/lib/api/cxapp/cloud-assembly.ts b/packages/aws-cdk/lib/api/cxapp/cloud-assembly.ts index d02e9b12d5008..4f0fa296ec123 100644 --- a/packages/aws-cdk/lib/api/cxapp/cloud-assembly.ts +++ b/packages/aws-cdk/lib/api/cxapp/cloud-assembly.ts @@ -2,7 +2,7 @@ import * as cxapi from '@aws-cdk/cx-api'; import * as chalk from 'chalk'; import { minimatch } from 'minimatch'; import * as semver from 'semver'; -import { error, print, warning } from '../../logging'; +import { error, info, warning } from '../../logging'; import { ToolkitError } from '../../toolkit/error'; import { flatten } from '../../util'; @@ -264,7 +264,7 @@ export class StackCollection { printMessage(error, 'Error', message.id, message.entry); break; case cxapi.SynthesisMessageLevel.INFO: - printMessage(print, 'Info', message.id, message.entry); + printMessage(info, 'Info', message.id, message.entry); break; } } @@ -346,7 +346,7 @@ function includeDownstreamStacks( } while (madeProgress); if (added.length > 0) { - print('Including depending stacks: %s', chalk.bold(added.join(', '))); + info('Including depending stacks: %s', chalk.bold(added.join(', '))); } } @@ -376,7 +376,7 @@ function includeUpstreamStacks( } if (added.length > 0) { - print('Including dependency stacks: %s', chalk.bold(added.join(', '))); + info('Including dependency stacks: %s', chalk.bold(added.join(', '))); } } diff --git a/packages/aws-cdk/lib/api/deploy-stack.ts b/packages/aws-cdk/lib/api/deploy-stack.ts index 696340d05010e..b9853737ec832 100644 --- a/packages/aws-cdk/lib/api/deploy-stack.ts +++ b/packages/aws-cdk/lib/api/deploy-stack.ts @@ -15,7 +15,7 @@ import { CfnEvaluationException } from './evaluate-cloudformation-template'; import { HotswapMode, HotswapPropertyOverrides, ICON } from './hotswap/common'; import { tryHotswapDeployment } from './hotswap-deployments'; import { addMetadataAssetsToManifest } from '../assets'; -import { debug, print, warning } from '../logging'; +import { debug, info, warning } from '../logging'; import { changeSetHasNoChanges, CloudFormationStack, @@ -333,7 +333,7 @@ export async function deployStack(options: DeployStackOptions): Promise { - print('%s: %s stack...', chalk.bold(this.stackName), this.update ? 'updating' : 'creating'); + info('%s: %s stack...', chalk.bold(this.stackName), this.update ? 'updating' : 'creating'); const startTime = new Date(); diff --git a/packages/aws-cdk/lib/api/deployments.ts b/packages/aws-cdk/lib/api/deployments.ts index 62a6146d6d5d5..32650ac7a3549 100644 --- a/packages/aws-cdk/lib/api/deployments.ts +++ b/packages/aws-cdk/lib/api/deployments.ts @@ -715,7 +715,6 @@ export class Deployments { // No need to validate anymore, we already did that during build const publisher = this.cachedPublisher(assetManifest, stackEnv, options.stackName); - // eslint-disable-next-line no-console await publisher.publishEntry(asset, { allowCrossAccount: await this.allowCrossAccountAssetPublishingForEnv(options.stack) }); if (publisher.hasFailures) { throw new Error(`Failed to publish asset ${asset.id}`); diff --git a/packages/aws-cdk/lib/api/garbage-collection/garbage-collector.ts b/packages/aws-cdk/lib/api/garbage-collection/garbage-collector.ts index 2d7123a6e0266..5869071d4a6cd 100644 --- a/packages/aws-cdk/lib/api/garbage-collection/garbage-collector.ts +++ b/packages/aws-cdk/lib/api/garbage-collection/garbage-collector.ts @@ -3,7 +3,7 @@ import { ImageIdentifier } from '@aws-sdk/client-ecr'; import { Tag } from '@aws-sdk/client-s3'; import * as chalk from 'chalk'; import * as promptly from 'promptly'; -import { debug, print } from '../../logging'; +import { debug, info } from '../../logging'; import { IECRClient, IS3Client, SDK, SdkProvider } from '../aws-auth'; import { DEFAULT_TOOLKIT_STACK_NAME, ToolkitInfo } from '../toolkit-info'; import { ProgressPrinter } from './progress-printer'; @@ -526,7 +526,7 @@ export class GarbageCollector { printer.reportDeletedAsset(deletables.slice(0, deletedCount)); } } catch (err) { - print(chalk.red(`Error deleting images: ${err}`)); + info(chalk.red(`Error deleting images: ${err}`)); } } @@ -559,23 +559,23 @@ export class GarbageCollector { printer.reportDeletedAsset(deletables.slice(0, deletedCount)); } } catch (err) { - print(chalk.red(`Error deleting objects: ${err}`)); + info(chalk.red(`Error deleting objects: ${err}`)); } } private async bootstrapBucketName(sdk: SDK, bootstrapStackName: string): Promise { - const info = await ToolkitInfo.lookup(this.props.resolvedEnvironment, sdk, bootstrapStackName); - return info.bucketName; + const toolkitInfo = await ToolkitInfo.lookup(this.props.resolvedEnvironment, sdk, bootstrapStackName); + return toolkitInfo.bucketName; } private async bootstrapRepositoryName(sdk: SDK, bootstrapStackName: string): Promise { - const info = await ToolkitInfo.lookup(this.props.resolvedEnvironment, sdk, bootstrapStackName); - return info.repositoryName; + const toolkitInfo = await ToolkitInfo.lookup(this.props.resolvedEnvironment, sdk, bootstrapStackName); + return toolkitInfo.repositoryName; } private async bootstrapQualifier(sdk: SDK, bootstrapStackName: string): Promise { - const info = await ToolkitInfo.lookup(this.props.resolvedEnvironment, sdk, bootstrapStackName); - return info.bootstrapStack.parameters.Qualifier; + const toolkitInfo = await ToolkitInfo.lookup(this.props.resolvedEnvironment, sdk, bootstrapStackName); + return toolkitInfo.bootstrapStack.parameters.Qualifier; } private async numObjectsInBucket(s3: IS3Client, bucket: string): Promise { diff --git a/packages/aws-cdk/lib/api/garbage-collection/progress-printer.ts b/packages/aws-cdk/lib/api/garbage-collection/progress-printer.ts index 37c75d622c966..9790dadeb0c5a 100644 --- a/packages/aws-cdk/lib/api/garbage-collection/progress-printer.ts +++ b/packages/aws-cdk/lib/api/garbage-collection/progress-printer.ts @@ -1,6 +1,6 @@ import * as chalk from 'chalk'; import { GcAsset as GCAsset } from './garbage-collector'; -import { print } from '../../logging'; +import { info } from '../../logging'; export class ProgressPrinter { private totalAssets: number; @@ -68,9 +68,9 @@ export class ProgressPrinter { const percentage = ((this.assetsScanned / this.totalAssets) * 100).toFixed(2); // print in MiB until we hit at least 1 GiB of data tagged/deleted if (Math.max(this.taggedAssetsSizeMb, this.deletedAssetsSizeMb) >= 1000) { - print(chalk.green(`[${percentage}%] ${this.assetsScanned} files scanned: ${this.taggedAsset} assets (${(this.taggedAssetsSizeMb / 1000).toFixed(2)} GiB) tagged, ${this.deletedAssets} assets (${(this.deletedAssetsSizeMb / 1000).toFixed(2)} GiB) deleted.`)); + info(chalk.green(`[${percentage}%] ${this.assetsScanned} files scanned: ${this.taggedAsset} assets (${(this.taggedAssetsSizeMb / 1000).toFixed(2)} GiB) tagged, ${this.deletedAssets} assets (${(this.deletedAssetsSizeMb / 1000).toFixed(2)} GiB) deleted.`)); } else { - print(chalk.green(`[${percentage}%] ${this.assetsScanned} files scanned: ${this.taggedAsset} assets (${this.taggedAssetsSizeMb.toFixed(2)} MiB) tagged, ${this.deletedAssets} assets (${this.deletedAssetsSizeMb.toFixed(2)} MiB) deleted.`)); + info(chalk.green(`[${percentage}%] ${this.assetsScanned} files scanned: ${this.taggedAsset} assets (${this.taggedAssetsSizeMb.toFixed(2)} MiB) tagged, ${this.deletedAssets} assets (${this.deletedAssetsSizeMb.toFixed(2)} MiB) deleted.`)); } } } diff --git a/packages/aws-cdk/lib/api/hotswap-deployments.ts b/packages/aws-cdk/lib/api/hotswap-deployments.ts index d93733bdd869b..c955148035e6d 100644 --- a/packages/aws-cdk/lib/api/hotswap-deployments.ts +++ b/packages/aws-cdk/lib/api/hotswap-deployments.ts @@ -5,7 +5,7 @@ import * as chalk from 'chalk'; import type { SDK, SdkProvider } from './aws-auth'; import type { SuccessfulDeployStackResult } from './deploy-stack'; import { EvaluateCloudFormationTemplate } from './evaluate-cloudformation-template'; -import { print } from '../logging'; +import { info } from '../logging'; import { isHotswappableAppSyncChange } from './hotswap/appsync-mapping-templates'; import { isHotswappableCodeBuildProjectChange } from './hotswap/code-build-projects'; import { @@ -400,7 +400,7 @@ function isCandidateForHotswapping( async function applyAllHotswappableChanges(sdk: SDK, hotswappableChanges: HotswappableChange[]): Promise { if (hotswappableChanges.length > 0) { - print(`\n${ICON} hotswapping resources:`); + info(`\n${ICON} hotswapping resources:`); } const limit = pLimit(10); // eslint-disable-next-line @cdklabs/promiseall-no-unbounded-parallelism @@ -415,7 +415,7 @@ async function applyHotswappableChange(sdk: SDK, hotswapOperation: HotswappableC sdk.appendCustomUserAgent(customUserAgent); for (const name of hotswapOperation.resourceNames) { - print(` ${ICON} %s`, chalk.bold(name)); + info(` ${ICON} %s`, chalk.bold(name)); } // if the SDK call fails, an error will be thrown by the SDK @@ -436,7 +436,7 @@ async function applyHotswappableChange(sdk: SDK, hotswapOperation: HotswappableC } for (const name of hotswapOperation.resourceNames) { - print(`${ICON} %s %s`, chalk.bold(name), chalk.green('hotswapped!')); + info(`${ICON} %s %s`, chalk.bold(name), chalk.green('hotswapped!')); } sdk.removeCustomUserAgent(customUserAgent); @@ -461,7 +461,7 @@ function logNonHotswappableChanges(nonHotswappableChanges: NonHotswappableChange } } if (hotswapMode === HotswapMode.HOTSWAP_ONLY) { - print( + info( '\n%s %s', chalk.red('⚠️'), chalk.red( @@ -469,19 +469,19 @@ function logNonHotswappableChanges(nonHotswappableChanges: NonHotswappableChange ), ); } else { - print('\n%s %s', chalk.red('⚠️'), chalk.red('The following non-hotswappable changes were found:')); + info('\n%s %s', chalk.red('⚠️'), chalk.red('The following non-hotswappable changes were found:')); } for (const change of nonHotswappableChanges) { change.rejectedChanges.length > 0 - ? print( + ? info( ' logicalID: %s, type: %s, rejected changes: %s, reason: %s', chalk.bold(change.logicalId), chalk.bold(change.resourceType), chalk.bold(change.rejectedChanges), chalk.red(change.reason), ) - : print( + : info( ' logicalID: %s, type: %s, reason: %s', chalk.bold(change.logicalId), chalk.bold(change.resourceType), @@ -489,5 +489,5 @@ function logNonHotswappableChanges(nonHotswappableChanges: NonHotswappableChange ); } - print(''); // newline + info(''); // newline } diff --git a/packages/aws-cdk/lib/api/logs/logs-monitor.ts b/packages/aws-cdk/lib/api/logs/logs-monitor.ts index 194a370d98521..a64a0d93df138 100644 --- a/packages/aws-cdk/lib/api/logs/logs-monitor.ts +++ b/packages/aws-cdk/lib/api/logs/logs-monitor.ts @@ -1,7 +1,7 @@ import * as util from 'util'; import * as cxapi from '@aws-cdk/cx-api'; import * as chalk from 'chalk'; -import { print, error } from '../../logging'; +import { info, error } from '../../logging'; import { flatten } from '../../util/arrays'; import type { SDK } from '../aws-auth'; @@ -162,7 +162,7 @@ export class CloudWatchLogEventMonitor { * Print out a cloudwatch event */ private print(event: CloudWatchLogEvent): void { - print( + info( util.format( '[%s] %s %s', chalk.blue(event.logGroupName), diff --git a/packages/aws-cdk/lib/api/plugin/plugin.ts b/packages/aws-cdk/lib/api/plugin/plugin.ts index 484dd9fa2ec8c..e18cf77a999fa 100644 --- a/packages/aws-cdk/lib/api/plugin/plugin.ts +++ b/packages/aws-cdk/lib/api/plugin/plugin.ts @@ -1,7 +1,7 @@ import { inspect } from 'util'; import type { CredentialProviderSource, IPluginHost, Plugin } from '@aws-cdk/cli-plugin-contract'; -import * as chalk from 'chalk'; +import * as chalk from 'chalk'; import { type ContextProviderPlugin, isContextProviderPlugin } from './context-provider-plugin'; import { error } from '../../logging'; import { ToolkitError } from '../../toolkit/error'; diff --git a/packages/aws-cdk/lib/api/util/cloudformation.ts b/packages/aws-cdk/lib/api/util/cloudformation.ts index 420537c08b805..aa963292626f4 100644 --- a/packages/aws-cdk/lib/api/util/cloudformation.ts +++ b/packages/aws-cdk/lib/api/util/cloudformation.ts @@ -353,7 +353,6 @@ export async function createDiffChangeSet( // This causes CreateChangeSet to fail with `Template Error: Fn::Equals cannot be partially collapsed`. for (const resource of Object.values(options.stack.template.Resources ?? {})) { if ((resource as any).Type === 'AWS::CloudFormation::Stack') { - // eslint-disable-next-line no-console debug('This stack contains one or more nested stacks, falling back to template-only diff...'); return undefined; diff --git a/packages/aws-cdk/lib/api/util/cloudformation/stack-activity-monitor.ts b/packages/aws-cdk/lib/api/util/cloudformation/stack-activity-monitor.ts index d3f6e843d0965..999ad18ed149b 100644 --- a/packages/aws-cdk/lib/api/util/cloudformation/stack-activity-monitor.ts +++ b/packages/aws-cdk/lib/api/util/cloudformation/stack-activity-monitor.ts @@ -3,7 +3,8 @@ import { ArtifactMetadataEntryType, type MetadataEntry } from '@aws-cdk/cloud-as import type { CloudFormationStackArtifact } from '@aws-cdk/cx-api'; import * as chalk from 'chalk'; import { ResourceEvent, StackEventPoller } from './stack-event-poller'; -import { error, LogLevel, setLogLevel } from '../../../logging'; +import { error, setIoMessageThreshold, info } from '../../../logging'; +import { IoMessageLevel } from '../../../toolkit/cli-io-host'; import type { ICloudFormationClient } from '../../aws-auth'; import { RewritableBlock } from '../display'; @@ -48,7 +49,7 @@ export interface WithDefaultPrinterProps { * * @default - Use value from logging.logLevel */ - readonly logLevel?: LogLevel; + readonly logLevel?: IoMessageLevel; /** * Whether to display all stack events or to display only the events for the @@ -102,7 +103,7 @@ export class StackActivityMonitor { }; const isWindows = process.platform === 'win32'; - const verbose = options.logLevel ?? LogLevel.INFO; + const verbose = options.logLevel ?? 'info'; // On some CI systems (such as CircleCI) output still reports as a TTY so we also // need an individual check for whether we're running on CI. // see: https://discuss.circleci.com/t/circleci-terminal-is-a-tty-but-term-is-not-set/9965 @@ -369,8 +370,6 @@ abstract class ActivityPrinterBase implements IActivityPrinter { protected hookFailureMap = new Map>(); - protected readonly stream: NodeJS.WriteStream; - constructor(protected readonly props: PrinterProps) { // +1 because the stack also emits a "COMPLETE" event at the end, and that wasn't // counted yet. This makes it line up with the amount of events we expect. @@ -378,8 +377,6 @@ abstract class ActivityPrinterBase implements IActivityPrinter { // How many digits does this number take to represent? this.resourceDigits = this.resourcesTotal ? Math.ceil(Math.log10(this.resourcesTotal)) : 0; - - this.stream = props.stream; } public failureReason(activity: StackActivity) { @@ -514,7 +511,7 @@ export class HistoryActivityPrinter extends ActivityPrinterBase { public stop() { // Print failures at the end if (this.failures.length > 0) { - this.stream.write('\nFailed resources:\n'); + info('\nFailed resources:'); for (const failure of this.failures) { // Root stack failures are not interesting if (failure.isStackEvent) { @@ -548,9 +545,9 @@ export class HistoryActivityPrinter extends ActivityPrinterBase { const logicalId = resourceName !== event.LogicalResourceId ? `(${event.LogicalResourceId}) ` : ''; - this.stream.write( + info( util.format( - '%s | %s%s | %s | %s | %s %s%s%s\n', + '%s | %s%s | %s | %s | %s %s%s%s', event.StackName, progress !== false ? `${this.progress()} | ` : '', new Date(event.Timestamp!).toLocaleTimeString(), @@ -591,9 +588,9 @@ export class HistoryActivityPrinter extends ActivityPrinterBase { } if (Object.keys(this.resourcesInProgress).length > 0) { - this.stream.write( + info( util.format( - '%s Currently in progress: %s\n', + '%s Currently in progress: %s', this.progress(), chalk.bold(Object.keys(this.resourcesInProgress).join(', ')), ), @@ -626,11 +623,14 @@ export class CurrentActivityPrinter extends ActivityPrinterBase { */ public readonly updateSleep: number = 2_000; - private oldLogLevel: LogLevel = LogLevel.INFO; - private block = new RewritableBlock(this.stream); + private oldLogThreshold: IoMessageLevel = 'info'; + private readonly stream: NodeJS.WriteStream; + private block: RewritableBlock; constructor(props: PrinterProps) { super(props); + this.stream = props.stream; + this.block = new RewritableBlock(this.stream); } public print(): void { @@ -674,11 +674,11 @@ export class CurrentActivityPrinter extends ActivityPrinterBase { public start() { // Need to prevent the waiter from printing 'stack not stable' every 5 seconds, it messes // with the output calculations. - setLogLevel(LogLevel.INFO); + setIoMessageThreshold('info'); } public stop() { - setLogLevel(this.oldLogLevel); + setIoMessageThreshold(this.oldLogThreshold); // Print failures at the end const lines = new Array(); diff --git a/packages/aws-cdk/lib/cdk-toolkit.ts b/packages/aws-cdk/lib/cdk-toolkit.ts index 319380f69b575..3f0db42c289ba 100644 --- a/packages/aws-cdk/lib/cdk-toolkit.ts +++ b/packages/aws-cdk/lib/cdk-toolkit.ts @@ -45,7 +45,7 @@ import { import { printSecurityDiff, printStackDiff, RequireApproval } from './diff'; import { ResourceImporter, removeNonImportResources } from './import'; import { listStacks } from './list-stacks'; -import { data, debug, error, highlight, print, success, warning, withCorkedLogging } from './logging'; +import { data, debug, error, highlight, info, success, warning, withCorkedLogging } from './logging'; import { deserializeStructure, serializeStructure } from './serialize'; import { Configuration, PROJECT_CONFIG } from './settings'; import { ToolkitError } from './toolkit/error'; @@ -275,11 +275,10 @@ export class CdkToolkit { options.ignoreNoStacks, ); const elapsedSynthTime = new Date().getTime() - startSynthTime; - print('\n✨ Synthesis time: %ss\n', formatTime(elapsedSynthTime)); + info(`\n✨ Synthesis time: ${formatTime(elapsedSynthTime)}s\n`); if (stackCollection.stackCount === 0) { - // eslint-disable-next-line no-console - console.error('This app contains no stacks'); + error('This app contains no stacks'); return; } @@ -388,7 +387,7 @@ export class CdkToolkit { } const stackIndex = stacks.indexOf(stack) + 1; - print('%s: deploying... [%s/%s]', chalk.bold(stack.displayName), stackIndex, stackCollection.stackCount); + info(`${chalk.bold(stack.displayName)}: deploying... [${stackIndex}/${stackCollection.stackCount}]`); const startDeployTime = new Date().getTime(); let tags = options.tags; @@ -492,20 +491,20 @@ export class CdkToolkit { success('\n' + message, stack.displayName); elapsedDeployTime = new Date().getTime() - startDeployTime; - print('\n✨ Deployment time: %ss\n', formatTime(elapsedDeployTime)); + info(`\n✨ Deployment time: ${formatTime(elapsedDeployTime)}s\n`); if (Object.keys(deployResult.outputs).length > 0) { - print('Outputs:'); + info('Outputs:'); stackOutputs[stack.stackName] = deployResult.outputs; } for (const name of Object.keys(deployResult.outputs).sort()) { const value = deployResult.outputs[name]; - print('%s.%s = %s', chalk.cyan(stack.id), chalk.cyan(name), chalk.underline(chalk.cyan(value))); + info(`${chalk.cyan(stack.id)}.${chalk.cyan(name)} = ${chalk.underline(chalk.cyan(value))}`); } - print('Stack ARN:'); + info('Stack ARN:'); data(deployResult.stackArn); } catch (e: any) { @@ -534,7 +533,7 @@ export class CdkToolkit { }); } } - print('\n✨ Total time: %ss\n', formatTime(elapsedSynthTime + elapsedDeployTime)); + info(`\n✨ Total time: ${formatTime(elapsedSynthTime + elapsedDeployTime)}s\n`); }; const assetBuildTime = options.assetBuildTime ?? AssetBuildTime.ALL_BEFORE_DEPLOY; @@ -576,18 +575,17 @@ export class CdkToolkit { const startSynthTime = new Date().getTime(); const stackCollection = await this.selectStacksForDeploy(options.selector, true); const elapsedSynthTime = new Date().getTime() - startSynthTime; - print('\n✨ Synthesis time: %ss\n', formatTime(elapsedSynthTime)); + info(`\n✨ Synthesis time: ${formatTime(elapsedSynthTime)}s\n`); if (stackCollection.stackCount === 0) { - // eslint-disable-next-line no-console - console.error('No stacks selected'); + error('No stacks selected'); return; } let anyRollbackable = false; for (const stack of stackCollection.stackArtifacts) { - print('Rolling back %s', chalk.bold(stack.displayName)); + info('Rolling back %s', chalk.bold(stack.displayName)); const startRollbackTime = new Date().getTime(); try { const result = await this.props.deployments.rollbackStack({ @@ -602,7 +600,7 @@ export class CdkToolkit { anyRollbackable = true; } const elapsedRollbackTime = new Date().getTime() - startRollbackTime; - print('\n✨ Rollback time: %ss\n', formatTime(elapsedRollbackTime)); + info(`\n✨ Rollback time: ${formatTime(elapsedRollbackTime).toString()}s\n`); } catch (e: any) { error('\n ❌ %s failed: %s', chalk.bold(stack.displayName), formatErrorMessage(e)); throw new ToolkitError('Rollback failed (use --force to orphan failing resources)'); @@ -676,7 +674,7 @@ export class CdkToolkit { // TypeScript doesn't realize latch can change between 'awaits', // and thinks the above 'while' condition is always 'false' without the cast latch = 'deploying'; - print("Detected file changes during deployment. Invoking 'cdk deploy' again"); + info("Detected file changes during deployment. Invoking 'cdk deploy' again"); await this.invokeDeployFromWatch(options, cloudWatchLogMonitor); } latch = 'open'; @@ -692,19 +690,19 @@ export class CdkToolkit { .on('ready', async () => { latch = 'open'; debug("'watch' received the 'ready' event. From now on, all file changes will trigger a deployment"); - print("Triggering initial 'cdk deploy'"); + info("Triggering initial 'cdk deploy'"); await deployAndWatch(); }) .on('all', async (event: 'add' | 'addDir' | 'change' | 'unlink' | 'unlinkDir', filePath?: string) => { if (latch === 'pre-ready') { - print(`'watch' is observing ${event === 'addDir' ? 'directory' : 'the file'} '%s' for changes`, filePath); + info(`'watch' is observing ${event === 'addDir' ? 'directory' : 'the file'} '%s' for changes`, filePath); } else if (latch === 'open') { - print("Detected change to '%s' (type: %s). Triggering 'cdk deploy'", filePath, event); + info("Detected change to '%s' (type: %s). Triggering 'cdk deploy'", filePath, event); await deployAndWatch(); } else { // this means latch is either 'deploying' or 'queued' latch = 'queued'; - print( + info( "Detected change to '%s' (type: %s) while 'cdk deploy' is still running. " + 'Will queue for another deployment after this one finishes', filePath, @@ -759,12 +757,12 @@ export class CdkToolkit { spaces: 2, encoding: 'utf8', }); - print('%s: mapping file written.', outputFile); + info('%s: mapping file written.', outputFile); return; } // Import the resources according to the given mapping - print('%s: importing resources into stack...', chalk.bold(stack.displayName)); + info('%s: importing resources into stack...', chalk.bold(stack.displayName)); const tags = tagsForStack(stack); await resourceImporter.importResourcesFromMap(actualImport, { roleArn: options.roleArn, @@ -777,7 +775,7 @@ export class CdkToolkit { }); // Notify user of next steps - print( + info( `Import operation complete. We recommend you run a ${chalk.blueBright('drift detection')} operation ` + 'to confirm your CDK app resource definitions are up-to-date. Read more here: ' + chalk.underline.blueBright( @@ -785,12 +783,12 @@ export class CdkToolkit { ), ); if (actualImport.importResources.length < additions.length) { - print(''); + info(''); warning( `Some resources were skipped. Run another ${chalk.blueBright('cdk import')} or a ${chalk.blueBright('cdk deploy')} to bring the stack up-to-date with your CDK app definition.`, ); } else if (hasNonAdditions) { - print(''); + info(''); warning( `Your app has pending updates or deletes excluded from this import operation. Run a ${chalk.blueBright('cdk deploy')} to bring the stack up-to-date with your CDK app definition.`, ); @@ -908,7 +906,7 @@ export class CdkToolkit { // not outputting template to stdout, let's explain things to the user a little bit... success(`Successfully synthesized to ${chalk.blue(path.resolve(stacks.assembly.directory))}`); - print( + info( `Supply a stack id (${stacks.stackArtifacts.map((s) => chalk.green(s.hierarchicalId)).join(', ')}) to display its template.`, ); @@ -1265,13 +1263,13 @@ export class CdkToolkit { const resourcesToImport = await this.tryGetResources(await migrateDeployment.resolveEnvironment()); if (resourcesToImport) { - print('%s: creating stack for resource migration...', chalk.bold(stack.displayName)); - print('%s: importing resources into stack...', chalk.bold(stack.displayName)); + info('%s: creating stack for resource migration...', chalk.bold(stack.displayName)); + info('%s: importing resources into stack...', chalk.bold(stack.displayName)); await this.performResourceMigration(migrateDeployment, resourcesToImport, options); fs.rmSync('migrate.json'); - print('%s: applying CDKMetadata and Outputs to stack (if applicable)...', chalk.bold(stack.displayName)); + info('%s: applying CDKMetadata and Outputs to stack (if applicable)...', chalk.bold(stack.displayName)); } } @@ -1297,7 +1295,7 @@ export class CdkToolkit { }); elapsedDeployTime = new Date().getTime() - startDeployTime; - print('\n✨ Resource migration time: %ss\n', formatTime(elapsedDeployTime)); + info('\n✨ Resource migration time: %ss\n', formatTime(elapsedDeployTime)); } private async tryGetResources(environment: cxapi.Environment): Promise { diff --git a/packages/aws-cdk/lib/cli.ts b/packages/aws-cdk/lib/cli.ts index d763eb924b0fc..75ab612a8d828 100644 --- a/packages/aws-cdk/lib/cli.ts +++ b/packages/aws-cdk/lib/cli.ts @@ -1,12 +1,13 @@ import * as cxapi from '@aws-cdk/cx-api'; import '@jsii/check-node/run'; import * as chalk from 'chalk'; - import { DeploymentMethod } from './api'; import { HotswapMode } from './api/hotswap/common'; import { ILock } from './api/util/rwlock'; import { parseCommandLineArguments } from './parse-command-line-arguments'; import { checkForPlatformWarnings } from './platform-warnings'; +import { IoMessageLevel, CliIoHost } from './toolkit/cli-io-host'; + import { enableTracing } from './util/tracing'; import { SdkProvider } from '../lib/api/aws-auth'; import { BootstrapSource, Bootstrapper } from '../lib/api/bootstrap'; @@ -22,7 +23,7 @@ import { docs } from '../lib/commands/docs'; import { doctor } from '../lib/commands/doctor'; import { getMigrateScanType } from '../lib/commands/migrate'; import { cliInit, printAvailableTemplates } from '../lib/init'; -import { data, debug, error, print, setCI, setLogLevel, LogLevel } from '../lib/logging'; +import { data, debug, error, info, setCI, setIoMessageThreshold } from '../lib/logging'; import { Notices } from '../lib/notices'; import { Command, Configuration, Settings } from '../lib/settings'; import * as version from '../lib/version'; @@ -43,17 +44,17 @@ export async function exec(args: string[], synthesizer?: Synthesizer): Promise { if (options.clear) { options.context.clear(); await options.context.save(PROJECT_CONTEXT); - print('All context values cleared.'); + info('All context values cleared.'); } else if (options.reset) { invalidateContext(options.context, options.reset, options.force ?? false); await options.context.save(PROJECT_CONTEXT); @@ -56,7 +56,7 @@ export async function contextHandler(options: ContextOptions): Promise { if (options.json) { /* istanbul ignore next */ const contextValues = options.context.all; - process.stdout.write(JSON.stringify(contextValues, undefined, 2)); + data(JSON.stringify(contextValues, undefined, 2)); } else { listContext(options.context); } @@ -70,27 +70,27 @@ function listContext(context: Context) { const keys = contextKeys(context); if (keys.length === 0) { - print('This CDK application does not have any saved context values yet.'); - print(''); - print('Context will automatically be saved when you synthesize CDK apps'); - print('that use environment context information like AZ information, VPCs,'); - print('SSM parameters, and so on.'); + info('This CDK application does not have any saved context values yet.'); + info(''); + info('Context will automatically be saved when you synthesize CDK apps'); + info('that use environment context information like AZ information, VPCs,'); + info('SSM parameters, and so on.'); return; } // Print config by default - const data: any[] = [[chalk.green('#'), chalk.green('Key'), chalk.green('Value')]]; + const data_out: any[] = [[chalk.green('#'), chalk.green('Key'), chalk.green('Value')]]; for (const [i, key] of keys) { const jsonWithoutNewlines = JSON.stringify(context.all[key], undefined, 2).replace(/\s+/g, ' '); - data.push([i, key, jsonWithoutNewlines]); + data_out.push([i, key, jsonWithoutNewlines]); } - print('Context found in %s:', chalk.blue(PROJECT_CONFIG)); - print(''); - print(renderTable(data, process.stdout.columns)); + info('Context found in %s:', chalk.blue(PROJECT_CONFIG)); + info(''); + info(renderTable(data_out, process.stdout.columns)); // eslint-disable-next-line max-len - print(`Run ${chalk.blue('cdk context --reset KEY_OR_NUMBER')} to remove a context key. It will be refreshed on the next CDK synthesis run.`); + info(`Run ${chalk.blue('cdk context --reset KEY_OR_NUMBER')} to remove a context key. It will be refreshed on the next CDK synthesis run.`); } function invalidateContext(context: Context, key: string, force: boolean) { @@ -104,7 +104,7 @@ function invalidateContext(context: Context, key: string, force: boolean) { context.unset(key); // check if the value was actually unset. if (!context.has(key)) { - print('Context value %s reset. It will be refreshed on next synthesis', chalk.blue(key)); + info('Context value %s reset. It will be refreshed on next synthesis', chalk.blue(key)); return; } @@ -145,9 +145,9 @@ function invalidateContext(context: Context, key: string, force: boolean) { function printUnset(unset: string[]) { if (unset.length === 0) return; - print('The following matched context values reset. They will be refreshed on next synthesis'); + info('The following matched context values reset. They will be refreshed on next synthesis'); unset.forEach((match) => { - print(' %s', match); + info(' %s', match); }); } @@ -155,10 +155,10 @@ function printReadonly(readonly: string[]) { if (readonly.length === 0) return; warning('The following matched context values could not be reset through the CLI'); readonly.forEach((match) => { - print(' %s', match); + info(' %s', match); }); - print(''); - print('This usually means they are configured in %s or %s', chalk.blue(PROJECT_CONFIG), chalk.blue(USER_DEFAULTS)); + info(''); + info('This usually means they are configured in %s or %s', chalk.blue(PROJECT_CONFIG), chalk.blue(USER_DEFAULTS)); } function keysByExpression(context: Context, expression: string) { diff --git a/packages/aws-cdk/lib/commands/docs.ts b/packages/aws-cdk/lib/commands/docs.ts index 7baa89e639b6d..9bb8eb6579bf4 100644 --- a/packages/aws-cdk/lib/commands/docs.ts +++ b/packages/aws-cdk/lib/commands/docs.ts @@ -1,6 +1,6 @@ import * as childProcess from 'child_process'; import * as chalk from 'chalk'; -import { debug, print, warning } from '../../lib/logging'; +import { debug, info, warning } from '../../lib/logging'; export const command = 'docs'; export const describe = 'Opens the reference documentation in a browser'; @@ -18,7 +18,7 @@ export interface DocsOptions { export async function docs(options: DocsOptions): Promise { const url = 'https://docs.aws.amazon.com/cdk/api/v2/'; - print(chalk.green(url)); + info(chalk.green(url)); const browserCommand = (options.browser).replace(/%u/g, url); debug(`Opening documentation ${chalk.green(browserCommand)}`); return new Promise((resolve, _reject) => { diff --git a/packages/aws-cdk/lib/commands/doctor.ts b/packages/aws-cdk/lib/commands/doctor.ts index 724a6cec23577..a2f03f08e08c0 100644 --- a/packages/aws-cdk/lib/commands/doctor.ts +++ b/packages/aws-cdk/lib/commands/doctor.ts @@ -1,7 +1,7 @@ import * as process from 'process'; import * as cxapi from '@aws-cdk/cx-api'; import * as chalk from 'chalk'; -import { print } from '../../lib/logging'; +import { info } from '../../lib/logging'; import * as version from '../../lib/version'; export async function doctor(): Promise { @@ -24,19 +24,19 @@ const verifications: Array<() => boolean | Promise> = [ // ### Verifications ### function displayVersionInformation() { - print(`ℹ️ CDK Version: ${chalk.green(version.DISPLAY_VERSION)}`); + info(`ℹ️ CDK Version: ${chalk.green(version.DISPLAY_VERSION)}`); return true; } function displayAwsEnvironmentVariables() { const keys = Object.keys(process.env).filter(s => s.startsWith('AWS_')); if (keys.length === 0) { - print('ℹ️ No AWS environment variables'); + info('ℹ️ No AWS environment variables'); return true; } - print('ℹ️ AWS environment variables:'); + info('ℹ️ AWS environment variables:'); for (const key of keys) { - print(` - ${chalk.blue(key)} = ${chalk.green(anonymizeAwsVariable(key, process.env[key]!))}`); + info(` - ${chalk.blue(key)} = ${chalk.green(anonymizeAwsVariable(key, process.env[key]!))}`); } return true; } @@ -44,17 +44,17 @@ function displayAwsEnvironmentVariables() { function displayCdkEnvironmentVariables() { const keys = Object.keys(process.env).filter(s => s.startsWith('CDK_')); if (keys.length === 0) { - print('ℹ️ No CDK environment variables'); + info('ℹ️ No CDK environment variables'); return true; } - print('ℹ️ CDK environment variables:'); + info('ℹ️ CDK environment variables:'); let healthy = true; for (const key of keys.sort()) { if (key === cxapi.CONTEXT_ENV || key === cxapi.CONTEXT_OVERFLOW_LOCATION_ENV || key === cxapi.OUTDIR_ENV) { - print(` - ${chalk.red(key)} = ${chalk.green(process.env[key]!)} (⚠️ reserved for use by the CDK toolkit)`); + info(` - ${chalk.red(key)} = ${chalk.green(process.env[key]!)} (⚠️ reserved for use by the CDK toolkit)`); healthy = false; } else { - print(` - ${chalk.blue(key)} = ${chalk.green(process.env[key]!)}`); + info(` - ${chalk.blue(key)} = ${chalk.green(process.env[key]!)}`); } } return healthy; diff --git a/packages/aws-cdk/lib/commands/migrate.ts b/packages/aws-cdk/lib/commands/migrate.ts index a6da22715ddc5..84733b9af9623 100644 --- a/packages/aws-cdk/lib/commands/migrate.ts +++ b/packages/aws-cdk/lib/commands/migrate.ts @@ -19,7 +19,7 @@ import type { import * as cdk_from_cfn from 'cdk-from-cfn'; import * as chalk from 'chalk'; import { cliInit } from '../../lib/init'; -import { print } from '../../lib/logging'; +import { info } from '../../lib/logging'; import type { ICloudFormationClient, SdkProvider } from '../api/aws-auth'; import { CloudFormationStack } from '../api/util/cloudformation'; import { zipDirectory } from '../util/archive'; @@ -168,7 +168,7 @@ export async function generateTemplate(options: GenerateTemplateOptions): Promis // if a customer accidentally ctrl-c's out of the command and runs it again, this will continue the progress bar where it left off const curScan = await cfn.describeResourceScan(scanId); if (curScan.Status == ScanStatus.IN_PROGRESS) { - print('Resource scan in progress. Please wait, this can take 10 minutes or longer.'); + info('Resource scan in progress. Please wait, this can take 10 minutes or longer.'); await scanProgressBar(scanId, cfn); } @@ -176,23 +176,23 @@ export async function generateTemplate(options: GenerateTemplateOptions): Promis let resources: ScannedResource[] = await cfn.listResourceScanResources(scanId!, options.filters); - print('finding related resources.'); + info('finding related resources.'); let relatedResources = await cfn.getResourceScanRelatedResources(scanId!, resources); - print(`Found ${relatedResources.length} resources.`); + info(`Found ${relatedResources.length} resources.`); - print('Generating CFN template from scanned resources.'); + info('Generating CFN template from scanned resources.'); const templateArn = (await cfn.createGeneratedTemplate(options.stackName, relatedResources)).GeneratedTemplateId!; let generatedTemplate = await cfn.describeGeneratedTemplate(templateArn); - print('Please wait, template creation in progress. This may take a couple minutes.'); + info('Please wait, template creation in progress. This may take a couple minutes.'); while (generatedTemplate.Status !== ScanStatus.COMPLETE && generatedTemplate.Status !== ScanStatus.FAILED) { await printDots(`[${generatedTemplate.Status}] Template Creation in Progress`, 400); generatedTemplate = await cfn.describeGeneratedTemplate(templateArn); } - print(''); - print('Template successfully generated!'); + info(''); + info('Template successfully generated!'); return buildGenertedTemplateOutput( generatedTemplate, (await cfn.getGeneratedTemplate(templateArn)).TemplateBody!, @@ -207,7 +207,7 @@ async function findLastSuccessfulScan( let resourceScanSummaries: ResourceScanSummary[] | undefined = []; const clientRequestToken = `cdk-migrate-${options.environment.account}-${options.environment.region}`; if (options.fromScan === FromScan.NEW) { - print(`Starting new scan for account ${options.environment.account} in region ${options.environment.region}`); + info(`Starting new scan for account ${options.environment.account} in region ${options.environment.region}`); try { await cfn.startResourceScan(clientRequestToken); resourceScanSummaries = (await cfn.listResourceScans()).ResourceScanSummaries; @@ -215,7 +215,7 @@ async function findLastSuccessfulScan( // continuing here because if the scan fails on a new-scan it is very likely because there is either already a scan in progress // or the customer hit a rate limit. In either case we want to continue with the most recent scan. // If this happens to fail for a credential error then that will be caught immediately after anyway. - print(`Scan failed to start due to error '${(e as Error).message}', defaulting to latest scan.`); + info(`Scan failed to start due to error '${(e as Error).message}', defaulting to latest scan.`); } } else { resourceScanSummaries = (await cfn.listResourceScans()).ResourceScanSummaries; @@ -423,8 +423,8 @@ export async function scanProgressBar(scanId: string, cfn: CfnTemplateGeneratorP printBar(30, curProgress); await new Promise((resolve) => setTimeout(resolve, 2000)); } - print(''); - print('✅ Scan Complete!'); + info(''); + info('✅ Scan Complete!'); } /** @@ -501,7 +501,7 @@ export function displayTimeDiff(time1: Date, time2: Date): void { const hours = Math.floor((diff % (1000 * 60 * 60 * 24)) / (1000 * 60 * 60)); const minutes = Math.floor((diff % (1000 * 60 * 60)) / (1000 * 60)); - print(`Using the latest successful scan which is ${days} days, ${hours} hours, and ${minutes} minutes old.`); + info(`Using the latest successful scan which is ${days} days, ${hours} hours, and ${minutes} minutes old.`); } /** @@ -683,7 +683,7 @@ export class CfnTemplateGeneratorProvider { 'No scans found. Please either start a new scan with the `--from-scan` new or do not specify a `--from-scan` option.', ); } else { - print('No scans found. Initiating a new resource scan.'); + info('No scans found. Initiating a new resource scan.'); await this.startResourceScan(clientRequestToken); } } @@ -772,7 +772,7 @@ export class CfnTemplateGeneratorProvider { let resourceScanInputs: ListResourceScanResourcesCommandInput; if (filters.length > 0) { - print('Applying filters to resource scan.'); + info('Applying filters to resource scan.'); for (const filter of filters) { const filterList = parseFilters(filter); resourceScanInputs = { @@ -795,7 +795,7 @@ export class CfnTemplateGeneratorProvider { } } } else { - print('No filters provided. Retrieving all resources from scan.'); + info('No filters provided. Retrieving all resources from scan.'); resourceScanInputs = { ResourceScanId: scanId, }; diff --git a/packages/aws-cdk/lib/context-providers/ami.ts b/packages/aws-cdk/lib/context-providers/ami.ts index 0d9d31753cf53..27a518163ee58 100644 --- a/packages/aws-cdk/lib/context-providers/ami.ts +++ b/packages/aws-cdk/lib/context-providers/ami.ts @@ -1,7 +1,7 @@ import type { AmiContextQuery } from '@aws-cdk/cloud-assembly-schema'; import { type SdkProvider, initContextProviderSdk } from '../api/aws-auth/sdk-provider'; import { ContextProviderPlugin } from '../api/plugin'; -import { debug, print } from '../logging'; +import { debug, info } from '../logging'; /** * Plugin to search AMIs for the current account @@ -15,7 +15,7 @@ export class AmiContextProviderPlugin implements ContextProviderPlugin { // Normally we'd do this only as 'debug', but searching AMIs typically takes dozens // of seconds, so be little more verbose about it so users know what is going on. - print(`Searching for AMI in ${account}:${region}`); + info(`Searching for AMI in ${account}:${region}`); debug(`AMI search parameters: ${JSON.stringify(args)}`); const ec2 = (await initContextProviderSdk(this.aws, args)).ec2(); diff --git a/packages/aws-cdk/lib/diff.ts b/packages/aws-cdk/lib/diff.ts index 77270c05bc048..dddeed2fa539f 100644 --- a/packages/aws-cdk/lib/diff.ts +++ b/packages/aws-cdk/lib/diff.ts @@ -12,7 +12,7 @@ import { import * as cxapi from '@aws-cdk/cx-api'; import * as chalk from 'chalk'; import { NestedStackTemplates } from './api/nested-stack-helpers'; -import { print, warning } from './logging'; +import { info, warning } from './logging'; import { ToolkitError } from './toolkit/error'; /** @@ -73,10 +73,10 @@ export function printStackDiff( ...buildLogicalToPathMap(newTemplate), }, context); } else if (!quiet) { - print(chalk.green('There were no differences')); + info(chalk.green('There were no differences')); } if (filteredChangesCount > 0) { - print(chalk.yellow(`Omitted ${filteredChangesCount} changes because they are likely mangled non-ASCII characters. Use --strict to print them.`)); + info(chalk.yellow(`Omitted ${filteredChangesCount} changes because they are likely mangled non-ASCII characters. Use --strict to print them.`)); } for (const nestedStackLogicalId of Object.keys(nestedStackTemplates ?? {})) { diff --git a/packages/aws-cdk/lib/import.ts b/packages/aws-cdk/lib/import.ts index 3d34fee6985ff..47451ce76d874 100644 --- a/packages/aws-cdk/lib/import.ts +++ b/packages/aws-cdk/lib/import.ts @@ -11,7 +11,7 @@ import { Deployments } from './api/deployments'; import { ResourceIdentifierProperties, ResourcesToImport } from './api/util/cloudformation'; import { StackActivityProgress } from './api/util/cloudformation/stack-activity-monitor'; import { Tag } from './cdk-toolkit'; -import { error, print, success, warning } from './logging'; +import { error, info, success, warning } from './logging'; import { ToolkitError } from './toolkit/error'; export interface ImportDeploymentOptions extends DeployOptions { @@ -99,13 +99,13 @@ export class ResourceImporter { const descr = this.describeResource(resource.logicalId); const idProps = contents[resource.logicalId]; if (idProps) { - print('%s: importing using %s', chalk.blue(descr), chalk.blue(fmtdict(idProps))); + info('%s: importing using %s', chalk.blue(descr), chalk.blue(fmtdict(idProps))); ret.importResources.push(resource); ret.resourceMap[resource.logicalId] = idProps; delete contents[resource.logicalId]; } else { - print('%s: skipping', chalk.blue(descr)); + info('%s: skipping', chalk.blue(descr)); } } @@ -306,7 +306,7 @@ export class ResourceImporter { // If we got here and the user rejected any available identifiers, then apparently they don't want the resource at all if (satisfiedPropSets.length > 0) { - print(chalk.grey(`Skipping import of ${resourceName}`)); + info(chalk.grey(`Skipping import of ${resourceName}`)); return undefined; } @@ -324,7 +324,7 @@ export class ResourceImporter { // Do the input loop here if (preamble) { - print(preamble); + info(preamble); } for (const idProps of idPropSets) { const input: Record = {}; @@ -359,7 +359,7 @@ export class ResourceImporter { } } - print(chalk.grey(`Skipping import of ${resourceName}`)); + info(chalk.grey(`Skipping import of ${resourceName}`)); return undefined; } diff --git a/packages/aws-cdk/lib/init.ts b/packages/aws-cdk/lib/init.ts index 7fe5854fd4704..fc91e3016a15c 100644 --- a/packages/aws-cdk/lib/init.ts +++ b/packages/aws-cdk/lib/init.ts @@ -3,7 +3,7 @@ import * as path from 'path'; import * as chalk from 'chalk'; import * as fs from 'fs-extra'; import { invokeBuiltinHooks } from './init-hooks'; -import { error, print, warning } from './logging'; +import { error, info, warning } from './logging'; import { ToolkitError } from './toolkit/error'; import { cdkHomeDir, rootDir } from './util/directories'; import { formatErrorMessage } from './util/error'; @@ -51,7 +51,7 @@ export async function cliInit(options: CliInitOptions) { ); } if (!options.language) { - print(`Available languages for ${chalk.green(type)}: ${template.languages.map((l) => chalk.blue(l)).join(', ')}`); + info(`Available languages for ${chalk.green(type)}: ${template.languages.map((l) => chalk.blue(l)).join(', ')}`); throw new ToolkitError('No language was selected'); } @@ -82,8 +82,8 @@ export class InitTemplate { public static async fromName(templatesDir: string, name: string) { const basePath = path.join(templatesDir, name); const languages = await listDirectory(basePath); - const info = await fs.readJson(path.join(basePath, INFO_DOT_JSON)); - return new InitTemplate(basePath, name, languages, info); + const initInfo = await fs.readJson(path.join(basePath, INFO_DOT_JSON)); + return new InitTemplate(basePath, name, languages, initInfo); } public readonly description: string; @@ -93,10 +93,10 @@ export class InitTemplate { private readonly basePath: string, public readonly name: string, public readonly languages: string[], - info: any, + initInfo: any, ) { - this.description = info.description; - for (const alias of info.aliases || []) { + this.description = initInfo.description; + for (const alias of initInfo.aliases || []) { this.aliases.add(alias); } } @@ -296,18 +296,18 @@ async function listDirectory(dirPath: string) { } export async function printAvailableTemplates(language?: string) { - print('Available templates:'); + info('Available templates:'); for (const template of await availableInitTemplates()) { if (language && template.languages.indexOf(language) === -1) { continue; } - print(`* ${chalk.green(template.name)}: ${template.description}`); + info(`* ${chalk.green(template.name)}: ${template.description}`); const languageArg = language ? chalk.bold(language) : template.languages.length > 1 ? `[${template.languages.map((t) => chalk.bold(t)).join('|')}]` : chalk.bold(template.languages[0]); - print(` └─ ${chalk.blue(`cdk init ${chalk.bold(template.name)} --language=${languageArg}`)}`); + info(` └─ ${chalk.blue(`cdk init ${chalk.bold(template.name)} --language=${languageArg}`)}`); } } @@ -321,14 +321,14 @@ async function initializeProject( migrate?: boolean, ) { await assertIsEmptyDirectory(workDir); - print(`Applying project template ${chalk.green(template.name)} for ${chalk.blue(language)}`); + info(`Applying project template ${chalk.green(template.name)} for ${chalk.blue(language)}`); await template.install(language, workDir, stackName); if (migrate) { await template.addMigrateContext(workDir); } if (await fs.pathExists(`${workDir}/README.md`)) { const readme = await fs.readFile(`${workDir}/README.md`, { encoding: 'utf-8' }); - print(chalk.green(readme)); + info(chalk.green(readme)); } if (!generateOnly) { @@ -336,7 +336,7 @@ async function initializeProject( await postInstall(language, canUseNetwork, workDir); } - print('✅ All done!'); + info('✅ All done!'); } async function assertIsEmptyDirectory(workDir: string) { @@ -350,7 +350,7 @@ async function initializeGitRepository(workDir: string) { if (await isInGitRepository(workDir)) { return; } - print('Initializing a new git repository...'); + info('Initializing a new git repository...'); try { await execute('git', ['init'], { cwd: workDir }); await execute('git', ['add', '.'], { cwd: workDir }); @@ -385,7 +385,7 @@ async function postInstallTypescript(canUseNetwork: boolean, cwd: string) { return; } - print(`Executing ${chalk.green(`${command} install`)}...`); + info(`Executing ${chalk.green(`${command} install`)}...`); try { await execute(command, ['install'], { cwd }); } catch (e: any) { @@ -400,7 +400,7 @@ async function postInstallJava(canUseNetwork: boolean, cwd: string) { return; } - print("Executing 'mvn package'"); + info("Executing 'mvn package'"); try { await execute('mvn', ['package'], { cwd }); } catch { @@ -412,7 +412,7 @@ async function postInstallJava(canUseNetwork: boolean, cwd: string) { async function postInstallPython(cwd: string) { const python = pythonExecutable(); warning(`Please run '${python} -m venv .venv'!`); - print(`Executing ${chalk.green('Creating virtualenv...')}`); + info(`Executing ${chalk.green('Creating virtualenv...')}`); try { await execute(python, ['-m venv', '.venv'], { cwd }); } catch { @@ -467,7 +467,7 @@ async function execute(cmd: string, args: string[], { cwd }: { cwd: string }) { if (status === 0) { return ok(stdout); } else { - process.stderr.write(stdout); + error(stdout); return fail(new ToolkitError(`${cmd} exited with status ${status}`)); } }); diff --git a/packages/aws-cdk/lib/logging.ts b/packages/aws-cdk/lib/logging.ts index fd1b8e5d0f47d..2df85c308708b 100644 --- a/packages/aws-cdk/lib/logging.ts +++ b/packages/aws-cdk/lib/logging.ts @@ -1,79 +1,27 @@ -import { Writable } from 'stream'; import * as util from 'util'; import * as chalk from 'chalk'; - -/** - * Available log levels in order of increasing verbosity. - */ -export enum LogLevel { - ERROR = 'error', - WARN = 'warn', - INFO = 'info', - DEBUG = 'debug', - TRACE = 'trace', -} - -/** - * Configuration options for a log entry. - */ -export interface LogEntry { - level: LogLevel; - message: string; - timestamp?: boolean; - prefix?: string; - style?: ((str: string) => string); - forceStdout?: boolean; -} - -const { stdout, stderr } = process; +import { IoMessageLevel, IoMessage, CliIoHost, IoMessageSpecificCode, IoMessageCode, IoMessageCodeCategory, IoCodeLevel } from './toolkit/cli-io-host'; // Corking mechanism let CORK_COUNTER = 0; -const logBuffer: [Writable, string][] = []; - -// Style mappings -const styleMap: Record string> = { - [LogLevel.ERROR]: chalk.red, - [LogLevel.WARN]: chalk.yellow, - [LogLevel.INFO]: chalk.white, - [LogLevel.DEBUG]: chalk.gray, - [LogLevel.TRACE]: chalk.gray, -}; - -// Stream selection -let CI = false; +const logBuffer: IoMessage[] = []; -/** - * Determines which output stream to use based on log level and configuration. - * @param level - The log level to determine stream for - * @param forceStdout - Whether to force stdout regardless of level - * @returns The appropriate Writable stream - */ -const getStream = (level: LogLevel, forceStdout?: boolean): Writable => { - // Special case - data() calls should always go to stdout - if (forceStdout) { - return stdout; - } - if (level === LogLevel.ERROR) return stderr; - return CI ? stdout : stderr; +const levelPriority: Record = { + error: 0, + warn: 1, + info: 2, + debug: 3, + trace: 4, }; -const levelPriority: Record = { - [LogLevel.ERROR]: 0, - [LogLevel.WARN]: 1, - [LogLevel.INFO]: 2, - [LogLevel.DEBUG]: 3, - [LogLevel.TRACE]: 4, -}; - -let currentLogLevel: LogLevel = LogLevel.INFO; +let currentIoMessageThreshold: IoMessageLevel = 'info'; /** - * Sets the current log level. Messages with a lower priority level will be filtered out. - * @param level - The new log level to set + * Sets the current threshold. Messages with a lower priority level will be ignored. + * @param level The new log level threshold */ -export function setLogLevel(level: LogLevel) { - currentLogLevel = level; +export function setIoMessageThreshold(level: IoMessageLevel) { + currentIoMessageThreshold = level; } /** @@ -82,22 +30,12 @@ export function setLogLevel(level: LogLevel) { * @param newCI - Whether CI mode should be enabled */ export function setCI(newCI: boolean) { - CI = newCI; -} - -/** - * Formats a date object into a timestamp string (HH:MM:SS). - * @param d - Date object to format - * @returns Formatted time string - */ -function formatTime(d: Date): string { - const pad = (n: number): string => n.toString().padStart(2, '0'); - return `${pad(d.getHours())}:${pad(d.getMinutes())}:${pad(d.getSeconds())}`; + CliIoHost.ci = newCI; } /** * Executes a block of code with corked logging. All log messages during execution - * are buffered and only written after the block completes. + * are buffered and only written when all nested cork blocks complete (when CORK_COUNTER reaches 0). * @param block - Async function to execute with corked logging * @returns Promise that resolves with the block's return value */ @@ -108,105 +46,235 @@ export async function withCorkedLogging(block: () => Promise): Promise } finally { CORK_COUNTER--; if (CORK_COUNTER === 0) { - logBuffer.forEach(([stream, str]) => stream.write(str + '\n')); + // Process each buffered message through notify + for (const ioMessage of logBuffer) { + void CliIoHost.getIoHost().notify(ioMessage); + } logBuffer.splice(0); } } } +interface LogOptions { + /** + * The log level to use + */ + readonly level: IoMessageLevel; + /** + * The message to log + */ + readonly message: string; + /** + * Whether to force stdout + * @default false + */ + readonly forceStdout?: boolean; + /** + * Message code of the format [CATEGORY]_[NUMBER_CODE] + * @pattern [A-Z]+_[0-2][0-9]{3} + * @default TOOLKIT_[0/1/2]000 + */ + readonly code: IoMessageCode; +} + /** - * Core logging function that handles all log output. - * @param entry - LogEntry object or log level - * @param fmt - Format string (when using with log level) - * @param args - Format arguments (when using with log level) + * Internal core logging function that writes messages through the CLI IO host. + * @param options Configuration options for the log message. See {@link LogOptions} */ -export function log(entry: LogEntry): void; -export function log(level: LogLevel, fmt: string, ...args: unknown[]): void; -export function log(levelOrEntry: LogLevel | LogEntry, fmt?: string, ...args: unknown[]): void { - // Normalize input - const entry: LogEntry = typeof levelOrEntry === 'string' - ? { level: levelOrEntry as LogLevel, message: util.format(fmt!, ...args) } - : levelOrEntry; - - // Check if we should log this level - if (levelPriority[entry.level] > levelPriority[currentLogLevel]) { +function log(options: LogOptions) { + if (levelPriority[options.level] > levelPriority[currentIoMessageThreshold]) { return; } - // Format the message - let finalMessage = entry.message; - - // Add timestamp first if requested - if (entry.timestamp) { - finalMessage = `[${formatTime(new Date())}] ${finalMessage}`; - } - - // Add prefix AFTER timestamp - if (entry.prefix) { - finalMessage = `${entry.prefix} ${finalMessage}`; - } - - // Apply custom style if provided, otherwise use level-based style - const style = entry.style || styleMap[entry.level]; - finalMessage = style(finalMessage); + const ioMessage: IoMessage = { + level: options.level, + message: options.message, + forceStdout: options.forceStdout, + time: new Date(), + action: CliIoHost.currentAction ?? 'none', + code: options.code, + }; - // Get appropriate stream - pass through forceStdout flag - const stream = getStream(entry.level, entry.forceStdout); - - // Handle corking if (CORK_COUNTER > 0) { - logBuffer.push([stream, finalMessage]); + logBuffer.push(ioMessage); return; } - // Write to stream - stream.write(finalMessage + '\n'); + void CliIoHost.getIoHost().notify(ioMessage); } -// Convenience logging methods -export const error = (fmt: string, ...args: unknown[]) => log(LogLevel.ERROR, fmt, ...args); -export const warning = (fmt: string, ...args: unknown[]) => log(LogLevel.WARN, fmt, ...args); -export const info = (fmt: string, ...args: unknown[]) => log(LogLevel.INFO, fmt, ...args); -export const print = (fmt: string, ...args: unknown[]) => log(LogLevel.INFO, fmt, ...args); -export const data = (fmt: string, ...args: unknown[]) => log({ - level: LogLevel.INFO, - message: util.format(fmt, ...args), - forceStdout: true, -}); -export const debug = (fmt: string, ...args: unknown[]) => log({ - level: LogLevel.DEBUG, - message: util.format(fmt, ...args), - timestamp: true, -}); - -export const trace = (fmt: string, ...args: unknown[]) => log({ - level: LogLevel.TRACE, - message: util.format(fmt, ...args), - timestamp: true, -}); - -export const success = (fmt: string, ...args: unknown[]) => log({ - level: LogLevel.INFO, - message: util.format(fmt, ...args), - style: chalk.green, -}); - -export const highlight = (fmt: string, ...args: unknown[]) => log({ - level: LogLevel.INFO, - message: util.format(fmt, ...args), - style: chalk.bold, -}); - /** - * Creates a logging function that prepends a prefix to all messages. - * @param prefixString - String to prepend to all messages - * @param level - Log level to use (defaults to INFO) - * @returns Logging function that accepts format string and arguments + * Internal helper that processes log inputs into a consistent format. + * Handles string interpolation, format strings, and object parameter styles. + * Applies optional styling and prepares the final message for logging. */ -export function prefix(prefixString: string, level: LogLevel = LogLevel.INFO): (fmt: string, ...args: unknown[]) => void { - return (fmt: string, ...args: unknown[]) => log({ +function formatMessageAndLog( + level: IoMessageLevel, + forceStdout: boolean, + input: LogInput, + style?: (str: string) => string, + ...args: unknown[] +): void { + // Extract message and code from input, using new default code format + const { message, code = getDefaultCode(level) } = typeof input === 'object' ? input : { message: input }; + + // Format message if args are provided + const formattedMessage = args.length > 0 + ? util.format(message, ...args) + : message; + + // Apply style if provided + const finalMessage = style ? style(formattedMessage) : formattedMessage; + + log({ level, - message: util.format(fmt, ...args), - prefix: prefixString, + message: finalMessage, + code, + forceStdout, }); } + +function getDefaultCode(level: IoMessageLevel, category: IoMessageCodeCategory = 'TOOLKIT'): IoMessageCode { + const levelIndicator = level === 'error' ? 'E' : + level === 'warn' ? 'W' : + 'I'; + return `CDK_${category}_${levelIndicator}0000`; +} + +// Type for the object parameter style +interface LogParams { + /** + * @see {@link IoMessage.code} + */ + readonly code?: IoMessageSpecificCode; + /** + * @see {@link IoMessage.message} + */ + readonly message: string; +} + +// Type for the exported log function arguments +type LogInput = string | LogParams; + +// Exported logging functions. If any additional logging functionality is required, it should be added as +// a new logging function here. + +/** + * Logs an error level message. + * + * Can be used in multiple ways: + * ```ts + * error(`operation failed: ${e}`) // infers default error code `CDK_TOOLKIT_E000` + * error('operation failed: %s', e) // infers default error code `CDK_TOOLKIT_E000` + * error({ message: 'operation failed', code: 'CDK_SDK_E001' }) // specifies error code `CDK_SDK_E001` + * error({ message: 'operation failed: %s', code: 'CDK_SDK_E001' }, e) // specifies error code `CDK_SDK_E001` + * ``` + */ +export const error = (input: LogInput<'E'>, ...args: unknown[]) => { + return formatMessageAndLog('error', false, input, undefined, ...args); +}; + +/** + * Logs an warning level message. + * + * Can be used in multiple ways: + * ```ts + * warning(`deprected feature: ${message}`) // infers default warning code `CDK_TOOLKIT_W000` + * warning('deprected feature: %s', message) // infers default warning code `CDK_TOOLKIT_W000` + * warning({ message: 'deprected feature', code: 'CDK_SDK_W001' }) // specifies warning code `CDK_SDK_W001` + * warning({ message: 'deprected feature: %s', code: 'CDK_SDK_W001' }, message) // specifies warning code `CDK_SDK_W001` + * ``` + */ +export const warning = (input: LogInput<'W'>, ...args: unknown[]) => { + return formatMessageAndLog('warn', false, input, undefined, ...args); +}; + +/** + * Logs an info level message. + * + * Can be used in multiple ways: + * ```ts + * info(`processing: ${message}`) // infers default info code `CDK_TOOLKIT_I000` + * info('processing: %s', message) // infers default info code `CDK_TOOLKIT_I000` + * info({ message: 'processing', code: 'CDK_TOOLKIT_I001' }) // specifies info code `CDK_TOOLKIT_I001` + * info({ message: 'processing: %s', code: 'CDK_TOOLKIT_I001' }, message) // specifies info code `CDK_TOOLKIT_I001` + * ``` + */ +export const info = (input: LogInput<'I'>, ...args: unknown[]) => { + return formatMessageAndLog('info', false, input, undefined, ...args); +}; + +/** + * Logs an info level message to stdout. + * + * Can be used in multiple ways: + * ```ts + * data(`${JSON.stringify(stats)}`) // infers default info code `CDK_TOOLKIT_I000` + * data('{"count": %d}', count) // infers default info code `CDK_TOOLKIT_I000` + * data({ message: 'stats: %j', code: 'CDK_DATA_I001' }) // specifies info code `CDK_DATA_I001` + * data({ message: 'stats: %j', code: 'CDK_DATA_I001' }, stats) // specifies info code `CDK_DATA_I001` + * ``` + */ +export const data = (input: LogInput<'I'>, ...args: unknown[]) => { + return formatMessageAndLog('info', true, input, undefined, ...args); +}; + +/** + * Logs a debug level message. + * + * Can be used in multiple ways: + * ```ts + * debug(`state: ${JSON.stringify(state)}`) // infers default info code `CDK_TOOLKIT_I000` + * debug('cache hit ratio: %d%%', ratio) // infers default info code `CDK_TOOLKIT_I000` + * debug({ message: 'state update', code: 'CDK_TOOLKIT_I001' }) // specifies info code `CDK_TOOLKIT_I001` + * debug({ message: 'ratio: %d%%', code: 'CDK_TOOLKIT_I001' }, ratio) // specifies info code `CDK_TOOLKIT_I001` + * ``` + */ +export const debug = (input: LogInput<'I'>, ...args: unknown[]) => { + return formatMessageAndLog('debug', false, input, undefined, ...args); +}; + +/** + * Logs a trace level message. + * + * Can be used in multiple ways: + * ```ts + * trace(`entered ${name} with ${args}`) // infers default info code `CDK_TOOLKIT_I000` + * trace('method: %s, args: %j', name, args) // infers default info code `CDK_TOOLKIT_I000` + * trace({ message: 'entered', code: 'CDK_TOOLKIT_I001' }) // specifies info code `CDK_TOOLKIT_I001` + * trace({ message: 'method: %s', code: 'CDK_TOOLKIT_I001' }, name) // specifies info code `CDK_TOOLKIT_I001` + * ``` + */ +export const trace = (input: LogInput<'I'>, ...args: unknown[]) => { + return formatMessageAndLog('trace', false, input, undefined, ...args); +}; + +/** + * Logs an info level success message in green text. + * + * Can be used in multiple ways: + * ```ts + * success(`deployment completed: ${name}`) // infers default info code `CDK_TOOLKIT_I000` + * success('processed %d items', count) // infers default info code `CDK_TOOLKIT_I000` + * success({ message: 'completed', code: 'CDK_TOOLKIT_I001' }) // specifies info code `CDK_TOOLKIT_I001` + * success({ message: 'items: %d', code: 'CDK_TOOLKIT_I001' }, count) // specifies info code `CDK_TOOLKIT_I001` + * ``` + */ +export const success = (input: LogInput<'I'>, ...args: unknown[]) => { + return formatMessageAndLog('info', false, input, chalk.green, ...args); +}; + +/** + * Logs an info level message in bold text. + * + * Can be used in multiple ways: + * ```ts + * highlight(`important: ${msg}`) // infers default info code `CDK_TOOLKIT_I000` + * highlight('attention required: %s', reason) // infers default info code `CDK_TOOLKIT_I000` + * highlight({ message: 'notice', code: 'CDK_TOOLKIT_I001' }) // specifies info code `CDK_TOOLKIT_I001` + * highlight({ message: 'notice: %s', code: 'CDK_TOOLKIT_I001' }, msg) // specifies info code `CDK_TOOLKIT_I001` + * ``` + */ +export const highlight = (input: LogInput<'I'>, ...args: unknown[]) => { + return formatMessageAndLog('info', false, input, chalk.bold, ...args); +}; diff --git a/packages/aws-cdk/lib/notices.ts b/packages/aws-cdk/lib/notices.ts index 5a4c8e3adf89c..5d21f6ced47d7 100644 --- a/packages/aws-cdk/lib/notices.ts +++ b/packages/aws-cdk/lib/notices.ts @@ -7,7 +7,7 @@ import * as fs from 'fs-extra'; import * as semver from 'semver'; import { SdkHttpOptions } from './api'; import { AwsCliCompatible } from './api/aws-auth/awscli-compatible'; -import { debug, print, warning, error } from './logging'; +import { debug, info, warning, error } from './logging'; import { Context } from './settings'; import { ToolkitError } from './toolkit/error'; import { loadTreeFromDir, some } from './tree'; @@ -300,9 +300,9 @@ export class Notices { }); if (filteredNotices.length > 0) { - print(''); - print('NOTICES (What\'s this? https://github.com/aws/aws-cdk/wiki/CLI-Notices)'); - print(''); + info(''); + info('NOTICES (What\'s this? https://github.com/aws/aws-cdk/wiki/CLI-Notices)'); + info(''); for (const filtered of filteredNotices) { const formatted = filtered.format(); switch (filtered.notice.severity) { @@ -313,16 +313,16 @@ export class Notices { error(formatted); break; default: - print(formatted); + info(formatted); } - print(''); + info(''); } - print(`If you don’t want to see a notice anymore, use "cdk acknowledge ". For example, "cdk acknowledge ${filteredNotices[0].notice.issueNumber}".`); + info(`If you don’t want to see a notice anymore, use "cdk acknowledge ". For example, "cdk acknowledge ${filteredNotices[0].notice.issueNumber}".`); } if (options.showTotal ?? false) { - print(''); - print(`There are ${filteredNotices.length} unacknowledged notice(s).`); + info(''); + info(`There are ${filteredNotices.length} unacknowledged notice(s).`); } } } diff --git a/packages/aws-cdk/lib/toolkit/cli-io-host.ts b/packages/aws-cdk/lib/toolkit/cli-io-host.ts index 9955c6b6d76c7..41038734d9c25 100644 --- a/packages/aws-cdk/lib/toolkit/cli-io-host.ts +++ b/packages/aws-cdk/lib/toolkit/cli-io-host.ts @@ -1,10 +1,15 @@ import * as chalk from 'chalk'; +export type IoMessageCodeCategory = 'TOOLKIT' | 'SDK' | 'ASSETS'; +export type IoCodeLevel = 'E' | 'W' | 'I'; +export type IoMessageSpecificCode = `CDK_${IoMessageCodeCategory}_${L}${number}${number}${number}${number}`; +export type IoMessageCode = IoMessageSpecificCode; + /** * Basic message structure for toolkit notifications. * Messages are emitted by the toolkit and handled by the IoHost. */ -interface IoMessage { +export interface IoMessage { /** * The time the message was emitted. */ @@ -18,12 +23,25 @@ interface IoMessage { /** * The action that triggered the message. */ - readonly action: IoAction; + readonly action: ToolkitAction; /** - * A short code uniquely identifying message type. + * A short message code uniquely identifying a message type using the format CDK_[CATEGORY]_[E/W/I][000-999]. + * + * The level indicator follows these rules: + * - 'E' for error level messages + * - 'W' for warning level messages + * - 'I' for info/debug/trace level messages + * + * Codes ending in 000 are generic messages, while codes ending in 001-999 are specific to a particular message. + * The following are examples of valid and invalid message codes: + * ```ts + * 'CDK_ASSETS_I000' // valid: generic assets info message + * 'CDK_TOOLKIT_E002' // valid: specific toolkit error message + * 'CDK_SDK_W023' // valid: specific sdk warning message + * ``` */ - readonly code: string; + readonly code: IoMessageCode; /** * The message text. @@ -41,36 +59,92 @@ interface IoMessage { export type IoMessageLevel = 'error' | 'warn' | 'info' | 'debug' | 'trace'; -export type IoAction = 'synth' | 'list' | 'deploy' | 'destroy'; +/** + * The current action being performed by the CLI. 'none' represents the absence of an action. + */ +export type ToolkitAction = 'synth' | 'list' | 'deploy' | 'destroy' | 'none'; /** - * Options for the CLI IO host. + * A simple IO host for the CLI that writes messages to the console. */ -interface CliIoHostOptions { +export class CliIoHost { /** - * If true, the host will use TTY features like color. + * Returns the singleton instance */ - useTTY?: boolean; + static getIoHost(): CliIoHost { + if (!CliIoHost.instance) { + CliIoHost.instance = new CliIoHost(); + } + return CliIoHost.instance; + } /** - * Flag representing whether the current process is running in a CI environment. - * If true, the host will write all messages to stdout, unless log level is 'error'. + * Singleton instance of the CliIoHost + */ + private static instance: CliIoHost | undefined; + + /** + * Determines which output stream to use based on log level and configuration. + */ + private static getStream(level: IoMessageLevel, forceStdout: boolean) { + // For legacy purposes all log streams are written to stderr by default, unless + // specified otherwise, by passing `forceStdout`, which is used by the `data()` logging function, or + // if the CDK is running in a CI environment. This is because some CI environments will immediately + // fail if stderr is written to. In these cases, we detect if we are in a CI environment and + // write all messages to stdout instead. + if (forceStdout) { + return process.stdout; + } + if (level == 'error') return process.stderr; + return this.ci ? process.stdout : process.stderr; + } + + /** + * Whether the host should apply chalk styles to messages. Defaults to false if the host is not running in a TTY. * * @default false */ - ci?: boolean; -} + private isTTY: boolean; -/** - * A simple IO host for the CLI that writes messages to the console. - */ -export class CliIoHost { - private readonly pretty_messages: boolean; - private readonly ci: boolean; + /** + * Whether the CliIoHost is running in CI mode. In CI mode, all non-error output goes to stdout instead of stderr. + * + * Set to false in the CliIoHost constructor it will be overwritten if the CLI CI argument is passed + */ + private ci: boolean; + + /** + * the current {@link ToolkitAction} set by the CLI. + */ + private currentAction: ToolkitAction | undefined; + + private constructor() { + this.isTTY = process.stdout.isTTY ?? false; + this.ci = false; + } + + public static get currentAction(): ToolkitAction | undefined { + return CliIoHost.getIoHost().currentAction; + } + + public static set currentAction(action: ToolkitAction) { + CliIoHost.getIoHost().currentAction = action; + } + + public static get ci(): boolean { + return CliIoHost.getIoHost().ci; + } + + public static set ci(value: boolean) { + CliIoHost.getIoHost().ci = value; + } + + public static get isTTY(): boolean { + return CliIoHost.getIoHost().isTTY; + } - constructor(options: CliIoHostOptions) { - this.pretty_messages = options.useTTY ?? process.stdout.isTTY ?? false; - this.ci = options.ci ?? false; + public static set isTTY(value: boolean) { + CliIoHost.getIoHost().isTTY = value; } /** @@ -80,7 +154,7 @@ export class CliIoHost { async notify(msg: IoMessage): Promise { const output = this.formatMessage(msg); - const stream = this.getStream(msg.level, msg.forceStdout ?? false); + const stream = CliIoHost.getStream(msg.level, msg.forceStdout ?? false); return new Promise((resolve, reject) => { stream.write(output, (err) => { @@ -93,28 +167,12 @@ export class CliIoHost { }); } - /** - * Determines which output stream to use based on log level and configuration. - */ - private getStream(level: IoMessageLevel, forceStdout: boolean) { - // For legacy purposes all log streams are written to stderr by default, unless - // specified otherwise, by passing `forceStdout`, which is used by the `data()` logging function, or - // if the CDK is running in a CI environment. This is because some CI environments will immediately - // fail if stderr is written to. In these cases, we detect if we are in a CI environment and - // write all messages to stdout instead. - if (forceStdout) { - return process.stdout; - } - if (level == 'error') return process.stderr; - return this.ci ? process.stdout : process.stderr; - } - /** * Formats a message for console output with optional color support */ private formatMessage(msg: IoMessage): string { // apply provided style or a default style if we're in TTY mode - let message_text = this.pretty_messages + let message_text = this.isTTY ? styleMap[msg.level](msg.message) : msg.message; diff --git a/packages/aws-cdk/lib/util/asset-publishing.ts b/packages/aws-cdk/lib/util/asset-publishing.ts index b35cedb3209d4..fd2739146fcdd 100644 --- a/packages/aws-cdk/lib/util/asset-publishing.ts +++ b/packages/aws-cdk/lib/util/asset-publishing.ts @@ -15,7 +15,7 @@ import { import type { SDK } from '../api'; import type { SdkProvider } from '../api/aws-auth/sdk-provider'; import { Mode } from '../api/plugin/mode'; -import { debug, error, print } from '../logging'; +import { debug, error, info } from '../logging'; export interface PublishAssetsOptions { /** @@ -227,8 +227,8 @@ export const EVENT_TO_LOGGER: Record void> = { debug, fail: error, found: debug, - start: print, - success: print, + start: info, + success: info, upload: debug, }; diff --git a/packages/aws-cdk/lib/version.ts b/packages/aws-cdk/lib/version.ts index a3b7f8383a28b..5b7fee798d80a 100644 --- a/packages/aws-cdk/lib/version.ts +++ b/packages/aws-cdk/lib/version.ts @@ -4,7 +4,7 @@ import * as fs from 'fs-extra'; import * as semver from 'semver'; import { cdkCacheDir, rootDir } from './util/directories'; import { getLatestVersionFromNpm } from './util/npm'; -import { debug, print } from '../lib/logging'; +import { debug, info } from '../lib/logging'; import { ToolkitError } from './toolkit/error'; import { formatAsBanner } from '../lib/util/console-formatters'; @@ -120,7 +120,7 @@ export async function displayVersionMessage(currentVersion = versionNumber(), ve const laterVersion = await latestVersionIfHigher(currentVersion, versionCheckCache ?? new VersionCheckTTL()); if (laterVersion) { const bannerMsg = formatAsBanner(getVersionMessage(currentVersion, laterVersion)); - bannerMsg.forEach((e) => print(e)); + bannerMsg.forEach((e) => info(e)); } } catch (err: any) { debug(`Could not run version check - ${err.message}`); diff --git a/packages/aws-cdk/test/api/exec.test.ts b/packages/aws-cdk/test/api/exec.test.ts index e67403dbb7680..fa450d241a6ae 100644 --- a/packages/aws-cdk/test/api/exec.test.ts +++ b/packages/aws-cdk/test/api/exec.test.ts @@ -7,7 +7,7 @@ import * as semver from 'semver'; import * as sinon from 'sinon'; import { ImportMock } from 'ts-mock-imports'; import { execProgram } from '../../lib/api/cxapp/exec'; -import { LogLevel, setLogLevel } from '../../lib/logging'; +import { setIoMessageThreshold } from '../../lib/logging'; import { Configuration } from '../../lib/settings'; import { testAssembly } from '../util'; import { mockSpawn } from '../util/mock-child_process'; @@ -18,7 +18,7 @@ import { rewriteManifestVersion } from './assembly-versions'; let sdkProvider: MockSdkProvider; let config: Configuration; beforeEach(() => { - setLogLevel(LogLevel.DEBUG); + setIoMessageThreshold('debug'); sdkProvider = new MockSdkProvider(); config = new Configuration(); @@ -37,7 +37,7 @@ beforeEach(() => { }); afterEach(() => { - setLogLevel(LogLevel.INFO); + setIoMessageThreshold('info'); sinon.restore(); bockfs.restore(); diff --git a/packages/aws-cdk/test/api/logs/cli-logging.test.ts b/packages/aws-cdk/test/api/logs/cli-logging.test.ts deleted file mode 100644 index bce7a9b35f231..0000000000000 --- a/packages/aws-cdk/test/api/logs/cli-logging.test.ts +++ /dev/null @@ -1,162 +0,0 @@ -import { LogLevel, log, setLogLevel, setCI, data, print, error, warning, success, debug, trace, prefix, withCorkedLogging } from '../../../lib/logging'; - -describe('logging', () => { - // Mock streams to capture output - let mockStdout: jest.Mock; - let mockStderr: jest.Mock; - - // Helper function to strip ANSI codes - const stripAnsi = (str: string): string => { - const ansiRegex = /\u001b\[[0-9;]*[a-zA-Z]/g; - return str.replace(ansiRegex, ''); - }; - - beforeEach(() => { - // Reset log level before each test - setLogLevel(LogLevel.INFO); - setCI(false); - - // Create mock functions to capture output - mockStdout = jest.fn(); - mockStderr = jest.fn(); - - // Mock the write methods directly and strip ANSI codes - jest.spyOn(process.stdout, 'write').mockImplementation((chunk: any) => { - mockStdout(stripAnsi(chunk.toString())); - return true; - }); - - jest.spyOn(process.stderr, 'write').mockImplementation((chunk: any) => { - mockStderr(stripAnsi(chunk.toString())); - return true; - }); - }); - - afterEach(() => { - jest.restoreAllMocks(); - }); - - describe('stream selection', () => { - test('data() always writes to stdout', () => { - data('test message'); - expect(mockStdout).toHaveBeenCalledWith('test message\n'); - expect(mockStderr).not.toHaveBeenCalled(); - }); - - test('error() always writes to stderr', () => { - error('test error'); - expect(mockStderr).toHaveBeenCalledWith('test error\n'); - expect(mockStdout).not.toHaveBeenCalled(); - }); - - test('print() writes to stderr by default', () => { - print('test print'); - expect(mockStderr).toHaveBeenCalledWith('test print\n'); - expect(mockStdout).not.toHaveBeenCalled(); - }); - - test('print() writes to stdout in CI mode', () => { - setCI(true); - print('test print'); - expect(mockStdout).toHaveBeenCalledWith('test print\n'); - expect(mockStderr).not.toHaveBeenCalled(); - }); - }); - - describe('log levels', () => { - test('respects log level settings', () => { - setLogLevel(LogLevel.ERROR); - error('error message'); - warning('warning message'); - print('print message'); - expect(mockStderr).toHaveBeenCalledWith('error message\n'); - expect(mockStderr).not.toHaveBeenCalledWith('warning message\n'); - expect(mockStderr).not.toHaveBeenCalledWith('print message\n'); - }); - - test('debug messages only show at debug level', () => { - setLogLevel(LogLevel.INFO); - debug('debug message'); - expect(mockStderr).not.toHaveBeenCalled(); - - setLogLevel(LogLevel.DEBUG); - debug('debug message'); - expect(mockStderr).toHaveBeenCalledWith( - expect.stringMatching(/^\[\d{2}:\d{2}:\d{2}\] debug message\n$/), - ); - }); - - test('trace messages only show at trace level', () => { - setLogLevel(LogLevel.DEBUG); - trace('trace message'); - expect(mockStderr).not.toHaveBeenCalled(); - - setLogLevel(LogLevel.TRACE); - trace('trace message'); - expect(mockStderr).toHaveBeenCalledWith( - expect.stringMatching(/^\[\d{2}:\d{2}:\d{2}\] trace message\n$/), - ); - }); - }); - - describe('message formatting', () => { - test('formats messages with multiple arguments', () => { - print('Value: %d, String: %s', 42, 'test'); - expect(mockStderr).toHaveBeenCalledWith('Value: 42, String: test\n'); - }); - - test('handles prefix correctly', () => { - const prefixedLog = prefix('PREFIX'); - prefixedLog('test message'); - expect(mockStderr).toHaveBeenCalledWith('PREFIX test message\n'); - }); - - test('handles custom styles', () => { - success('success message'); - expect(mockStderr).toHaveBeenCalledWith('success message\n'); - }); - }); - - describe('corked logging', () => { - test('buffers messages when corked', async () => { - await withCorkedLogging(async () => { - print('message 1'); - print('message 2'); - expect(mockStderr).not.toHaveBeenCalled(); - }); - - expect(mockStderr).toHaveBeenCalledWith('message 1\n'); - expect(mockStderr).toHaveBeenCalledWith('message 2\n'); - }); - - test('handles nested corking correctly', async () => { - await withCorkedLogging(async () => { - print('outer 1'); - await withCorkedLogging(async () => { - print('inner'); - }); - print('outer 2'); - expect(mockStderr).not.toHaveBeenCalled(); - }); - - expect(mockStderr).toHaveBeenCalledTimes(3); - expect(mockStderr).toHaveBeenCalledWith('outer 1\n'); - expect(mockStderr).toHaveBeenCalledWith('inner\n'); - expect(mockStderr).toHaveBeenCalledWith('outer 2\n'); - }); - }); - - describe('timestamp and prefix handling', () => { - test('combines timestamp and prefix correctly', () => { - log({ - level: LogLevel.INFO, - message: 'test message', - timestamp: true, - prefix: 'PREFIX', - }); - expect(mockStderr).toHaveBeenCalledWith( - expect.stringMatching(/^PREFIX \[\d{2}:\d{2}:\d{2}\] test message\n$/), - ); - }); - }); -}); diff --git a/packages/aws-cdk/test/api/logs/logging.test.ts b/packages/aws-cdk/test/api/logs/logging.test.ts new file mode 100644 index 0000000000000..b7ec1db6df603 --- /dev/null +++ b/packages/aws-cdk/test/api/logs/logging.test.ts @@ -0,0 +1,333 @@ +import { setIoMessageThreshold, setCI, data, success, highlight, error, warning, info, debug, trace, withCorkedLogging } from '../../../lib/logging'; + +describe('logging', () => { + let mockStdout: jest.Mock; + let mockStderr: jest.Mock; + + const stripAnsi = (str: string): string => { + const ansiRegex = /\u001b\[[0-9;]*[a-zA-Z]/g; + return str.replace(ansiRegex, ''); + }; + + beforeEach(() => { + setIoMessageThreshold('info'); + setCI(false); + + mockStdout = jest.fn(); + mockStderr = jest.fn(); + + jest.spyOn(process.stdout, 'write').mockImplementation((chunk: any) => { + mockStdout(stripAnsi(chunk.toString())); + return true; + }); + + jest.spyOn(process.stderr, 'write').mockImplementation((chunk: any) => { + mockStderr(stripAnsi(chunk.toString())); + return true; + }); + }); + + afterEach(() => { + jest.restoreAllMocks(); + }); + + describe('stream selection', () => { + test('data() always writes to stdout with both styles', () => { + // String style + data('test message'); + expect(mockStdout).toHaveBeenCalledWith('test message\n'); + + // Object style + data({ message: 'test message 2' }); + expect(mockStdout).toHaveBeenCalledWith('test message 2\n'); + expect(mockStderr).not.toHaveBeenCalled(); + }); + + test('error() always writes to stderr with both styles', () => { + // String style + error('test error'); + expect(mockStderr).toHaveBeenCalledWith('test error\n'); + + // Object style + error({ message: 'test error 2' }); + expect(mockStderr).toHaveBeenCalledWith('test error 2\n'); + expect(mockStdout).not.toHaveBeenCalled(); + }); + + test('info() writes to stderr by default with both styles', () => { + // String style + info('test print'); + expect(mockStderr).toHaveBeenCalledWith('test print\n'); + + // Object style + info({ message: 'test print 2' }); + expect(mockStderr).toHaveBeenCalledWith('test print 2\n'); + expect(mockStdout).not.toHaveBeenCalled(); + }); + + test('info() writes to stdout in CI mode with both styles', () => { + setCI(true); + // String style + info('test print'); + expect(mockStdout).toHaveBeenCalledWith('test print\n'); + + // Object style + info({ message: 'test print 2' }); + expect(mockStdout).toHaveBeenCalledWith('test print 2\n'); + expect(mockStderr).not.toHaveBeenCalled(); + }); + }); + + describe('log levels', () => { + test('respects log level settings with both styles', () => { + setIoMessageThreshold('error'); + + // String style + error('error message'); + warning('warning message'); + info('print message'); + + // Object style + error({ message: 'error message 2' }); + warning({ message: 'warning message 2' }); + info({ message: 'print message 2' }); + + expect(mockStderr).toHaveBeenCalledWith('error message\n'); + expect(mockStderr).toHaveBeenCalledWith('error message 2\n'); + expect(mockStderr).not.toHaveBeenCalledWith('warning message\n'); + expect(mockStderr).not.toHaveBeenCalledWith('warning message 2\n'); + expect(mockStderr).not.toHaveBeenCalledWith('print message\n'); + expect(mockStderr).not.toHaveBeenCalledWith('print message 2\n'); + }); + + test('debug messages only show at debug level with both styles', () => { + setIoMessageThreshold('info'); + debug('debug message'); + debug({ message: 'debug message 2' }); + expect(mockStderr).not.toHaveBeenCalled(); + + setIoMessageThreshold('debug'); + debug('debug message'); + debug({ message: 'debug message 2' }); + expect(mockStderr).toHaveBeenCalledWith( + expect.stringMatching(/^\[\d{2}:\d{2}:\d{2}\] debug message\n$/), + ); + expect(mockStderr).toHaveBeenCalledWith( + expect.stringMatching(/^\[\d{2}:\d{2}:\d{2}\] debug message 2\n$/), + ); + }); + + test('trace messages only show at trace level with both styles', () => { + setIoMessageThreshold('debug'); + trace('trace message'); + trace({ message: 'trace message 2' }); + expect(mockStderr).not.toHaveBeenCalled(); + + setIoMessageThreshold('trace'); + trace('trace message'); + trace({ message: 'trace message 2' }); + expect(mockStderr).toHaveBeenCalledWith( + expect.stringMatching(/^\[\d{2}:\d{2}:\d{2}\] trace message\n$/), + ); + expect(mockStderr).toHaveBeenCalledWith( + expect.stringMatching(/^\[\d{2}:\d{2}:\d{2}\] trace message 2\n$/), + ); + }); + }); + + describe('formatted messages', () => { + test('handles format strings correctly with both styles', () => { + // String style + info('Hello %s, you have %d messages', 'User', 5); + expect(mockStderr).toHaveBeenCalledWith('Hello User, you have 5 messages\n'); + + // Object style + info({ message: 'Hello %s, you have %d messages' }, 'User', 5); + expect(mockStderr).toHaveBeenCalledWith('Hello User, you have 5 messages\n'); + }); + + test('handles objects in format strings with both styles', () => { + const obj = { name: 'test' }; + // String style + info('Object: %j', obj); + expect(mockStderr).toHaveBeenCalledWith('Object: {"name":"test"}\n'); + + // Object style + info({ message: 'Object: %j' }, obj); + expect(mockStderr).toHaveBeenCalledWith('Object: {"name":"test"}\n'); + }); + + test('handles multiple style changes in single call', () => { + const obj = { id: 123 }; + success('Processing %s: %j at %d%%', 'task', obj, 50); + expect(mockStderr).toHaveBeenCalledWith( + 'Processing task: {"id":123} at 50%\n', + ); + }); + }); + + describe('styled output', () => { + test('success() adds green color to output with both styles', () => { + // String style + success('operation completed'); + expect(mockStderr).toHaveBeenCalledWith('operation completed\n'); + + // Object style + success({ message: 'operation completed 2' }); + expect(mockStderr).toHaveBeenCalledWith('operation completed 2\n'); + }); + + test('highlight() adds bold formatting to output with both styles', () => { + // String style + highlight('important message'); + expect(mockStderr).toHaveBeenCalledWith('important message\n'); + + // Object style + highlight({ message: 'important message 2' }); + expect(mockStderr).toHaveBeenCalledWith('important message 2\n'); + }); + + test('success handles format strings with styling', () => { + success('completed task %d of %d', 1, 3); + expect(mockStderr).toHaveBeenCalledWith('completed task 1 of 3\n'); + + // Remove the code from the test since it's an implementation detail + success({ message: 'completed task %d of %d' }, 2, 3); + expect(mockStderr).toHaveBeenCalledWith('completed task 2 of 3\n'); + }); + + test('highlight handles complex objects with styling', () => { + const complexObj = { status: 'active', count: 42 }; + highlight('Status: %j', complexObj); + expect(mockStderr).toHaveBeenCalledWith('Status: {"status":"active","count":42}\n'); + + // Remove the code from the test since it's an implementation detail + highlight({ message: 'Status: %j' }, complexObj); + expect(mockStderr).toHaveBeenCalledWith('Status: {"status":"active","count":42}\n'); + }); + }); + + describe('edge cases', () => { + test('handles null and undefined arguments with both styles', () => { + // String style + info('Values: %s, %s', null, undefined); + expect(mockStderr).toHaveBeenCalledWith('Values: null, undefined\n'); + + // Object style + info({ message: 'Values: %s, %s' }, null, undefined); + expect(mockStderr).toHaveBeenCalledWith('Values: null, undefined\n'); + }); + + test('handles circular references in objects with both styles', () => { + const obj: any = { name: 'test' }; + obj.self = obj; + + // String style + info('Object: %j', obj); + expect(mockStderr).toHaveBeenCalledWith(expect.stringContaining('[Circular')); + + // Object style + info({ message: 'Object: %j' }, obj); + expect(mockStderr).toHaveBeenCalledWith(expect.stringContaining('[Circular')); + }); + }); + + describe('message codes', () => { + test('validates message codes correctly', () => { + // Valid codes + expect(() => error({ message: 'test', code: 'CDK_TOOLKIT_E0001' })).not.toThrow(); + expect(() => warning({ message: 'test', code: 'CDK_ASSETS_W4999' })).not.toThrow(); + expect(() => info({ message: 'test', code: 'CDK_SDK_I0000' })).not.toThrow(); + }); + + test('uses default codes when none provided', () => { + error('test error'); + expect(mockStderr).toHaveBeenCalledWith(expect.stringContaining('test error')); + // Would need to modify the code to expose the actual message code for verification + }); + }); + + describe('corked logging', () => { + test('buffers messages when corked', async () => { + await withCorkedLogging(async () => { + info('message 1'); + info({ message: 'message 2' }); + expect(mockStderr).not.toHaveBeenCalled(); + }); + + expect(mockStderr).toHaveBeenCalledWith('message 1\n'); + expect(mockStderr).toHaveBeenCalledWith('message 2\n'); + }); + + test('handles nested corking correctly', async () => { + await withCorkedLogging(async () => { + info('outer 1'); + await withCorkedLogging(async () => { + info({ message: 'inner' }); + }); + info({ message: 'outer 2' }); + expect(mockStderr).not.toHaveBeenCalled(); + }); + + expect(mockStderr).toHaveBeenCalledTimes(3); + expect(mockStderr).toHaveBeenCalledWith('outer 1\n'); + expect(mockStderr).toHaveBeenCalledWith('inner\n'); + expect(mockStderr).toHaveBeenCalledWith('outer 2\n'); + }); + + test('handles errors in corked block while preserving buffer', async () => { + await expect(withCorkedLogging(async () => { + info('message 1'); + throw new Error('test error'); + })).rejects.toThrow('test error'); + + // The buffered message should still be printed even if the block throws + expect(mockStderr).toHaveBeenCalledWith('message 1\n'); + }); + + test('maintains correct order with mixed log levels in corked block', async () => { + // Set threshold to debug to allow debug messages + setIoMessageThreshold('debug'); + + await withCorkedLogging(async () => { + error('error message'); + warning('warning message'); + success('success message'); + debug('debug message'); + }); + + const calls = mockStderr.mock.calls.map(call => call[0]); + expect(calls).toEqual([ + 'error message\n', + 'warning message\n', + 'success message\n', + expect.stringMatching(/^\[\d{2}:\d{2}:\d{2}\] debug message\n$/), + ]); + + // Reset threshold back to info for other tests + setIoMessageThreshold('info'); + }); + }); + + describe('CI mode behavior', () => { + test('correctly switches between stdout and stderr based on CI mode', () => { + setCI(true); + warning('warning in CI'); + success('success in CI'); + error('error in CI'); + + expect(mockStdout).toHaveBeenCalledWith('warning in CI\n'); + expect(mockStdout).toHaveBeenCalledWith('success in CI\n'); + expect(mockStderr).toHaveBeenCalledWith('error in CI\n'); + + setCI(false); + warning('warning not in CI'); + success('success not in CI'); + error('error not in CI'); + + expect(mockStderr).toHaveBeenCalledWith('warning not in CI\n'); + expect(mockStderr).toHaveBeenCalledWith('success not in CI\n'); + expect(mockStderr).toHaveBeenCalledWith('error not in CI\n'); + }); + }); +}); diff --git a/packages/aws-cdk/test/api/sdk-provider.test.ts b/packages/aws-cdk/test/api/sdk-provider.test.ts index 6d87e891a93ea..50bbb1faeeebd 100644 --- a/packages/aws-cdk/test/api/sdk-provider.test.ts +++ b/packages/aws-cdk/test/api/sdk-provider.test.ts @@ -10,7 +10,7 @@ import { AwsCliCompatible } from '../../lib/api/aws-auth/awscli-compatible'; import { defaultCliUserAgent } from '../../lib/api/aws-auth/user-agent'; import { PluginHost } from '../../lib/api/plugin'; import { Mode } from '../../lib/api/plugin/mode'; -import * as logging from '../../lib/logging'; +import { setIoMessageThreshold } from '../../lib/logging'; import { withMocked } from '../util'; import { mockSTSClient, restoreSdkMocksToDefault } from '../util/mock-sdk'; @@ -40,7 +40,7 @@ beforeEach(() => { uid = `(${uuid.v4()})`; pluginQueried = false; - logging.setLogLevel(logging.LogLevel.TRACE); + setIoMessageThreshold('trace'); PluginHost.instance.credentialProviderSources.splice(0); PluginHost.instance.credentialProviderSources.push({ diff --git a/packages/aws-cdk/test/api/stack-activity-monitor.test.ts b/packages/aws-cdk/test/api/stack-activity-monitor.test.ts index a5cf50df7ec25..d4f47d5755868 100644 --- a/packages/aws-cdk/test/api/stack-activity-monitor.test.ts +++ b/packages/aws-cdk/test/api/stack-activity-monitor.test.ts @@ -1,5 +1,5 @@ /* eslint-disable import/order */ -import { bold, reset, green, yellow, red } from 'chalk'; +import * as chalk from 'chalk'; import { stderr } from './console-listener'; import { HistoryActivityPrinter } from '../../lib/api/util/cloudformation/stack-activity-monitor'; import { ResourceStatus } from '@aws-sdk/client-cloudformation'; @@ -35,7 +35,7 @@ test('prints 0/4 progress report, when addActivity is called with an "IN_PROGRES }); expect(output[0].trim()).toStrictEqual( - `stack-name | 0/4 | ${HUMAN_TIME} | ${reset('CREATE_IN_PROGRESS ')} | AWS::CloudFormation::Stack | ${reset(bold('stack1'))}`, + `stack-name | 0/4 | ${HUMAN_TIME} | ${chalk.reset('CREATE_IN_PROGRESS ')} | AWS::CloudFormation::Stack | ${chalk.reset(chalk.bold('stack1'))}`, ); }); @@ -62,7 +62,7 @@ test('prints 1/4 progress report, when addActivity is called with an "UPDATE_COM }); expect(output[0].trim()).toStrictEqual( - `stack-name | 1/4 | ${HUMAN_TIME} | ${green('UPDATE_COMPLETE ')} | AWS::CloudFormation::Stack | ${green(bold('stack1'))}`, + `stack-name | 1/4 | ${HUMAN_TIME} | ${chalk.green('UPDATE_COMPLETE ')} | AWS::CloudFormation::Stack | ${chalk.green(chalk.bold('stack1'))}`, ); }); @@ -89,7 +89,7 @@ test('prints 1/4 progress report, when addActivity is called with an "UPDATE_COM }); expect(output[0].trim()).toStrictEqual( - `stack-name | 1/4 | ${HUMAN_TIME} | ${green('UPDATE_COMPLETE ')} | AWS::CloudFormation::Stack | ${green(bold('stack1'))}`, + `stack-name | 1/4 | ${HUMAN_TIME} | ${chalk.green('UPDATE_COMPLETE ')} | AWS::CloudFormation::Stack | ${chalk.green(chalk.bold('stack1'))}`, ); }); @@ -116,7 +116,7 @@ test('prints 1/4 progress report, when addActivity is called with an "ROLLBACK_C }); expect(output[0].trim()).toStrictEqual( - `stack-name | 1/4 | ${HUMAN_TIME} | ${yellow('ROLLBACK_COMPLETE ')} | AWS::CloudFormation::Stack | ${yellow(bold('stack1'))}`, + `stack-name | 1/4 | ${HUMAN_TIME} | ${chalk.yellow('ROLLBACK_COMPLETE ')} | AWS::CloudFormation::Stack | ${chalk.yellow(chalk.bold('stack1'))}`, ); }); @@ -143,7 +143,7 @@ test('prints 0/4 progress report, when addActivity is called with an "UPDATE_FAI }); expect(output[0].trim()).toStrictEqual( - `stack-name | 0/4 | ${HUMAN_TIME} | ${red('UPDATE_FAILED ')} | AWS::CloudFormation::Stack | ${red(bold('stack1'))}`, + `stack-name | 0/4 | ${HUMAN_TIME} | ${chalk.red('UPDATE_FAILED ')} | AWS::CloudFormation::Stack | ${chalk.red(chalk.bold('stack1'))}`, ); }); @@ -196,13 +196,13 @@ test('does not print "Failed Resources:" list, when all deployments are successf expect(output.length).toStrictEqual(3); expect(output[0].trim()).toStrictEqual( - `stack-name | 0/2 | ${HUMAN_TIME} | ${reset('UPDATE_IN_PROGRESS ')} | AWS::CloudFormation::Stack | ${reset(bold('stack1'))}`, + `stack-name | 0/2 | ${HUMAN_TIME} | ${chalk.reset('UPDATE_IN_PROGRESS ')} | AWS::CloudFormation::Stack | ${chalk.reset(chalk.bold('stack1'))}`, ); expect(output[1].trim()).toStrictEqual( - `stack-name | 1/2 | ${HUMAN_TIME} | ${green('UPDATE_COMPLETE ')} | AWS::CloudFormation::Stack | ${green(bold('stack1'))}`, + `stack-name | 1/2 | ${HUMAN_TIME} | ${chalk.green('UPDATE_COMPLETE ')} | AWS::CloudFormation::Stack | ${chalk.green(chalk.bold('stack1'))}`, ); expect(output[2].trim()).toStrictEqual( - `stack-name | 2/2 | ${HUMAN_TIME} | ${green('UPDATE_COMPLETE ')} | AWS::CloudFormation::Stack | ${green(bold('stack2'))}`, + `stack-name | 2/2 | ${HUMAN_TIME} | ${chalk.green('UPDATE_COMPLETE ')} | AWS::CloudFormation::Stack | ${chalk.green(chalk.bold('stack2'))}`, ); }); @@ -243,14 +243,14 @@ test('prints "Failed Resources:" list, when at least one deployment fails', () = expect(output.length).toStrictEqual(4); expect(output[0].trim()).toStrictEqual( - `stack-name | 0/2 | ${HUMAN_TIME} | ${reset('UPDATE_IN_PROGRESS ')} | AWS::CloudFormation::Stack | ${reset(bold('stack1'))}`, + `stack-name | 0/2 | ${HUMAN_TIME} | ${chalk.reset('UPDATE_IN_PROGRESS ')} | AWS::CloudFormation::Stack | ${chalk.reset(chalk.bold('stack1'))}`, ); expect(output[1].trim()).toStrictEqual( - `stack-name | 0/2 | ${HUMAN_TIME} | ${red('UPDATE_FAILED ')} | AWS::CloudFormation::Stack | ${red(bold('stack1'))}`, + `stack-name | 0/2 | ${HUMAN_TIME} | ${chalk.red('UPDATE_FAILED ')} | AWS::CloudFormation::Stack | ${chalk.red(chalk.bold('stack1'))}`, ); expect(output[2].trim()).toStrictEqual('Failed resources:'); expect(output[3].trim()).toStrictEqual( - `stack-name | ${HUMAN_TIME} | ${red('UPDATE_FAILED ')} | AWS::CloudFormation::Stack | ${red(bold('stack1'))}`, + `stack-name | ${HUMAN_TIME} | ${chalk.red('UPDATE_FAILED ')} | AWS::CloudFormation::Stack | ${chalk.red(chalk.bold('stack1'))}`, ); }); @@ -295,13 +295,13 @@ test('print failed resources because of hook failures', () => { expect(output.length).toStrictEqual(4); expect(output[0].trim()).toStrictEqual( - `stack-name | 0/2 | ${HUMAN_TIME} | ${reset('UPDATE_IN_PROGRESS ')} | AWS::CloudFormation::Stack | ${reset(bold('stack1'))}`, + `stack-name | 0/2 | ${HUMAN_TIME} | ${chalk.reset('UPDATE_IN_PROGRESS ')} | AWS::CloudFormation::Stack | ${chalk.reset(chalk.bold('stack1'))}`, ); expect(output[1].trim()).toStrictEqual( - `stack-name | 0/2 | ${HUMAN_TIME} | ${red('UPDATE_FAILED ')} | AWS::CloudFormation::Stack | ${red(bold('stack1'))} ${red(bold('The following hook(s) failed: hook1 : stack1 must obey certain rules'))}`, + `stack-name | 0/2 | ${HUMAN_TIME} | ${chalk.red('UPDATE_FAILED ')} | AWS::CloudFormation::Stack | ${chalk.red(chalk.bold('stack1'))} ${chalk.red(chalk.bold('The following hook(s) failed: hook1 : stack1 must obey certain rules'))}`, ); expect(output[2].trim()).toStrictEqual('Failed resources:'); expect(output[3].trim()).toStrictEqual( - `stack-name | ${HUMAN_TIME} | ${red('UPDATE_FAILED ')} | AWS::CloudFormation::Stack | ${red(bold('stack1'))} ${red(bold('The following hook(s) failed: hook1 : stack1 must obey certain rules'))}`, + `stack-name | ${HUMAN_TIME} | ${chalk.red('UPDATE_FAILED ')} | AWS::CloudFormation::Stack | ${chalk.red(chalk.bold('stack1'))} ${chalk.red(chalk.bold('The following hook(s) failed: hook1 : stack1 must obey certain rules'))}`, ); }); diff --git a/packages/aws-cdk/test/cli.test.ts b/packages/aws-cdk/test/cli.test.ts index e0887059c8732..d4a524c6a7cae 100644 --- a/packages/aws-cdk/test/cli.test.ts +++ b/packages/aws-cdk/test/cli.test.ts @@ -1,5 +1,5 @@ import { exec } from '../lib/cli'; -import { LogLevel, setLogLevel } from '../lib/logging'; +import { setIoMessageThreshold } from '../lib/logging'; // Store original version module exports so we don't conflict with other tests const originalVersion = jest.requireActual('../lib/version'); @@ -10,7 +10,7 @@ jest.mock('../lib/logging', () => ({ DEBUG: 'DEBUG', TRACE: 'TRACE', }, - setLogLevel: jest.fn(), + setIoMessageThreshold: jest.fn(), debug: jest.fn(), error: jest.fn(), print: jest.fn(), @@ -74,31 +74,31 @@ describe('exec verbose flag tests', () => { test('should not set log level when no verbose flag is present', async () => { await exec(['version']); - expect(setLogLevel).not.toHaveBeenCalled(); + expect(setIoMessageThreshold).not.toHaveBeenCalled(); }); test('should set DEBUG level with single -v flag', async () => { await exec(['-v', 'version']); - expect(setLogLevel).toHaveBeenCalledWith(LogLevel.DEBUG); + expect(setIoMessageThreshold).toHaveBeenCalledWith('debug'); }); test('should set TRACE level with double -v flag', async () => { await exec(['-v', '-v', 'version']); - expect(setLogLevel).toHaveBeenCalledWith(LogLevel.TRACE); + expect(setIoMessageThreshold).toHaveBeenCalledWith('trace'); }); test('should set DEBUG level with --verbose=1', async () => { await exec(['--verbose', '1', 'version']); - expect(setLogLevel).toHaveBeenCalledWith(LogLevel.DEBUG); + expect(setIoMessageThreshold).toHaveBeenCalledWith('debug'); }); test('should set TRACE level with --verbose=2', async () => { await exec(['--verbose', '2', 'version']); - expect(setLogLevel).toHaveBeenCalledWith(LogLevel.TRACE); + expect(setIoMessageThreshold).toHaveBeenCalledWith('trace'); }); test('should set TRACE level with verbose level > 2', async () => { await exec(['--verbose', '3', 'version']); - expect(setLogLevel).toHaveBeenCalledWith(LogLevel.TRACE); + expect(setIoMessageThreshold).toHaveBeenCalledWith('trace'); }); }); diff --git a/packages/aws-cdk/test/notices.test.ts b/packages/aws-cdk/test/notices.test.ts index 8a70067573251..f082091c5ae31 100644 --- a/packages/aws-cdk/test/notices.test.ts +++ b/packages/aws-cdk/test/notices.test.ts @@ -508,7 +508,7 @@ describe(Notices, () => { dataSource: { fetch: async () => [BOOTSTRAP_NOTICE_V10, BOOTSTRAP_NOTICE_V11] }, }); - const print = jest.spyOn(logging, 'print'); + const print = jest.spyOn(logging, 'info'); notices.display(); expect(print).toHaveBeenCalledWith(new FilteredNotice(BOOTSTRAP_NOTICE_V10).format()); @@ -555,7 +555,7 @@ describe(Notices, () => { dataSource: { fetch: async () => [BASIC_NOTICE, BASIC_NOTICE] }, }); - const print = jest.spyOn(logging, 'print'); + const print = jest.spyOn(logging, 'info'); notices.display(); expect(print).toHaveBeenCalledWith(new FilteredNotice(BASIC_NOTICE).format()); @@ -570,7 +570,7 @@ describe(Notices, () => { dataSource: { fetch: async () => [] }, }); - const print = jest.spyOn(logging, 'print'); + const print = jest.spyOn(logging, 'info'); notices.display({ showTotal: true }); expect(print).toHaveBeenNthCalledWith(1, ''); @@ -615,7 +615,7 @@ describe(Notices, () => { dataSource: { fetch: async () => [BASIC_NOTICE, MULTIPLE_AFFECTED_VERSIONS_NOTICE] }, }); - const print = jest.spyOn(logging, 'print'); + const print = jest.spyOn(logging, 'info'); notices.display(); expect(print).toHaveBeenNthCalledWith(4, new FilteredNotice(BASIC_NOTICE).format()); @@ -633,7 +633,7 @@ describe(Notices, () => { dataSource: { fetch: async () => [BASIC_NOTICE, MULTIPLE_AFFECTED_VERSIONS_NOTICE] }, }); - const print = jest.spyOn(logging, 'print'); + const print = jest.spyOn(logging, 'info'); notices.display(); expect(print).toHaveBeenCalledWith(new FilteredNotice(BASIC_NOTICE).format()); @@ -651,7 +651,7 @@ describe(Notices, () => { dataSource: { fetch: async () => [BASIC_NOTICE, BASIC_NOTICE] }, }); - const print = jest.spyOn(logging, 'print'); + const print = jest.spyOn(logging, 'info'); notices.display(); expect(print).toHaveBeenNthCalledWith(2, 'NOTICES (What\'s this? https://github.com/aws/aws-cdk/wiki/CLI-Notices)'); @@ -667,7 +667,7 @@ describe(Notices, () => { dataSource: { fetch: async () => [BASIC_NOTICE, BASIC_NOTICE] }, }); - const print = jest.spyOn(logging, 'print'); + const print = jest.spyOn(logging, 'info'); notices.display(); expect(print).toHaveBeenNthCalledWith(4, new FilteredNotice(BASIC_NOTICE).format()); @@ -678,21 +678,21 @@ describe(Notices, () => { const notices = Notices.create({ context: new Context(), shouldDisplay: false }); await notices.refresh({ dataSource: { fetch: async () => [BASIC_NOTICE] } }); - const print = jest.spyOn(logging, 'print'); + const print = jest.spyOn(logging, 'info'); notices.display(); expect(print).toHaveBeenCalledTimes(0); }); test('nothing when there are no notices', async () => { - const print = jest.spyOn(logging, 'print'); + const print = jest.spyOn(logging, 'info'); Notices.create({ context: new Context() }).display(); expect(print).toHaveBeenCalledTimes(0); }); test('total count when show total is true', async () => { - const print = jest.spyOn(logging, 'print'); + const print = jest.spyOn(logging, 'info'); Notices.create({ context: new Context() }).display({ showTotal: true }); expect(print).toHaveBeenNthCalledWith(2, 'There are 0 unacknowledged notice(s).'); @@ -739,7 +739,7 @@ describe(Notices, () => { dataSource: { fetch: async () => [BASIC_NOTICE] }, }); - const print = jest.spyOn(logging, 'print'); + const print = jest.spyOn(logging, 'info'); notices.display(); expect(print).toHaveBeenNthCalledWith(4, new FilteredNotice(BASIC_NOTICE).format()); @@ -756,7 +756,7 @@ describe(Notices, () => { dataSource: { fetch: async () => [BASIC_NOTICE, MULTIPLE_AFFECTED_VERSIONS_NOTICE] }, }); - const print = jest.spyOn(logging, 'print'); + const print = jest.spyOn(logging, 'info'); notices.display(); expect(print).toHaveBeenNthCalledWith(4, new FilteredNotice(BASIC_NOTICE).format()); @@ -772,7 +772,7 @@ describe(Notices, () => { dataSource: { fetch: async () => [BASIC_NOTICE, MULTIPLE_AFFECTED_VERSIONS_NOTICE] }, }); - const print = jest.spyOn(logging, 'print'); + const print = jest.spyOn(logging, 'info'); notices.display(); expect(print).toHaveBeenNthCalledWith(4, new FilteredNotice(BASIC_NOTICE).format()); diff --git a/packages/aws-cdk/test/toolkit/cli-io-host.test.ts b/packages/aws-cdk/test/toolkit/cli-io-host.test.ts index 983294583736a..7ea32efcf6c2e 100644 --- a/packages/aws-cdk/test/toolkit/cli-io-host.test.ts +++ b/packages/aws-cdk/test/toolkit/cli-io-host.test.ts @@ -1,18 +1,30 @@ import * as chalk from 'chalk'; -import { CliIoHost, IoAction, styleMap } from '../../lib/toolkit/cli-io-host'; +import { CliIoHost, IoMessage } from '../../lib/toolkit/cli-io-host'; describe('CliIoHost', () => { let mockStdout: jest.Mock; let mockStderr: jest.Mock; + let defaultMessage: IoMessage; beforeEach(() => { mockStdout = jest.fn(); mockStderr = jest.fn(); - // Mock the write methods of STD out and STD err + // Reset singleton state + CliIoHost.isTTY = process.stdout.isTTY ?? false; + CliIoHost.ci = false; + CliIoHost.currentAction = 'none'; + + defaultMessage = { + time: new Date('2024-01-01T12:00:00'), + level: 'info', + action: 'synth', + code: 'CDK_TOOLKIT_I0001', + message: 'test message', + }; + jest.spyOn(process.stdout, 'write').mockImplementation((str: any, encoding?: any, cb?: any) => { mockStdout(str.toString()); - // Handle callback const callback = typeof encoding === 'function' ? encoding : cb; if (callback) callback(); return true; @@ -20,7 +32,6 @@ describe('CliIoHost', () => { jest.spyOn(process.stderr, 'write').mockImplementation((str: any, encoding?: any, cb?: any) => { mockStderr(str.toString()); - // Handle callback const callback = typeof encoding === 'function' ? encoding : cb; if (callback) callback(); return true; @@ -33,12 +44,12 @@ describe('CliIoHost', () => { describe('stream selection', () => { test('writes to stderr by default for non-error messages in non-CI mode', async () => { - const host = new CliIoHost({ useTTY: true }); - await host.notify({ + CliIoHost.isTTY = true; + await CliIoHost.getIoHost().notify({ time: new Date(), level: 'info', action: 'synth', - code: 'TEST', + code: 'CDK_TOOLKIT_I0001', message: 'test message', }); @@ -47,12 +58,12 @@ describe('CliIoHost', () => { }); test('writes to stderr for error level with red color', async () => { - const host = new CliIoHost({ useTTY: true }); - await host.notify({ + CliIoHost.isTTY = true; + await CliIoHost.getIoHost().notify({ time: new Date(), level: 'error', action: 'synth', - code: 'TEST', + code: 'CDK_TOOLKIT_E0001', message: 'error message', }); @@ -61,12 +72,12 @@ describe('CliIoHost', () => { }); test('writes to stdout when forceStdout is true', async () => { - const host = new CliIoHost({ useTTY: true }); - await host.notify({ + CliIoHost.isTTY = true; + await CliIoHost.getIoHost().notify({ time: new Date(), level: 'info', action: 'synth', - code: 'TEST', + code: 'CDK_TOOLKIT_I0001', message: 'forced message', forceStdout: true, }); @@ -76,142 +87,87 @@ describe('CliIoHost', () => { }); }); - describe('TTY formatting', () => { - test('accepts inlined chalk styles', async () => { - const host = new CliIoHost({ useTTY: true }); - await host.notify({ - time: new Date(), - level: 'info', - action: 'synth', - code: 'TEST', - message: chalk.green('[green prefix message]') + ' regular info level text', - forceStdout: true, - }); - - const expected_text = styleMap.info(chalk.green('[green prefix message]') + ' regular info level text'); - expect(mockStdout).toHaveBeenCalledWith(expected_text + '\n'); + describe('message formatting', () => { + beforeEach(() => { + CliIoHost.isTTY = true; }); - test('applies custom style in TTY mode', async () => { - const host = new CliIoHost({ useTTY: true }); - const customStyle = (str: string) => `\x1b[35m${str}\x1b[0m`; // Custom purple color - - await host.notify({ - time: new Date(), - level: 'info', - action: 'synth', - code: 'TEST', - message: customStyle('styled message'), + test('formats debug messages with timestamp', async () => { + await CliIoHost.getIoHost().notify({ + ...defaultMessage, + level: 'debug', forceStdout: true, }); - const expected_text = styleMap.info(customStyle('styled message')); - expect(mockStdout).toHaveBeenCalledWith(expected_text + '\n'); + expect(mockStdout).toHaveBeenCalledWith(`[12:00:00] ${chalk.gray('test message')}\n`); }); - test('applies default style by message level in TTY mode', async () => { - const host = new CliIoHost({ useTTY: true }); - await host.notify({ - time: new Date(), - level: 'warn', - action: 'synth', - code: 'TEST', - message: 'warning message', + test('formats trace messages with timestamp', async () => { + await CliIoHost.getIoHost().notify({ + ...defaultMessage, + level: 'trace', forceStdout: true, }); - expect(mockStdout).toHaveBeenCalledWith(chalk.yellow('warning message') + '\n'); + expect(mockStdout).toHaveBeenCalledWith(`[12:00:00] ${chalk.gray('test message')}\n`); }); - test('does not apply styles in non-TTY mode', async () => { - const host = new CliIoHost({ useTTY: false }); - await host.notify({ - time: new Date(), - level: 'info', - action: 'synth', - code: 'TEST', - message: 'unstyled message', + test('applies no styling when TTY is false', async () => { + CliIoHost.isTTY = false; + await CliIoHost.getIoHost().notify({ + ...defaultMessage, forceStdout: true, }); - expect(mockStdout).toHaveBeenCalledWith('unstyled message\n'); + expect(mockStdout).toHaveBeenCalledWith('test message\n'); }); - }); - describe('timestamp handling', () => { - test('includes timestamp for DEBUG level with gray color', async () => { - const host = new CliIoHost({ useTTY: true }); - const testDate = new Date('2024-01-01T12:34:56'); + test('applies correct color styles for different message levels', async () => { + const testCases = [ + { level: 'error' as const, style: chalk.red }, + { level: 'warn' as const, style: chalk.yellow }, + { level: 'info' as const, style: chalk.white }, + { level: 'debug' as const, style: chalk.gray }, + { level: 'trace' as const, style: chalk.gray }, + ]; - await host.notify({ - time: testDate, - level: 'debug', - action: 'synth', - code: 'TEST', - message: 'debug message', - forceStdout: true, - }); - - expect(mockStdout).toHaveBeenCalledWith(`[12:34:56] ${chalk.gray('debug message')}\n`); - }); - - test('includes timestamp for TRACE level with gray color', async () => { - const host = new CliIoHost({ useTTY: true }); - const testDate = new Date('2024-01-01T12:34:56'); + for (const { level, style } of testCases) { + await CliIoHost.getIoHost().notify({ + ...defaultMessage, + level, + forceStdout: true, + }); - await host.notify({ - time: testDate, - level: 'trace', - action: 'synth', - code: 'TEST', - message: 'trace message', - forceStdout: true, - }); + const expectedOutput = level === 'debug' || level === 'trace' + ? `[12:00:00] ${style('test message')}\n` + : `${style('test message')}\n`; - expect(mockStdout).toHaveBeenCalledWith(`[12:34:56] ${chalk.gray('trace message')}\n`); + expect(mockStdout).toHaveBeenCalledWith(expectedOutput); + mockStdout.mockClear(); + } }); + }); - test('excludes timestamp for other levels but includes color', async () => { - const host = new CliIoHost({ useTTY: true }); - const testDate = new Date('2024-01-01T12:34:56'); - - await host.notify({ - time: testDate, - level: 'info', - action: 'synth', - code: 'TEST', - message: 'info message', - forceStdout: true, - }); - - expect(mockStdout).toHaveBeenCalledWith(chalk.white('info message') + '\n'); + describe('action handling', () => { + test('sets and gets current action', () => { + CliIoHost.currentAction = 'deploy'; + expect(CliIoHost.currentAction).toBe('deploy'); }); }); describe('CI mode behavior', () => { - test('writes to stdout in CI mode when level is not error', async () => { - const host = new CliIoHost({ useTTY: true, ci: true }); - await host.notify({ - time: new Date(), - level: 'info', - action: 'synth', - code: 'TEST', - message: 'ci message', - }); - - expect(mockStdout).toHaveBeenCalledWith(chalk.white('ci message') + '\n'); - expect(mockStderr).not.toHaveBeenCalled(); + beforeEach(() => { + CliIoHost.isTTY = true; + CliIoHost.ci = true; }); - test('writes to stdout in CI mode with forceStdout', async () => { - const host = new CliIoHost({ useTTY: true, ci: true }); - await host.notify({ + test('writes to stdout in CI mode when level is not error', async () => { + await CliIoHost.getIoHost().notify({ time: new Date(), level: 'info', action: 'synth', - code: 'TEST', + code: 'CDK_TOOLKIT_W0001', message: 'ci message', - forceStdout: true, }); expect(mockStdout).toHaveBeenCalledWith(chalk.white('ci message') + '\n'); @@ -219,114 +175,50 @@ describe('CliIoHost', () => { }); test('writes to stderr for error level in CI mode', async () => { - const host = new CliIoHost({ useTTY: true, ci: true }); - await host.notify({ + await CliIoHost.getIoHost().notify({ time: new Date(), level: 'error', action: 'synth', - code: 'TEST', + code: 'CDK_TOOLKIT_E0001', message: 'ci error message', }); expect(mockStderr).toHaveBeenCalledWith(chalk.red('ci error message') + '\n'); expect(mockStdout).not.toHaveBeenCalled(); }); - - test('writes to stdout for error level in CI mode with forceStdOut', async () => { - const host = new CliIoHost({ useTTY: true, ci: true }); - await host.notify({ - time: new Date(), - level: 'error', - action: 'synth', - code: 'TEST', - message: 'ci error message', - forceStdout: true, - }); - - expect(mockStdout).toHaveBeenCalledWith(chalk.red('ci error message') + '\n'); - expect(mockStderr).not.toHaveBeenCalled(); - }); }); - describe('special characters handling', () => { - test('handles messages with ANSI escape sequences', async () => { - const host = new CliIoHost({ useTTY: true }); - await host.notify({ - time: new Date(), - level: 'info', - action: 'synth', - code: 'TEST', - message: '\u001b[31mred text\u001b[0m', - forceStdout: true, - }); - - expect(mockStdout).toHaveBeenCalledWith(chalk.white('\u001b[31mred text\u001b[0m') + '\n'); + describe('timestamp handling', () => { + beforeEach(() => { + CliIoHost.isTTY = true; }); - test('handles messages with newlines', async () => { - const host = new CliIoHost({ useTTY: true }); - await host.notify({ - time: new Date(), - level: 'info', + test('includes timestamp for DEBUG level with gray color', async () => { + const testDate = new Date('2024-01-01T12:34:56'); + await CliIoHost.getIoHost().notify({ + time: testDate, + level: 'debug', action: 'synth', - code: 'TEST', - message: 'line1\nline2\nline3', + code: 'CDK_TOOLKIT_I0001', + message: 'debug message', forceStdout: true, }); - expect(mockStdout).toHaveBeenCalledWith(chalk.white('line1\nline2\nline3') + '\n'); + expect(mockStdout).toHaveBeenCalledWith(`[12:34:56] ${chalk.gray('debug message')}\n`); }); - test('handles empty messages', async () => { - const host = new CliIoHost({ useTTY: true }); - await host.notify({ - time: new Date(), + test('excludes timestamp for other levels but includes color', async () => { + const testDate = new Date('2024-01-01T12:34:56'); + await CliIoHost.getIoHost().notify({ + time: testDate, level: 'info', action: 'synth', - code: 'TEST', - message: '', + code: 'CDK_TOOLKIT_I0001', + message: 'info message', forceStdout: true, }); - expect(mockStdout).toHaveBeenCalledWith(chalk.white('') + '\n'); - }); - }); - - describe('action and code behavior', () => { - test('handles all possible actions', async () => { - const host = new CliIoHost({ useTTY: true }); - const actions: IoAction[] = ['synth', 'list', 'deploy', 'destroy']; - - for (const action of actions) { - await host.notify({ - time: new Date(), - level: 'info', - action, - code: 'TEST', - message: `${action} message`, - forceStdout: true, - }); - - expect(mockStdout).toHaveBeenCalledWith(chalk.white(`${action} message`) + '\n'); - } - }); - - test('handles various code values', async () => { - const host = new CliIoHost({ useTTY: true }); - const testCases = ['ERROR_1', 'SUCCESS', 'WARN_XYZ', '123']; - - for (const code of testCases) { - await host.notify({ - time: new Date(), - level: 'info', - action: 'synth', - code, - message: `message with code ${code}`, - forceStdout: true, - }); - - expect(mockStdout).toHaveBeenCalledWith(chalk.white(`message with code ${code}`) + '\n'); - } + expect(mockStdout).toHaveBeenCalledWith(chalk.white('info message') + '\n'); }); }); @@ -337,12 +229,11 @@ describe('CliIoHost', () => { return true; }); - const host = new CliIoHost({ useTTY: true }); - await expect(host.notify({ + await expect(CliIoHost.getIoHost().notify({ time: new Date(), level: 'info', action: 'synth', - code: 'TEST', + code: 'CDK_TOOLKIT_I0001', message: 'test message', forceStdout: true, })).rejects.toThrow('Write failed'); diff --git a/packages/aws-cdk/test/util/silent.ts b/packages/aws-cdk/test/util/silent.ts index 127afde3d32b7..dff91132a7390 100644 --- a/packages/aws-cdk/test/util/silent.ts +++ b/packages/aws-cdk/test/util/silent.ts @@ -2,7 +2,7 @@ import * as logging from '../../lib/logging'; export function silentTest(name: string, callback: () => void | Promise, timeout?: number): void { - const spy = jest.spyOn(logging, 'print'); + const spy = jest.spyOn(logging, 'info'); if (process.env.CLI_TEST_VERBOSE) { spy.mockRestore(); } diff --git a/packages/aws-cdk/test/version.test.ts b/packages/aws-cdk/test/version.test.ts index 784c7d8dc0bf6..c0242d779ef48 100644 --- a/packages/aws-cdk/test/version.test.ts +++ b/packages/aws-cdk/test/version.test.ts @@ -86,7 +86,7 @@ test('No Version specified for storage in the TTL file', async () => { test('Skip version check if environment variable is set', async () => { sinon.stub(process, 'stdout').value({ ...process.stdout, isTTY: true }); sinon.stub(process, 'env').value({ ...process.env, CDK_DISABLE_VERSION_CHECK: '1' }); - const printStub = sinon.stub(logging, 'print'); + const printStub = sinon.stub(logging, 'info'); await displayVersionMessage(); expect(printStub.called).toEqual(false); }); @@ -105,7 +105,7 @@ describe('version message', () => { // Given the current version is 1.0.0 and the latest version is 1.1.0 const currentVersion = '1.0.0'; jest.spyOn(npm, 'getLatestVersionFromNpm').mockResolvedValue('1.1.0'); - const printSpy = jest.spyOn(logging, 'print'); + const printSpy = jest.spyOn(logging, 'info'); // When displayVersionMessage is called await displayVersionMessage(currentVersion, new VersionCheckTTL(tmpfile(), 0)); @@ -118,7 +118,7 @@ describe('version message', () => { // Given the current version is 1.0.0 and the latest version is 2.0.0 const currentVersion = '1.0.0'; jest.spyOn(npm, 'getLatestVersionFromNpm').mockResolvedValue('2.0.0'); - const printSpy = jest.spyOn(logging, 'print'); + const printSpy = jest.spyOn(logging, 'info'); // When displayVersionMessage is called await displayVersionMessage(currentVersion, new VersionCheckTTL(tmpfile(), 0)); @@ -131,7 +131,7 @@ describe('version message', () => { // Given current version is 99.0.0 and the latest version is 100.0.0 const currentVersion = '99.0.0'; jest.spyOn(npm, 'getLatestVersionFromNpm').mockResolvedValue('100.0.0'); - const printSpy = jest.spyOn(logging, 'print'); + const printSpy = jest.spyOn(logging, 'info'); // When displayVersionMessage is called await displayVersionMessage(currentVersion, new VersionCheckTTL(tmpfile(), 0));