From a0fcbbdba86d9d7bf6254f6c926c08c2878b1e27 Mon Sep 17 00:00:00 2001 From: Momo Kornher Date: Fri, 21 Feb 2025 19:56:26 +0000 Subject: [PATCH] refactor(cli): stack monitor uses io-host --- .../@aws-cdk/toolkit-lib/CODE_REGISTRY.md | 4 + .../toolkit-lib/lib/actions/deploy/index.ts | 8 +- .../@aws-cdk/toolkit-lib/lib/api/aws-cdk.ts | 1 - .../toolkit-lib/lib/api/io/private/codes.ts | 23 + .../toolkit-lib/lib/toolkit/toolkit.ts | 8 +- .../lib/api/deployments/deploy-stack.ts | 61 +- .../lib/api/deployments/deployments.ts | 54 +- .../lib/api/resource-import/importer.ts | 9 - .../lib/api/resource-import/migrator.ts | 1 - .../stack-events/stack-activity-monitor.ts | 768 ++++-------------- .../api/stack-events/stack-event-poller.ts | 7 + .../stack-events/stack-progress-monitor.ts | 129 +++ .../aws-cdk/lib/cli/activity-printer/base.ts | 194 +++++ .../lib/cli/activity-printer/current.ts | 170 ++++ .../activity-printer}/display.ts | 0 .../lib/cli/activity-printer/history.ts | 145 ++++ .../aws-cdk/lib/cli/activity-printer/index.ts | 3 + packages/aws-cdk/lib/cli/cdk-toolkit.ts | 16 +- packages/aws-cdk/lib/cli/cli-config.ts | 2 +- packages/aws-cdk/lib/cli/cli.ts | 1 + packages/aws-cdk/lib/commands/deploy.ts | 14 + packages/aws-cdk/lib/legacy-exports-source.ts | 2 +- packages/aws-cdk/lib/toolkit/cli-io-host.ts | 94 +++ packages/aws-cdk/lib/util/cloudformation.ts | 26 + .../aws-cdk/lib/util/string-manipulation.ts | 12 +- .../api/stack-events/progress-monitor.test.ts | 89 ++ .../stack-activity-monitor.test.ts | 520 ++++++------ .../api/stack-events/stack-monitor.test.ts | 271 ------ .../{api => cli}/_helpers/console-listener.ts | 10 + .../activity-monitor}/display.test.ts | 2 +- .../test/cli/activity-monitor/history.test.ts | 166 ++++ 31 files changed, 1530 insertions(+), 1280 deletions(-) create mode 100644 packages/aws-cdk/lib/api/stack-events/stack-progress-monitor.ts create mode 100644 packages/aws-cdk/lib/cli/activity-printer/base.ts create mode 100644 packages/aws-cdk/lib/cli/activity-printer/current.ts rename packages/aws-cdk/lib/{api/stack-events => cli/activity-printer}/display.ts (100%) create mode 100644 packages/aws-cdk/lib/cli/activity-printer/history.ts create mode 100644 packages/aws-cdk/lib/cli/activity-printer/index.ts create mode 100644 packages/aws-cdk/lib/commands/deploy.ts create mode 100644 packages/aws-cdk/test/api/stack-events/progress-monitor.test.ts delete mode 100644 packages/aws-cdk/test/api/stack-events/stack-monitor.test.ts rename packages/aws-cdk/test/{api => cli}/_helpers/console-listener.ts (86%) rename packages/aws-cdk/test/{api/stack-events => cli/activity-monitor}/display.test.ts (96%) create mode 100644 packages/aws-cdk/test/cli/activity-monitor/history.test.ts diff --git a/packages/@aws-cdk/toolkit-lib/CODE_REGISTRY.md b/packages/@aws-cdk/toolkit-lib/CODE_REGISTRY.md index 220144b0..c188e45b 100644 --- a/packages/@aws-cdk/toolkit-lib/CODE_REGISTRY.md +++ b/packages/@aws-cdk/toolkit-lib/CODE_REGISTRY.md @@ -13,8 +13,12 @@ | CDK_TOOLKIT_I5031 | Informs about any log groups that are traced as part of the deployment | info | n/a | | CDK_TOOLKIT_I5050 | Confirm rollback during deployment | info | n/a | | CDK_TOOLKIT_I5060 | Confirm deploy security sensitive changes | info | n/a | +| CDK_TOOLKIT_I5501 | Stack Monitoring Start | debug | n/a | +| CDK_TOOLKIT_I5502 | Stack Monitoring Activity event | info | [StackActivity](https://docs.aws.amazon.com/cdk/api/toolkit-lib/interfaces/StackActivity.html) | +| CDK_TOOLKIT_I5503 | Stack Monitoring End | debug | n/a | | CDK_TOOLKIT_I5900 | Deployment results on success | result | [SuccessfulDeployStackResult](https://docs.aws.amazon.com/cdk/api/toolkit-lib/interfaces/SuccessfulDeployStackResult.html) | | CDK_TOOLKIT_E5001 | No stacks found | error | n/a | +| CDK_TOOLKIT_E5500 | Stack Monitoring error | error | n/a | | CDK_TOOLKIT_I6000 | Provides rollback times | info | n/a | | CDK_TOOLKIT_E6001 | No stacks found | error | n/a | | CDK_TOOLKIT_E6900 | Rollback failed | error | n/a | diff --git a/packages/@aws-cdk/toolkit-lib/lib/actions/deploy/index.ts b/packages/@aws-cdk/toolkit-lib/lib/actions/deploy/index.ts index be8b0511..d129838a 100644 --- a/packages/@aws-cdk/toolkit-lib/lib/actions/deploy/index.ts +++ b/packages/@aws-cdk/toolkit-lib/lib/actions/deploy/index.ts @@ -1,5 +1,5 @@ import type { BaseDeployOptions } from './private/deploy-options'; -import type { StackActivityProgress, Tag } from '../../api/aws-cdk'; +import type { Tag } from '../../api/aws-cdk'; export type DeploymentMethod = DirectDeploymentMethod | ChangeSetDeploymentMethod; @@ -164,16 +164,16 @@ export interface DeployOptions extends BaseDeployOptions { /** * Change stack watcher output to CI mode. * - * @deprecated Implement in IoHost instead + * @deprecated has no functionality, please implement in your IoHost */ readonly ci?: boolean; /** * Display mode for stack deployment progress. * - * @deprecated Implement in IoHost instead + * @deprecated has no functionality, please implement in your IoHost */ - readonly progress?: StackActivityProgress; + readonly progress?: any; /** * Represents configuration property overrides for hotswap deployments. diff --git a/packages/@aws-cdk/toolkit-lib/lib/api/aws-cdk.ts b/packages/@aws-cdk/toolkit-lib/lib/api/aws-cdk.ts index a6e85dd3..8171d85a 100644 --- a/packages/@aws-cdk/toolkit-lib/lib/api/aws-cdk.ts +++ b/packages/@aws-cdk/toolkit-lib/lib/api/aws-cdk.ts @@ -8,7 +8,6 @@ export { Settings } from '../../../../aws-cdk/lib/api/settings'; export { tagsForStack, Tag } from '../../../../aws-cdk/lib/api/tags'; export { DEFAULT_TOOLKIT_STACK_NAME } from '../../../../aws-cdk/lib/api/toolkit-info'; export { ResourceMigrator } from '../../../../aws-cdk/lib/api/resource-import'; -export { StackActivityProgress } from '../../../../aws-cdk/lib/api/stack-events'; export { CloudWatchLogEventMonitor, findCloudWatchLogGroups } from '../../../../aws-cdk/lib/api/logs'; export { type WorkGraph, WorkGraphBuilder, AssetBuildNode, AssetPublishNode, StackNode, Concurrency } from '../../../../aws-cdk/lib/api/work-graph'; diff --git a/packages/@aws-cdk/toolkit-lib/lib/api/io/private/codes.ts b/packages/@aws-cdk/toolkit-lib/lib/api/io/private/codes.ts index 3c35848f..06c2ea02 100644 --- a/packages/@aws-cdk/toolkit-lib/lib/api/io/private/codes.ts +++ b/packages/@aws-cdk/toolkit-lib/lib/api/io/private/codes.ts @@ -109,6 +109,24 @@ export const CODES = { description: 'Confirm deploy security sensitive changes', level: 'info', }), + + CDK_TOOLKIT_I5501: codeInfo({ + code: 'CDK_TOOLKIT_I5501', + description: 'Stack Monitoring Start', + level: 'debug', + }), + CDK_TOOLKIT_I5502: codeInfo({ + code: 'CDK_TOOLKIT_I5502', + description: 'Stack Monitoring Activity event', + level: 'info', + interface: 'StackActivity', + }), + CDK_TOOLKIT_I5503: codeInfo({ + code: 'CDK_TOOLKIT_I5503', + description: 'Stack Monitoring End', + level: 'debug', + }), + CDK_TOOLKIT_I5900: codeInfo({ code: 'CDK_TOOLKIT_I5900', description: 'Deployment results on success', @@ -121,6 +139,11 @@ export const CODES = { description: 'No stacks found', level: 'error', }), + CDK_TOOLKIT_E5500: codeInfo({ + code: 'CDK_TOOLKIT_E5500', + description: 'Stack Monitoring error', + level: 'error', + }), // 6: Rollback CDK_TOOLKIT_I6000: codeInfo({ diff --git a/packages/@aws-cdk/toolkit-lib/lib/toolkit/toolkit.ts b/packages/@aws-cdk/toolkit-lib/lib/toolkit/toolkit.ts index d314eb70..6c23b904 100644 --- a/packages/@aws-cdk/toolkit-lib/lib/toolkit/toolkit.ts +++ b/packages/@aws-cdk/toolkit-lib/lib/toolkit/toolkit.ts @@ -15,7 +15,7 @@ import { type SynthOptions } from '../actions/synth'; import { WatchOptions } from '../actions/watch'; import { patternsArrayForWatch } from '../actions/watch/private'; import { type SdkConfig } from '../api/aws-auth'; -import { DEFAULT_TOOLKIT_STACK_NAME, SdkProvider, SuccessfulDeployStackResult, StackCollection, Deployments, HotswapMode, StackActivityProgress, ResourceMigrator, obscureTemplate, serializeStructure, tagsForStack, CliIoHost, validateSnsTopicArn, Concurrency, WorkGraphBuilder, AssetBuildNode, AssetPublishNode, StackNode, formatErrorMessage, CloudWatchLogEventMonitor, findCloudWatchLogGroups, formatTime, StackDetails } from '../api/aws-cdk'; +import { DEFAULT_TOOLKIT_STACK_NAME, SdkProvider, SuccessfulDeployStackResult, StackCollection, Deployments, HotswapMode, ResourceMigrator, obscureTemplate, serializeStructure, tagsForStack, CliIoHost, validateSnsTopicArn, Concurrency, WorkGraphBuilder, AssetBuildNode, AssetPublishNode, StackNode, formatErrorMessage, CloudWatchLogEventMonitor, findCloudWatchLogGroups, formatTime, StackDetails } from '../api/aws-cdk'; import { ICloudAssemblySource, StackSelectionStrategy } from '../api/cloud-assembly'; import { ALL_STACKS, CachedCloudAssemblySource, CloudAssemblySourceBuilder, IdentityCloudAssemblySource, StackAssembly } from '../api/cloud-assembly/private'; import { ToolkitError } from '../api/errors'; @@ -375,8 +375,6 @@ export class Toolkit extends CloudAssemblySourceBuilder implements AsyncDisposab force: options.force, parameters: Object.assign({}, parameterMap['*'], parameterMap[stack.stackName]), usePreviousParameters: options.parameters?.keepExistingParameters, - progress, - ci: options.ci, rollback, hotswap: hotswapMode, extraUserAgent: options.extraUserAgent, @@ -494,10 +492,6 @@ export class Toolkit extends CloudAssemblySourceBuilder implements AsyncDisposab const assetBuildTime = options.assetBuildTime ?? AssetBuildTime.ALL_BEFORE_DEPLOY; const prebuildAssets = assetBuildTime === AssetBuildTime.ALL_BEFORE_DEPLOY; const concurrency = options.concurrency || 1; - const progress = concurrency > 1 ? StackActivityProgress.EVENTS : options.progress; - if (concurrency > 1 && options.progress && options.progress != StackActivityProgress.EVENTS) { - await ioHost.notify(warn('⚠️ The --concurrency flag only supports --progress "events". Switching to "events".')); - } const stacksAndTheirAssetManifests = stacks.flatMap((stack) => [ stack, diff --git a/packages/aws-cdk/lib/api/deployments/deploy-stack.ts b/packages/aws-cdk/lib/api/deployments/deploy-stack.ts index 2d7e81a1..c8b5354a 100644 --- a/packages/aws-cdk/lib/api/deployments/deploy-stack.ts +++ b/packages/aws-cdk/lib/api/deployments/deploy-stack.ts @@ -36,7 +36,7 @@ import type { SDK, SdkProvider, ICloudFormationClient } from '../aws-auth'; import type { EnvironmentResources } from '../environment'; import { CfnEvaluationException } from '../evaluate-cloudformation-template'; import { HotswapMode, HotswapPropertyOverrides, ICON } from '../hotswap/common'; -import { StackActivityMonitor, type StackActivityProgress } from '../stack-events'; +import { StackActivityMonitor } from '../stack-events'; import { StringWithoutPlaceholders } from '../util/placeholders'; import { type TemplateBodyParameter, makeBodyParameter } from '../util/template-body-parameter'; @@ -105,13 +105,6 @@ export interface DeployStackOptions { */ readonly deployName?: string; - /** - * Quiet or verbose deployment - * - * @default false - */ - readonly quiet?: boolean; - /** * List of asset IDs which shouldn't be built * @@ -153,27 +146,12 @@ export interface DeployStackOptions { */ readonly usePreviousParameters?: boolean; - /** - * Display mode for stack deployment progress. - * - * @default StackActivityProgress.Bar stack events will be displayed for - * the resource currently being deployed. - */ - readonly progress?: StackActivityProgress; - /** * Deploy even if the deployed template is identical to the one we are about to deploy. * @default false */ readonly force?: boolean; - /** - * Whether we are on a CI system - * - * @default false - */ - readonly ci?: boolean; - /** * Rollback failed deployments * @@ -612,14 +590,16 @@ class FullCloudFormationDeployment { } private async monitorDeployment(startTime: Date, expectedChanges: number | undefined): Promise { - const monitor = this.options.quiet - ? undefined - : StackActivityMonitor.withDefaultPrinter(this.cfn, this.stackName, this.stackArtifact, { - resourcesTotal: expectedChanges, - progress: this.options.progress, - changeSetCreationTime: startTime, - ci: this.options.ci, - }).start(); + const monitor = new StackActivityMonitor({ + cfn: this.cfn, + stack: this.stackArtifact, + stackName: this.stackName, + resourcesTotal: expectedChanges, + ioHost: this.ioHost, + action: this.action, + changeSetCreationTime: startTime, + }); + await monitor.start(); let finalState = this.cloudFormationStack; try { @@ -631,9 +611,9 @@ class FullCloudFormationDeployment { } finalState = successStack; } catch (e: any) { - throw new ToolkitError(suffixWithErrors(formatErrorMessage(e), monitor?.errors)); + throw new ToolkitError(suffixWithErrors(formatErrorMessage(e), monitor.errors)); } finally { - await monitor?.stop(); + await monitor.stop(); } debug(this.action, format('Stack %s has completed updating', this.stackName)); return { @@ -696,11 +676,14 @@ export async function destroyStack(options: DestroyStackOptions, { ioHost, actio if (!currentStack.exists) { return; } - const monitor = options.quiet - ? undefined - : StackActivityMonitor.withDefaultPrinter(cfn, deployName, options.stack, { - ci: options.ci, - }).start(); + const monitor = new StackActivityMonitor({ + cfn, + stack: options.stack, + stackName: deployName, + ioHost, + action, + }); + await monitor.start(); try { await cfn.deleteStack({ StackName: deployName, RoleARN: options.roleArn }); @@ -709,7 +692,7 @@ export async function destroyStack(options: DestroyStackOptions, { ioHost, actio throw new ToolkitError(`Failed to destroy ${deployName}: ${destroyedStack.stackStatus}`); } } catch (e: any) { - throw new ToolkitError(suffixWithErrors(formatErrorMessage(e), monitor?.errors)); + throw new ToolkitError(suffixWithErrors(formatErrorMessage(e), monitor.errors)); } finally { if (monitor) { await monitor.stop(); diff --git a/packages/aws-cdk/lib/api/deployments/deployments.ts b/packages/aws-cdk/lib/api/deployments/deployments.ts index a9cc3b00..6bd75b79 100644 --- a/packages/aws-cdk/lib/api/deployments/deployments.ts +++ b/packages/aws-cdk/lib/api/deployments/deployments.ts @@ -31,7 +31,7 @@ import { formatErrorMessage } from '../../util/format-error'; import type { SdkProvider } from '../aws-auth/sdk-provider'; import { type EnvironmentResources, EnvironmentAccess } from '../environment'; import { HotswapMode, HotswapPropertyOverrides } from '../hotswap/common'; -import { StackActivityMonitor, StackActivityProgress, StackEventPoller, RollbackChoice } from '../stack-events'; +import { StackActivityMonitor, StackEventPoller, RollbackChoice } from '../stack-events'; import type { Tag } from '../tags'; import { DEFAULT_TOOLKIT_STACK_NAME } from '../toolkit-info'; import { makeBodyParameter } from '../util/template-body-parameter'; @@ -65,13 +65,6 @@ export interface DeployStackOptions { */ readonly deployName?: string; - /** - * Don't show stack deployment events, just wait - * - * @default false - */ - readonly quiet?: boolean; - /** * Name of the toolkit stack, if not the default name * @@ -135,21 +128,6 @@ export interface DeployStackOptions { */ readonly usePreviousParameters?: boolean; - /** - * Display mode for stack deployment progress. - * - * @default - StackActivityProgress.Bar - stack events will be displayed for - * the resource currently being deployed. - */ - readonly progress?: StackActivityProgress; - - /** - * Whether we are on a CI system - * - * @default false - */ - readonly ci?: boolean; - /** * Rollback failed deployments * @@ -255,14 +233,6 @@ export interface RollbackStackOptions { */ readonly orphanLogicalIds?: string[]; - /** - * Display mode for stack deployment progress. - * - * @default - StackActivityProgress.Bar - stack events will be displayed for - * the resource currently being deployed. - */ - readonly progress?: StackActivityProgress; - /** * Whether to validate the version of the bootstrap stack permissions * @@ -463,7 +433,6 @@ export class Deployments { resolvedEnvironment: env.resolvedEnvironment, deployName: options.deployName, notificationArns: options.notificationArns, - quiet: options.quiet, sdk: env.sdk, sdkProvider: this.deployStackSdkProvider, roleArn: executionRoleArn, @@ -474,8 +443,6 @@ export class Deployments { force: options.force, parameters: options.parameters, usePreviousParameters: options.usePreviousParameters, - progress: options.progress, - ci: options.ci, rollback: options.rollback, hotswap: options.hotswap, hotswapPropertyOverrides: options.hotswapPropertyOverrides, @@ -565,11 +532,14 @@ export class Deployments { throw new ToolkitError(`Unexpected rollback choice: ${cloudFormationStack.stackStatus.rollbackChoice}`); } - const monitor = options.quiet - ? undefined - : StackActivityMonitor.withDefaultPrinter(cfn, deployName, options.stack, { - ci: options.ci, - }).start(); + const monitor = new StackActivityMonitor({ + cfn, + stack: options.stack, + stackName: deployName, + ioHost: this.ioHost, + action: this.action, + }); + await monitor.start(); let stackErrorMessage: string | undefined = undefined; let finalStackState = cloudFormationStack; @@ -582,14 +552,14 @@ export class Deployments { } finalStackState = successStack; - const errors = monitor?.errors?.join(', '); + const errors = monitor.errors.join(', '); if (errors) { stackErrorMessage = errors; } } catch (e: any) { - stackErrorMessage = suffixWithErrors(formatErrorMessage(e), monitor?.errors); + stackErrorMessage = suffixWithErrors(formatErrorMessage(e), monitor.errors); } finally { - await monitor?.stop(); + await monitor.stop(); } if (finalStackState.stackStatus.isRollbackSuccess || !stackErrorMessage) { diff --git a/packages/aws-cdk/lib/api/resource-import/importer.ts b/packages/aws-cdk/lib/api/resource-import/importer.ts index 89411331..044d0549 100644 --- a/packages/aws-cdk/lib/api/resource-import/importer.ts +++ b/packages/aws-cdk/lib/api/resource-import/importer.ts @@ -9,7 +9,6 @@ import { error, info, warn } from '../../cli/messages'; import { IIoHost, ToolkitAction } from '../../toolkit/cli-io-host'; import { ToolkitError } from '../../toolkit/error'; import { assertIsSuccessfulDeployStackResult, type Deployments, DeploymentMethod, ResourceIdentifierProperties, ResourcesToImport } from '../deployments'; -import type { StackActivityProgress } from '../stack-events'; import type { Tag } from '../tags'; export interface ResourceImporterProps { @@ -49,14 +48,6 @@ export interface ImportDeploymentOptions { */ readonly usePreviousParameters?: boolean; - /** - * Display mode for stack deployment progress. - * - * @default - StackActivityProgress.Bar - stack events will be displayed for - * the resource currently being deployed. - */ - readonly progress?: StackActivityProgress; - /** * Rollback failed deployments * diff --git a/packages/aws-cdk/lib/api/resource-import/migrator.ts b/packages/aws-cdk/lib/api/resource-import/migrator.ts index e0f2e421..0180fd6f 100644 --- a/packages/aws-cdk/lib/api/resource-import/migrator.ts +++ b/packages/aws-cdk/lib/api/resource-import/migrator.ts @@ -67,7 +67,6 @@ export class ResourceMigrator { roleArn: options.roleArn, deploymentMethod: options.deploymentMethod, usePreviousParameters: true, - progress: options.progress, rollback: options.rollback, }); diff --git a/packages/aws-cdk/lib/api/stack-events/stack-activity-monitor.ts b/packages/aws-cdk/lib/api/stack-events/stack-activity-monitor.ts index 962b505d..327e3f72 100644 --- a/packages/aws-cdk/lib/api/stack-events/stack-activity-monitor.ts +++ b/packages/aws-cdk/lib/api/stack-events/stack-activity-monitor.ts @@ -1,15 +1,38 @@ + import * as util from 'util'; import { ArtifactMetadataEntryType, type MetadataEntry } from '@aws-cdk/cloud-assembly-schema'; import type { CloudFormationStackArtifact } from '@aws-cdk/cx-api'; -import * as chalk from 'chalk'; -import { ResourceEvent, StackEventPoller } from './stack-event-poller'; -import { error, info } from '../../logging'; -import { CliIoHost, IoMessageLevel } from '../../toolkit/cli-io-host'; +import { StackEvent } from '@aws-sdk/client-cloudformation'; +import * as uuid from 'uuid'; +import { StackEventPoller } from './stack-event-poller'; +import { debug, error, info } from '../../cli/messages'; +import { IoMessaging } from '../../toolkit/cli-io-host'; +import { stackEventHasErrorMessage } from '../../util'; import type { ICloudFormationClient } from '../aws-auth'; -import { RewritableBlock } from './display'; +import { StackProgress, StackProgressMonitor } from './stack-progress-monitor'; + +export interface StackActivity { + /** + * A unique identifier for a specific stack deployment. + * + * Use this value to attribute stack activities received for concurrent deployments. + */ + readonly deployment: string; + + /** + * The Stack Event as received from CloudFormation + */ + readonly event: StackEvent; -export interface StackActivity extends ResourceEvent { + /** + * Additional resource metadata + */ readonly metadata?: ResourceMetadata; + + /** + * The stack progress + */ + readonly progress: StackProgress; } export interface ResourceMetadata { @@ -17,58 +40,40 @@ export interface ResourceMetadata { constructPath: string; } -/** - * Supported display modes for stack deployment activity - */ -export enum StackActivityProgress { +export interface StackActivityMonitorProps { /** - * Displays a progress bar with only the events for the resource currently being deployed + * The CloudFormation client */ - BAR = 'bar', + readonly cfn: ICloudFormationClient; /** - * Displays complete history with all CloudFormation stack events + * The IoHost used for messaging */ - EVENTS = 'events', -} + readonly ioHost: IoMessaging['ioHost']; -export interface WithDefaultPrinterProps { /** - * Total number of resources to update - * - * Used to calculate a progress bar. - * - * @default - No progress reporting. + * The current ToolkitAction */ - readonly resourcesTotal?: number; + readonly action: IoMessaging['action']; /** - * The log level that was requested in the CLI - * - * If verbose or trace is requested, we'll always use the full history printer. - * - * @default - Use value from logging.logLevel + * The stack artifact that is deployed */ - readonly logLevel?: IoMessageLevel; + readonly stack: CloudFormationStackArtifact; /** - * Whether to display all stack events or to display only the events for the - * resource currently being deployed - * - * If not set, the stack history with all stack events will be displayed - * - * @default false + * The name of the Stack */ - progress?: StackActivityProgress; + readonly stackName: string; /** - * Whether we are on a CI system + * Total number of resources to update * - * If so, disable the "optimized" stack monitor. + * Used to calculate a progress bar. * - * @default false + * @default - No progress reporting. */ - readonly ci?: boolean; + readonly resourcesTotal?: number; /** * Creation time of the change set @@ -82,50 +87,32 @@ export interface WithDefaultPrinterProps { * @default - local machine's current time */ readonly changeSetCreationTime?: Date; + + /** + * Time to wait between fetching new activities. + * + * @default 1_000 + */ + readonly pollingInterval?: number; } export class StackActivityMonitor { /** - * Create a Stack Activity Monitor using a default printer, based on context clues + * The poller used to read stack events */ - public static withDefaultPrinter( - cfn: ICloudFormationClient, - stackName: string, - stackArtifact: CloudFormationStackArtifact, - options: WithDefaultPrinterProps = {}, - ) { - const stream = options.ci ? process.stdout : process.stderr; - - const props: PrinterProps = { - resourceTypeColumnWidth: calcMaxResourceTypeLength(stackArtifact.template), - resourcesTotal: options.resourcesTotal, - stream, - }; - - const isWindows = process.platform === 'win32'; - 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 - const fancyOutputAvailable = !isWindows && stream.isTTY && !options.ci; - const progress = options.progress ?? StackActivityProgress.BAR; - - const printer = - fancyOutputAvailable && !verbose && progress === StackActivityProgress.BAR - ? new CurrentActivityPrinter(props) - : new HistoryActivityPrinter(props); - - return new StackActivityMonitor(cfn, stackName, printer, stackArtifact, options.changeSetCreationTime); - } + private readonly poller: StackEventPoller; /** - * The poller used to read stack events + * Fetch new activity every 1 second + * Printers can decide to update a view less frequently if desired */ - public readonly poller: StackEventPoller; + private readonly pollingInterval: number; public readonly errors: string[] = []; - private active = false; + private monitorId?: string; + + private readonly progressMonitor: StackProgressMonitor; /** * Current tick timer @@ -137,28 +124,48 @@ export class StackActivityMonitor { */ private readPromise?: Promise; - constructor( - cfn: ICloudFormationClient, - private readonly stackName: string, - private readonly printer: IActivityPrinter, - private readonly stack?: CloudFormationStackArtifact, - changeSetCreationTime?: Date, - ) { + private readonly ioHost: IoMessaging['ioHost']; + private readonly action: IoMessaging['action']; + private readonly stackName: string; + private readonly stack: CloudFormationStackArtifact; + + constructor({ + cfn, + ioHost, + action, + stack, + stackName, + resourcesTotal, + changeSetCreationTime, + pollingInterval = 1000, + }: StackActivityMonitorProps) { + this.ioHost = ioHost; + this.action = action; + this.stack = stack; + this.stackName = stackName; + + this.progressMonitor = new StackProgressMonitor(resourcesTotal); + this.pollingInterval = pollingInterval; this.poller = new StackEventPoller(cfn, { stackName, startTime: changeSetCreationTime?.getTime() ?? Date.now(), }); } - public start() { - this.active = true; - this.printer.start(); + public async start() { + this.monitorId = uuid.v4(); + await this.ioHost.notify(debug(this.action, `Deploying ${this.stackName}`, 'CDK_TOOLKIT_I5501', { + deployment: this.monitorId, + stack: this.stack, + stackName: this.stackName, + })); this.scheduleNextTick(); return this; } public async stop() { - this.active = false; + const oldMonitorId = this.monitorId!; + this.monitorId = undefined; if (this.tickTimer) { clearTimeout(this.tickTimer); } @@ -166,43 +173,51 @@ export class StackActivityMonitor { // Do a final poll for all events. This is to handle the situation where DescribeStackStatus // already returned an error, but the monitor hasn't seen all the events yet and we'd end // up not printing the failure reason to users. - await this.finalPollToEnd(); + await this.finalPollToEnd(oldMonitorId); - this.printer.stop(); + await this.ioHost.notify(debug(this.action, `Completed ${this.stackName}`, 'CDK_TOOLKIT_I5503', { + deployment: oldMonitorId, + stack: this.stack, + stackName: this.stackName, + errors: this.errors, + })); } private scheduleNextTick() { - if (!this.active) { + if (!this.monitorId) { return; } - this.tickTimer = setTimeout(() => void this.tick(), this.printer.updateSleep); + this.tickTimer = setTimeout(() => void this.tick(), this.pollingInterval); } private async tick() { - if (!this.active) { + if (!this.monitorId) { return; } try { - this.readPromise = this.readNewEvents(); + this.readPromise = this.readNewEvents(this.monitorId); await this.readPromise; this.readPromise = undefined; // We might have been stop()ped while the network call was in progress. - if (!this.active) { + if (!this.monitorId) { return; } - - this.printer.print(); } catch (e) { - error('Error occurred while monitoring stack: %s', e); + await this.ioHost.notify(error( + this.action, + util.format('Error occurred while monitoring stack: %s', e), + 'CDK_TOOLKIT_E5002', + { error: e }, + )); } this.scheduleNextTick(); } private findMetadataFor(logicalId: string | undefined): ResourceMetadata | undefined { - const metadata = this.stack?.manifest?.metadata; + const metadata = this.stack.manifest?.metadata; if (!logicalId || !metadata) { return undefined; } @@ -227,17 +242,21 @@ export class StackActivityMonitor { * see a next page and the last event in the page is new to us (and within the time window). * haven't seen the final event */ - private async readNewEvents(): Promise { + private async readNewEvents(monitorId: string): Promise { const pollEvents = await this.poller.poll(); - const activities: StackActivity[] = pollEvents.map((event) => ({ - ...event, - metadata: this.findMetadataFor(event.event.LogicalResourceId), - })); + for (const resourceEvent of pollEvents) { + this.progressMonitor.process(resourceEvent.event); + + const activity: StackActivity = { + deployment: monitorId, + event: resourceEvent.event, + metadata: this.findMetadataFor(resourceEvent.event.LogicalResourceId), + progress: this.progressMonitor.progress, + }; - for (const activity of activities) { this.checkForErrors(activity); - this.printer.addActivity(activity); + await this.ioHost.notify(info(this.action, this.formatActivity(activity, true), 'CDK_TOOLKIT_I5502', activity)); } } @@ -247,7 +266,7 @@ export class StackActivityMonitor { * Finish any poll currently in progress, then do a final one until we've * reached the last page. */ - private async finalPollToEnd() { + private async finalPollToEnd(monitorId: string) { // If we were doing a poll, finish that first. It was started before // the moment we were sure we weren't going to get any new events anymore // so we need to do a new one anyway. Need to wait for this one though @@ -256,11 +275,35 @@ export class StackActivityMonitor { await this.readPromise; } - await this.readNewEvents(); + await this.readNewEvents(monitorId); + } + + /** + * Formats a stack activity into a basic string + */ + private formatActivity(activity: StackActivity, progress: boolean): string { + const event = activity.event; + const metadata = activity.metadata; + + const resourceName = metadata ? metadata.constructPath : event.LogicalResourceId || ''; + const logicalId = resourceName !== event.LogicalResourceId ? `(${event.LogicalResourceId}) ` : ''; + + return util.format( + '%s | %s%s | %s | %s | %s %s%s%s', + event.StackName, + progress !== false ? `${activity.progress.formatted} | ` : '', + new Date(event.Timestamp!).toLocaleTimeString(), + event.ResourceStatus || '', + event.ResourceType, + resourceName, + logicalId, + event.ResourceStatusReason ? event.ResourceStatusReason : '', + metadata?.entry.trace ? `\n\t${metadata.entry.trace.join('\n\t\\_ ')}` : '', + ); } private checkForErrors(activity: StackActivity) { - if (hasErrorMessage(activity.event.ResourceStatus ?? '')) { + if (stackEventHasErrorMessage(activity.event.ResourceStatus ?? '')) { const isCancelled = (activity.event.ResourceStatusReason ?? '').indexOf('cancelled') > -1; // Cancelled is not an interesting failure reason, nor is the stack message (stack @@ -282,520 +325,3 @@ export class StackActivityMonitor { return path; } } - -function padRight(n: number, x: string): string { - return x + ' '.repeat(Math.max(0, n - x.length)); -} - -/** - * Infamous padLeft() - */ -function padLeft(n: number, x: string): string { - return ' '.repeat(Math.max(0, n - x.length)) + x; -} - -function calcMaxResourceTypeLength(template: any) { - const resources = (template && template.Resources) || {}; - let maxWidth = 0; - for (const id of Object.keys(resources)) { - const type = resources[id].Type || ''; - if (type.length > maxWidth) { - maxWidth = type.length; - } - } - return maxWidth; -} - -interface PrinterProps { - /** - * Total resources to deploy - */ - readonly resourcesTotal?: number; - - /** - * The with of the "resource type" column. - */ - readonly resourceTypeColumnWidth: number; - - /** - * Stream to write to - */ - readonly stream: NodeJS.WriteStream; -} - -export interface IActivityPrinter { - readonly updateSleep: number; - - addActivity(activity: StackActivity): void; - print(): void; - start(): void; - stop(): void; -} - -abstract class ActivityPrinterBase implements IActivityPrinter { - /** - * Fetch new activity every 5 seconds - */ - public readonly updateSleep: number = 5_000; - - /** - * A list of resource IDs which are currently being processed - */ - protected resourcesInProgress: Record = {}; - - /** - * Previous completion state observed by logical ID - * - * We use this to detect that if we see a DELETE_COMPLETE after a - * CREATE_COMPLETE, it's actually a rollback and we should DECREASE - * resourcesDone instead of increase it - */ - protected resourcesPrevCompleteState: Record = {}; - - /** - * Count of resources that have reported a _COMPLETE status - */ - protected resourcesDone: number = 0; - - /** - * How many digits we need to represent the total count (for lining up the status reporting) - */ - protected readonly resourceDigits: number = 0; - - protected readonly resourcesTotal?: number; - - protected rollingBack = false; - - protected readonly failures = new Array(); - - protected hookFailureMap = new Map>(); - - 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. - this.resourcesTotal = props.resourcesTotal ? props.resourcesTotal + 1 : undefined; - - // How many digits does this number take to represent? - this.resourceDigits = this.resourcesTotal ? Math.ceil(Math.log10(this.resourcesTotal)) : 0; - } - - public failureReason(activity: StackActivity) { - const resourceStatusReason = activity.event.ResourceStatusReason ?? ''; - const logicalResourceId = activity.event.LogicalResourceId ?? ''; - const hookFailureReasonMap = this.hookFailureMap.get(logicalResourceId); - - if (hookFailureReasonMap !== undefined) { - for (const hookType of hookFailureReasonMap.keys()) { - if (resourceStatusReason.includes(hookType)) { - return resourceStatusReason + ' : ' + hookFailureReasonMap.get(hookType); - } - } - } - return resourceStatusReason; - } - - public addActivity(activity: StackActivity) { - const status = activity.event.ResourceStatus; - const hookStatus = activity.event.HookStatus; - const hookType = activity.event.HookType; - if (!status || !activity.event.LogicalResourceId) { - return; - } - - if (status === 'ROLLBACK_IN_PROGRESS' || status === 'UPDATE_ROLLBACK_IN_PROGRESS') { - // Only triggered on the stack once we've started doing a rollback - this.rollingBack = true; - } - - if (status.endsWith('_IN_PROGRESS')) { - this.resourcesInProgress[activity.event.LogicalResourceId] = activity; - } - - if (hasErrorMessage(status)) { - const isCancelled = (activity.event.ResourceStatusReason ?? '').indexOf('cancelled') > -1; - - // Cancelled is not an interesting failure reason - if (!isCancelled) { - this.failures.push(activity); - } - } - - if (status.endsWith('_COMPLETE') || status.endsWith('_FAILED')) { - delete this.resourcesInProgress[activity.event.LogicalResourceId]; - } - - if (status.endsWith('_COMPLETE_CLEANUP_IN_PROGRESS')) { - this.resourcesDone++; - } - - if (status.endsWith('_COMPLETE')) { - const prevState = this.resourcesPrevCompleteState[activity.event.LogicalResourceId]; - if (!prevState) { - this.resourcesDone++; - } else { - // If we completed this before and we're completing it AGAIN, means we're rolling back. - // Protect against silly underflow. - this.resourcesDone--; - if (this.resourcesDone < 0) { - this.resourcesDone = 0; - } - } - this.resourcesPrevCompleteState[activity.event.LogicalResourceId] = status; - } - - if ( - hookStatus !== undefined && - hookStatus.endsWith('_COMPLETE_FAILED') && - activity.event.LogicalResourceId !== undefined && - hookType !== undefined - ) { - if (this.hookFailureMap.has(activity.event.LogicalResourceId)) { - this.hookFailureMap.get(activity.event.LogicalResourceId)?.set(hookType, activity.event.HookStatusReason ?? ''); - } else { - this.hookFailureMap.set(activity.event.LogicalResourceId, new Map()); - this.hookFailureMap.get(activity.event.LogicalResourceId)?.set(hookType, activity.event.HookStatusReason ?? ''); - } - } - } - - public abstract print(): void; - - public start() { - // Empty on purpose - } - - public stop() { - // Empty on purpose - } -} - -/** - * Activity Printer which shows a full log of all CloudFormation events - * - * When there hasn't been activity for a while, it will print the resources - * that are currently in progress, to show what's holding up the deployment. - */ -export class HistoryActivityPrinter extends ActivityPrinterBase { - /** - * Last time we printed something to the console. - * - * Used to measure timeout for progress reporting. - */ - private lastPrintTime = Date.now(); - - /** - * Number of ms of change absence before we tell the user about the resources that are currently in progress. - */ - private readonly inProgressDelay = 30_000; - - private readonly printable = new Array(); - - constructor(props: PrinterProps) { - super(props); - } - - public addActivity(activity: StackActivity) { - super.addActivity(activity); - this.printable.push(activity); - this.print(); - } - - public print() { - for (const activity of this.printable) { - this.printOne(activity); - } - this.printable.splice(0, this.printable.length); - this.printInProgress(); - } - - public stop() { - // Print failures at the end - if (this.failures.length > 0) { - info('\nFailed resources:'); - for (const failure of this.failures) { - // Root stack failures are not interesting - if (failure.isStackEvent) { - continue; - } - - this.printOne(failure, false); - } - } - } - - private printOne(activity: StackActivity, progress?: boolean) { - const event = activity.event; - const color = colorFromStatusResult(event.ResourceStatus); - let reasonColor = chalk.cyan; - - let stackTrace = ''; - const metadata = activity.metadata; - - if (event.ResourceStatus && event.ResourceStatus.indexOf('FAILED') !== -1) { - if (progress == undefined || progress) { - event.ResourceStatusReason = event.ResourceStatusReason ? this.failureReason(activity) : ''; - } - if (metadata) { - stackTrace = metadata.entry.trace ? `\n\t${metadata.entry.trace.join('\n\t\\_ ')}` : ''; - } - reasonColor = chalk.red; - } - - const resourceName = metadata ? metadata.constructPath : event.LogicalResourceId || ''; - - const logicalId = resourceName !== event.LogicalResourceId ? `(${event.LogicalResourceId}) ` : ''; - - info( - util.format( - '%s | %s%s | %s | %s | %s %s%s%s', - event.StackName, - progress !== false ? `${this.progress()} | ` : '', - new Date(event.Timestamp!).toLocaleTimeString(), - color(padRight(STATUS_WIDTH, (event.ResourceStatus || '').slice(0, STATUS_WIDTH))), // pad left and trim - padRight(this.props.resourceTypeColumnWidth, event.ResourceType || ''), - color(chalk.bold(resourceName)), - logicalId, - reasonColor(chalk.bold(event.ResourceStatusReason ? event.ResourceStatusReason : '')), - reasonColor(stackTrace), - ), - ); - - this.lastPrintTime = Date.now(); - } - - /** - * Report the current progress as a [34/42] string, or just [34] if the total is unknown - */ - private progress(): string { - if (this.resourcesTotal == null) { - // Don't have total, show simple count and hope the human knows - return padLeft(3, util.format('%s', this.resourcesDone)); // max 500 resources - } - - return util.format( - '%s/%s', - padLeft(this.resourceDigits, this.resourcesDone.toString()), - padLeft(this.resourceDigits, this.resourcesTotal != null ? this.resourcesTotal.toString() : '?'), - ); - } - - /** - * If some resources are taking a while to create, notify the user about what's currently in progress - */ - private printInProgress() { - if (Date.now() < this.lastPrintTime + this.inProgressDelay) { - return; - } - - if (Object.keys(this.resourcesInProgress).length > 0) { - info( - util.format( - '%s Currently in progress: %s', - this.progress(), - chalk.bold(Object.keys(this.resourcesInProgress).join(', ')), - ), - ); - } - - // We cheat a bit here. To prevent printInProgress() from repeatedly triggering, - // we set the timestamp into the future. It will be reset whenever a regular print - // occurs, after which we can be triggered again. - this.lastPrintTime = +Infinity; - } -} - -/** - * Activity Printer which shows the resources currently being updated - * - * It will continuously reupdate the terminal and show only the resources - * that are currently being updated, in addition to a progress bar which - * shows how far along the deployment is. - * - * Resources that have failed will always be shown, and will be recapitulated - * along with their stack trace when the monitoring ends. - * - * Resources that failed deployment because they have been cancelled are - * not included. - */ -export class CurrentActivityPrinter extends ActivityPrinterBase { - /** - * This looks very disorienting sleeping for 5 seconds. Update quicker. - */ - public readonly updateSleep: number = 2_000; - - private oldLogThreshold: IoMessageLevel; - private readonly stream: NodeJS.WriteStream; - private block: RewritableBlock; - - constructor(props: PrinterProps) { - super(props); - this.oldLogThreshold = CliIoHost.instance().logLevel; - this.stream = props.stream; - this.block = new RewritableBlock(this.stream); - } - - public print(): void { - const lines = []; - - // Add a progress bar at the top - const progressWidth = Math.max( - Math.min((this.block.width ?? 80) - PROGRESSBAR_EXTRA_SPACE - 1, MAX_PROGRESSBAR_WIDTH), - MIN_PROGRESSBAR_WIDTH, - ); - const prog = this.progressBar(progressWidth); - if (prog) { - lines.push(' ' + prog, ''); - } - - // Normally we'd only print "resources in progress", but it's also useful - // to keep an eye on the failures and know about the specific errors asquickly - // as possible (while the stack is still rolling back), so add those in. - const toPrint: StackActivity[] = [...this.failures, ...Object.values(this.resourcesInProgress)]; - toPrint.sort((a, b) => a.event.Timestamp!.getTime() - b.event.Timestamp!.getTime()); - - lines.push( - ...toPrint.map((res) => { - const color = colorFromStatusActivity(res.event.ResourceStatus); - const resourceName = res.metadata?.constructPath ?? res.event.LogicalResourceId ?? ''; - - return util.format( - '%s | %s | %s | %s%s', - padLeft(TIMESTAMP_WIDTH, new Date(res.event.Timestamp!).toLocaleTimeString()), - color(padRight(STATUS_WIDTH, (res.event.ResourceStatus || '').slice(0, STATUS_WIDTH))), - padRight(this.props.resourceTypeColumnWidth, res.event.ResourceType || ''), - color(chalk.bold(shorten(40, resourceName))), - this.failureReasonOnNextLine(res), - ); - }), - ); - - this.block.displayLines(lines); - } - - public start() { - // Need to prevent the waiter from printing 'stack not stable' every 5 seconds, it messes - // with the output calculations. - this.oldLogThreshold = CliIoHost.instance().logLevel; - CliIoHost.instance().logLevel = 'info'; - } - - public stop() { - CliIoHost.instance().logLevel = this.oldLogThreshold; - - // Print failures at the end - const lines = new Array(); - for (const failure of this.failures) { - // Root stack failures are not interesting - if (failure.isStackEvent) { - continue; - } - - lines.push( - util.format( - chalk.red('%s | %s | %s | %s%s') + '\n', - padLeft(TIMESTAMP_WIDTH, new Date(failure.event.Timestamp!).toLocaleTimeString()), - padRight(STATUS_WIDTH, (failure.event.ResourceStatus || '').slice(0, STATUS_WIDTH)), - padRight(this.props.resourceTypeColumnWidth, failure.event.ResourceType || ''), - shorten(40, failure.event.LogicalResourceId ?? ''), - this.failureReasonOnNextLine(failure), - ), - ); - - const trace = failure.metadata?.entry?.trace; - if (trace) { - lines.push(chalk.red(`\t${trace.join('\n\t\\_ ')}\n`)); - } - } - - // Display in the same block space, otherwise we're going to have silly empty lines. - this.block.displayLines(lines); - this.block.removeEmptyLines(); - } - - private progressBar(width: number) { - if (!this.resourcesTotal) { - return ''; - } - const fraction = Math.min(this.resourcesDone / this.resourcesTotal, 1); - const innerWidth = Math.max(1, width - 2); - const chars = innerWidth * fraction; - const remainder = chars - Math.floor(chars); - - const fullChars = FULL_BLOCK.repeat(Math.floor(chars)); - const partialChar = PARTIAL_BLOCK[Math.floor(remainder * PARTIAL_BLOCK.length)]; - const filler = '·'.repeat(innerWidth - Math.floor(chars) - (partialChar ? 1 : 0)); - - const color = this.rollingBack ? chalk.yellow : chalk.green; - - return '[' + color(fullChars + partialChar) + filler + `] (${this.resourcesDone}/${this.resourcesTotal})`; - } - - private failureReasonOnNextLine(activity: StackActivity) { - return hasErrorMessage(activity.event.ResourceStatus ?? '') - ? `\n${' '.repeat(TIMESTAMP_WIDTH + STATUS_WIDTH + 6)}${chalk.red(this.failureReason(activity) ?? '')}` - : ''; - } -} - -const FULL_BLOCK = '█'; -const PARTIAL_BLOCK = ['', '▏', '▎', '▍', '▌', '▋', '▊', '▉']; -const MAX_PROGRESSBAR_WIDTH = 60; -const MIN_PROGRESSBAR_WIDTH = 10; -const PROGRESSBAR_EXTRA_SPACE = - 2 /* leading spaces */ + 2 /* brackets */ + 4 /* progress number decoration */ + 6; /* 2 progress numbers up to 999 */ - -function hasErrorMessage(status: string) { - return status.endsWith('_FAILED') || status === 'ROLLBACK_IN_PROGRESS' || status === 'UPDATE_ROLLBACK_IN_PROGRESS'; -} - -function colorFromStatusResult(status?: string) { - if (!status) { - return chalk.reset; - } - - if (status.indexOf('FAILED') !== -1) { - return chalk.red; - } - if (status.indexOf('ROLLBACK') !== -1) { - return chalk.yellow; - } - if (status.indexOf('COMPLETE') !== -1) { - return chalk.green; - } - - return chalk.reset; -} - -function colorFromStatusActivity(status?: string) { - if (!status) { - return chalk.reset; - } - - if (status.endsWith('_FAILED')) { - return chalk.red; - } - - if (status.startsWith('CREATE_') || status.startsWith('UPDATE_') || status.startsWith('IMPORT_')) { - return chalk.green; - } - // For stacks, it may also be 'UPDDATE_ROLLBACK_IN_PROGRESS' - if (status.indexOf('ROLLBACK_') !== -1) { - return chalk.yellow; - } - if (status.startsWith('DELETE_')) { - return chalk.yellow; - } - - return chalk.reset; -} - -function shorten(maxWidth: number, p: string) { - if (p.length <= maxWidth) { - return p; - } - const half = Math.floor((maxWidth - 3) / 2); - return p.slice(0, half) + '...' + p.slice(-half); -} - -const TIMESTAMP_WIDTH = 12; -const STATUS_WIDTH = 20; diff --git a/packages/aws-cdk/lib/api/stack-events/stack-event-poller.ts b/packages/aws-cdk/lib/api/stack-events/stack-event-poller.ts index 02f93970..e86fcc73 100644 --- a/packages/aws-cdk/lib/api/stack-events/stack-event-poller.ts +++ b/packages/aws-cdk/lib/api/stack-events/stack-event-poller.ts @@ -32,7 +32,14 @@ export interface StackEventPollerProps { } export interface ResourceEvent { + /** + * The Stack Event as received from CloudFormation + */ readonly event: StackEvent; + + /** + * IDs of parent stacks of the resource, in case of resources in nested stacks + */ readonly parentStackLogicalIds: string[]; /** diff --git a/packages/aws-cdk/lib/api/stack-events/stack-progress-monitor.ts b/packages/aws-cdk/lib/api/stack-events/stack-progress-monitor.ts new file mode 100644 index 00000000..ae64370e --- /dev/null +++ b/packages/aws-cdk/lib/api/stack-events/stack-progress-monitor.ts @@ -0,0 +1,129 @@ + +import * as util from 'util'; +import { StackEvent } from '@aws-sdk/client-cloudformation'; +import { padLeft } from '../../util/string-manipulation'; + +export interface StackProgress { + /** + * The total number of progress monitored resources. + */ + readonly total?: number; + + /** + * The number of completed resources. + */ + readonly completed: number; + + /** + * The current progress as a [34/42] string, or just [34] if the total is unknown. + */ + readonly formatted: string; +} + +/** + * Monitors stack progress.s + */ +export class StackProgressMonitor { + /** + * Previous completion state observed by logical ID + * + * We use this to detect that if we see a DELETE_COMPLETE after a + * CREATE_COMPLETE, it's actually a rollback and we should DECREASE + * resourcesDone instead of increase it + */ + private resourcesPrevCompleteState: Record = {}; + + /** + * Count of resources that have reported a _COMPLETE status + */ + private resourcesDone: number = 0; + + /** + * How many digits we need to represent the total count (for lining up the status reporting) + */ + private readonly resourceDigits: number = 0; + + /** + * Number of expected resources in the monitor. + */ + private readonly resourcesTotal?: number; + + constructor(resourcesTotal?: number) { + // +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. + this.resourcesTotal = resourcesTotal ? resourcesTotal + 1 : undefined; + + // How many digits does this number take to represent? + this.resourceDigits = this.resourcesTotal ? Math.ceil(Math.log10(this.resourcesTotal)) : 0; + } + + /** + * Report the stack progress + */ + public get progress(): StackProgress { + return { + total: this.total, + completed: this.completed, + formatted: this.formatted, + }; + } + + /** + * The total number of progress monitored resources. + */ + public get total(): number | undefined { + return this.resourcesTotal; + } + + /** + * The number of completed resources. + */ + public get completed(): number { + return this.resourcesDone; + } + + /** + * Report the current progress as a [34/42] string, or just [34] if the total is unknown + */ + public get formatted(): string { + if (this.resourcesTotal == null) { + // Don't have total, show simple count and hope the human knows + return padLeft(3, util.format('%s', this.resourcesDone)); // max 500 resources + } + + return util.format( + '%s/%s', + padLeft(this.resourceDigits, this.resourcesDone.toString()), + padLeft(this.resourceDigits, this.resourcesTotal != null ? this.resourcesTotal.toString() : '?'), + ); + } + + /** + * Process as stack event and update the progress state. + */ + public process(event: StackEvent): void { + const status = event.ResourceStatus; + if (!status || !event.LogicalResourceId) { + return; + } + + if (status.endsWith('_COMPLETE_CLEANUP_IN_PROGRESS')) { + this.resourcesDone++; + } + + if (status.endsWith('_COMPLETE')) { + const prevState = this.resourcesPrevCompleteState[event.LogicalResourceId]; + if (!prevState) { + this.resourcesDone++; + } else { + // If we completed this before and we're completing it AGAIN, means we're rolling back. + // Protect against silly underflow. + this.resourcesDone--; + if (this.resourcesDone < 0) { + this.resourcesDone = 0; + } + } + this.resourcesPrevCompleteState[event.LogicalResourceId] = status; + } + } +} diff --git a/packages/aws-cdk/lib/cli/activity-printer/base.ts b/packages/aws-cdk/lib/cli/activity-printer/base.ts new file mode 100644 index 00000000..6c3cc27d --- /dev/null +++ b/packages/aws-cdk/lib/cli/activity-printer/base.ts @@ -0,0 +1,194 @@ +import { CloudFormationStackArtifact } from '@aws-cdk/cx-api'; +import type { StackActivity } from '../../api/stack-events'; +import { StackProgress } from '../../api/stack-events/stack-progress-monitor'; +import { IoMessage } from '../../toolkit/cli-io-host'; +import { maxResourceTypeLength, stackEventHasErrorMessage } from '../../util'; + +export interface IActivityPrinter { + notify(msg: IoMessage): Promise; +} + +export interface ActivityPrinterProps { + /** + * Stream to write to + */ + readonly stream: NodeJS.WriteStream; +} + +export abstract class ActivityPrinterBase implements IActivityPrinter { + protected static readonly TIMESTAMP_WIDTH = 12; + protected static readonly STATUS_WIDTH = 20; + + /** + * Fetch new activity every 5 seconds + */ + public readonly updateSleep: number = 5_000; + + /** + * Stream to write to + */ + protected readonly stream: NodeJS.WriteStream; + + /** + * The with of the "resource type" column. + */ + protected resourceTypeColumnWidth: number = maxResourceTypeLength({}); + + /** + * A list of resource IDs which are currently being processed + */ + protected resourcesInProgress: Record = {}; + + protected stackProgress?: StackProgress; + + protected rollingBack = false; + + protected readonly failures = new Array(); + + protected hookFailureMap = new Map>(); + + /** + * Current tick timer + */ + private tickTimer?: ReturnType; + + /** + * Is the printer currently active? + **/ + protected active: boolean = false; + + constructor(protected readonly props: ActivityPrinterProps) { + this.stream = props.stream; + } + + protected abstract print(): void; + + /** + * Receive a stack activity message + */ + public async notify(msg: IoMessage): Promise { + switch (msg.code) { + case 'CDK_TOOLKIT_I5501': + this.start(msg.data); + break; + case 'CDK_TOOLKIT_I5502': + this.addActivity(msg.data as StackActivity); + break; + case 'CDK_TOOLKIT_I5503': + await this.stop(); + break; + default: + // ignore all other messages + break; + } + } + + public addActivity(activity: StackActivity) { + const status = activity.event.ResourceStatus; + const hookStatus = activity.event.HookStatus; + const hookType = activity.event.HookType; + if (!status || !activity.event.LogicalResourceId) { + return; + } + + this.stackProgress = activity.progress; + + if (status === 'ROLLBACK_IN_PROGRESS' || status === 'UPDATE_ROLLBACK_IN_PROGRESS') { + // Only triggered on the stack once we've started doing a rollback + this.rollingBack = true; + } + + if (status.endsWith('_IN_PROGRESS')) { + this.resourcesInProgress[activity.event.LogicalResourceId] = activity; + } + + if (stackEventHasErrorMessage(status)) { + const isCancelled = (activity.event.ResourceStatusReason ?? '').indexOf('cancelled') > -1; + + // Cancelled is not an interesting failure reason + if (!isCancelled) { + this.failures.push(activity); + } + } + + if (status.endsWith('_COMPLETE') || status.endsWith('_FAILED')) { + delete this.resourcesInProgress[activity.event.LogicalResourceId]; + } + + if ( + hookStatus !== undefined && + hookStatus.endsWith('_COMPLETE_FAILED') && + activity.event.LogicalResourceId !== undefined && + hookType !== undefined + ) { + if (this.hookFailureMap.has(activity.event.LogicalResourceId)) { + this.hookFailureMap.get(activity.event.LogicalResourceId)?.set(hookType, activity.event.HookStatusReason ?? ''); + } else { + this.hookFailureMap.set(activity.event.LogicalResourceId, new Map()); + this.hookFailureMap.get(activity.event.LogicalResourceId)?.set(hookType, activity.event.HookStatusReason ?? ''); + } + } + } + + protected failureReason(activity: StackActivity) { + const resourceStatusReason = activity.event.ResourceStatusReason ?? ''; + const logicalResourceId = activity.event.LogicalResourceId ?? ''; + const hookFailureReasonMap = this.hookFailureMap.get(logicalResourceId); + + if (hookFailureReasonMap !== undefined) { + for (const hookType of hookFailureReasonMap.keys()) { + if (resourceStatusReason.includes(hookType)) { + return resourceStatusReason + ' : ' + hookFailureReasonMap.get(hookType); + } + } + } + return resourceStatusReason; + } + + public start({ stack }: { stack: CloudFormationStackArtifact}) { + this.active = true; + this.resourceTypeColumnWidth = maxResourceTypeLength(stack.template), + this.scheduleNextTick(); + } + + public async stop() { + // Do a final pass of all received messages + await this.tick(); + + // disable ticking and clear timeout + this.active = false; + if (this.tickTimer) { + clearTimeout(this.tickTimer); + } + } + + private scheduleNextTick() { + if (!this.active) { + return; + } + + this.tickTimer = setTimeout(() => void this.tick(), this.updateSleep); + } + + private async tick() { + if (!this.active) { + return; + } + + this.print(); + + // We might have been stop()ped while the network call was in progress. + if (!this.active) { + return; + } + + this.scheduleNextTick(); + } + + /** + * Is the activity a meta activity for the stack itself. + */ + protected isActivityForTheStack(activity: StackActivity) { + return activity.event.PhysicalResourceId === activity.event.StackId; + } +} diff --git a/packages/aws-cdk/lib/cli/activity-printer/current.ts b/packages/aws-cdk/lib/cli/activity-printer/current.ts new file mode 100644 index 00000000..d133319d --- /dev/null +++ b/packages/aws-cdk/lib/cli/activity-printer/current.ts @@ -0,0 +1,170 @@ +import * as util from 'util'; +import * as chalk from 'chalk'; +import { ActivityPrinterBase, ActivityPrinterProps } from './base'; +import { RewritableBlock } from './display'; +import type { StackActivity } from '../../api/stack-events'; +import { padLeft, padRight, stackEventHasErrorMessage } from '../../util'; + +/** + * Activity Printer which shows the resources currently being updated + * + * It will continuously re-update the terminal and show only the resources + * that are currently being updated, in addition to a progress bar which + * shows how far along the deployment is. + * + * Resources that have failed will always be shown, and will be recapitulated + * along with their stack trace when the monitoring ends. + * + * Resources that failed deployment because they have been cancelled are + * not included. + */ +export class CurrentActivityPrinter extends ActivityPrinterBase { + /** + * This looks very disorienting sleeping for 5 seconds. Update quicker. + */ + public readonly updateSleep: number = 2_000; + + /** + * Continuously write to the same output block. + */ + private block: RewritableBlock; + + constructor(props: ActivityPrinterProps) { + super(props); + this.block = new RewritableBlock(this.stream); + } + + protected print(): void { + const lines = []; + + // Add a progress bar at the top + const progressWidth = Math.max( + Math.min((this.block.width ?? 80) - PROGRESSBAR_EXTRA_SPACE - 1, MAX_PROGRESSBAR_WIDTH), + MIN_PROGRESSBAR_WIDTH, + ); + const prog = this.progressBar(progressWidth); + if (prog) { + lines.push(' ' + prog, ''); + } + + // Normally we'd only print "resources in progress", but it's also useful + // to keep an eye on the failures and know about the specific errors asquickly + // as possible (while the stack is still rolling back), so add those in. + const toPrint: StackActivity[] = [...this.failures, ...Object.values(this.resourcesInProgress)]; + toPrint.sort((a, b) => a.event.Timestamp!.getTime() - b.event.Timestamp!.getTime()); + + lines.push( + ...toPrint.map((res) => { + const color = colorFromStatusActivity(res.event.ResourceStatus); + const resourceName = res.metadata?.constructPath ?? res.event.LogicalResourceId ?? ''; + + return util.format( + '%s | %s | %s | %s%s', + padLeft(CurrentActivityPrinter.TIMESTAMP_WIDTH, new Date(res.event.Timestamp!).toLocaleTimeString()), + color(padRight(CurrentActivityPrinter.STATUS_WIDTH, (res.event.ResourceStatus || '').slice(0, CurrentActivityPrinter.STATUS_WIDTH))), + padRight(this.resourceTypeColumnWidth, res.event.ResourceType || ''), + color(chalk.bold(shorten(40, resourceName))), + this.failureReasonOnNextLine(res), + ); + }), + ); + + this.block.displayLines(lines); + } + + public async stop() { + await super.stop(); + + // Print failures at the end + const lines = new Array(); + for (const failure of this.failures) { + // Root stack failures are not interesting + if (this.isActivityForTheStack(failure)) { + continue; + } + + lines.push( + util.format( + chalk.red('%s | %s | %s | %s%s') + '\n', + padLeft(CurrentActivityPrinter.TIMESTAMP_WIDTH, new Date(failure.event.Timestamp!).toLocaleTimeString()), + padRight(CurrentActivityPrinter.STATUS_WIDTH, (failure.event.ResourceStatus || '').slice(0, CurrentActivityPrinter.STATUS_WIDTH)), + padRight(this.resourceTypeColumnWidth, failure.event.ResourceType || ''), + shorten(40, failure.event.LogicalResourceId ?? ''), + this.failureReasonOnNextLine(failure), + ), + ); + + const trace = failure.metadata?.entry?.trace; + if (trace) { + lines.push(chalk.red(`\t${trace.join('\n\t\\_ ')}\n`)); + } + } + + // Display in the same block space, otherwise we're going to have silly empty lines. + this.block.displayLines(lines); + this.block.removeEmptyLines(); + } + + private progressBar(width: number) { + if (!this.stackProgress || !this.stackProgress.total) { + return ''; + } + const fraction = Math.min(this.stackProgress.completed / this.stackProgress.total, 1); + const innerWidth = Math.max(1, width - 2); + const chars = innerWidth * fraction; + const remainder = chars - Math.floor(chars); + + const fullChars = FULL_BLOCK.repeat(Math.floor(chars)); + const partialChar = PARTIAL_BLOCK[Math.floor(remainder * PARTIAL_BLOCK.length)]; + const filler = '·'.repeat(innerWidth - Math.floor(chars) - (partialChar ? 1 : 0)); + + const color = this.rollingBack ? chalk.yellow : chalk.green; + + return '[' + color(fullChars + partialChar) + filler + `] (${this.stackProgress.completed}/${this.stackProgress.total})`; + } + + private failureReasonOnNextLine(activity: StackActivity) { + return stackEventHasErrorMessage(activity.event.ResourceStatus ?? '') + ? `\n${' '.repeat(CurrentActivityPrinter.TIMESTAMP_WIDTH + CurrentActivityPrinter.STATUS_WIDTH + 6)}${chalk.red(this.failureReason(activity) ?? '')}` + : ''; + } +} + +const FULL_BLOCK = '█'; +const PARTIAL_BLOCK = ['', '▏', '▎', '▍', '▌', '▋', '▊', '▉']; +const MAX_PROGRESSBAR_WIDTH = 60; +const MIN_PROGRESSBAR_WIDTH = 10; +const PROGRESSBAR_EXTRA_SPACE = + 2 /* leading spaces */ + 2 /* brackets */ + 4 /* progress number decoration */ + 6; /* 2 progress numbers up to 999 */ + +function colorFromStatusActivity(status?: string) { + if (!status) { + return chalk.reset; + } + + if (status.endsWith('_FAILED')) { + return chalk.red; + } + + if (status.startsWith('CREATE_') || status.startsWith('UPDATE_') || status.startsWith('IMPORT_')) { + return chalk.green; + } + // For stacks, it may also be 'UPDDATE_ROLLBACK_IN_PROGRESS' + if (status.indexOf('ROLLBACK_') !== -1) { + return chalk.yellow; + } + if (status.startsWith('DELETE_')) { + return chalk.yellow; + } + + return chalk.reset; +} + +function shorten(maxWidth: number, p: string) { + if (p.length <= maxWidth) { + return p; + } + const half = Math.floor((maxWidth - 3) / 2); + return p.slice(0, half) + '...' + p.slice(-half); +} + diff --git a/packages/aws-cdk/lib/api/stack-events/display.ts b/packages/aws-cdk/lib/cli/activity-printer/display.ts similarity index 100% rename from packages/aws-cdk/lib/api/stack-events/display.ts rename to packages/aws-cdk/lib/cli/activity-printer/display.ts diff --git a/packages/aws-cdk/lib/cli/activity-printer/history.ts b/packages/aws-cdk/lib/cli/activity-printer/history.ts new file mode 100644 index 00000000..be7968a2 --- /dev/null +++ b/packages/aws-cdk/lib/cli/activity-printer/history.ts @@ -0,0 +1,145 @@ +import * as util from 'util'; +import * as chalk from 'chalk'; +import { ActivityPrinterBase, ActivityPrinterProps } from './base'; +import type { StackActivity } from '../../api/stack-events'; +import { padRight } from '../../util'; + +/** + * Activity Printer which shows a full log of all CloudFormation events + * + * When there hasn't been activity for a while, it will print the resources + * that are currently in progress, to show what's holding up the deployment. + */ +export class HistoryActivityPrinter extends ActivityPrinterBase { + /** + * Last time we printed something to the console. + * + * Used to measure timeout for progress reporting. + */ + private lastPrintTime = Date.now(); + + private lastPrinted?: StackActivity; + + /** + * Number of ms of change absence before we tell the user about the resources that are currently in progress. + */ + private readonly inProgressDelay = 30_000; + + private readonly printable = new Array(); + + constructor(props: ActivityPrinterProps) { + super(props); + } + + public addActivity(activity: StackActivity) { + super.addActivity(activity); + this.printable.push(activity); + } + + public async stop() { + await super.stop(); + + // Print failures at the end + if (this.failures.length > 0) { + this.stream.write('\nFailed resources:\n'); + for (const failure of this.failures) { + // Root stack failures are not interesting + if (this.isActivityForTheStack(failure)) { + continue; + } + + this.printOne(failure, false); + } + } + } + + protected print() { + for (const activity of this.printable) { + this.printOne(activity); + this.lastPrinted = activity; + } + this.printable.splice(0, this.printable.length); + this.printInProgress(this.lastPrinted?.progress.formatted); + } + + private printOne(activity: StackActivity, progress?: boolean) { + const event = activity.event; + const color = colorFromStatusResult(event.ResourceStatus); + let reasonColor = chalk.cyan; + + let stackTrace = ''; + const metadata = activity.metadata; + + if (event.ResourceStatus && event.ResourceStatus.indexOf('FAILED') !== -1) { + if (progress == undefined || progress) { + event.ResourceStatusReason = event.ResourceStatusReason ? this.failureReason(activity) : ''; + } + if (metadata) { + stackTrace = metadata.entry.trace ? `\n\t${metadata.entry.trace.join('\n\t\\_ ')}` : ''; + } + reasonColor = chalk.red; + } + + const resourceName = metadata ? metadata.constructPath : event.LogicalResourceId || ''; + const logicalId = resourceName !== event.LogicalResourceId ? `(${event.LogicalResourceId}) ` : ''; + + this.stream.write( + util.format( + '%s | %s%s | %s | %s | %s %s%s%s\n', + event.StackName, + progress !== false ? `${activity.progress.formatted} | ` : '', + new Date(event.Timestamp!).toLocaleTimeString(), + color(padRight(HistoryActivityPrinter.STATUS_WIDTH, (event.ResourceStatus || '').slice(0, HistoryActivityPrinter.STATUS_WIDTH))), // pad left and trim + padRight(this.resourceTypeColumnWidth, event.ResourceType || ''), + color(chalk.bold(resourceName)), + logicalId, + reasonColor(chalk.bold(event.ResourceStatusReason ? event.ResourceStatusReason : '')), + reasonColor(stackTrace), + ), + ); + + this.lastPrintTime = Date.now(); + } + + /** + * If some resources are taking a while to create, notify the user about what's currently in progress + */ + private printInProgress(progress?: string) { + if (!progress || Date.now() < this.lastPrintTime + this.inProgressDelay) { + return; + } + + if (Object.keys(this.resourcesInProgress).length > 0) { + this.stream.write( + util.format( + '%s Currently in progress: %s\n', + progress, + chalk.bold(Object.keys(this.resourcesInProgress).join(', ')), + ), + ); + } + + // We cheat a bit here. To prevent printInProgress() from repeatedly triggering, + // we set the timestamp into the future. It will be reset whenever a regular print + // occurs, after which we can be triggered again. + this.lastPrintTime = +Infinity; + } +} + +function colorFromStatusResult(status?: string) { + if (!status) { + return chalk.reset; + } + + if (status.indexOf('FAILED') !== -1) { + return chalk.red; + } + if (status.indexOf('ROLLBACK') !== -1) { + return chalk.yellow; + } + if (status.indexOf('COMPLETE') !== -1) { + return chalk.green; + } + + return chalk.reset; +} diff --git a/packages/aws-cdk/lib/cli/activity-printer/index.ts b/packages/aws-cdk/lib/cli/activity-printer/index.ts new file mode 100644 index 00000000..b82fd2e0 --- /dev/null +++ b/packages/aws-cdk/lib/cli/activity-printer/index.ts @@ -0,0 +1,3 @@ +export * from './base'; +export * from './history'; +export * from './current'; diff --git a/packages/aws-cdk/lib/cli/cdk-toolkit.ts b/packages/aws-cdk/lib/cli/cdk-toolkit.ts index fb7567b8..8d3e289b 100644 --- a/packages/aws-cdk/lib/cli/cdk-toolkit.ts +++ b/packages/aws-cdk/lib/cli/cdk-toolkit.ts @@ -25,10 +25,10 @@ import { HotswapMode, HotswapPropertyOverrides, EcsHotswapProperties } from '../ import { findCloudWatchLogGroups } from '../api/logs/find-cloudwatch-logs'; import { CloudWatchLogEventMonitor } from '../api/logs/logs-monitor'; import { ResourceImporter, removeNonImportResources, ResourceMigrator } from '../api/resource-import'; -import { StackActivityProgress } from '../api/stack-events'; import { tagsForStack, type Tag } from '../api/tags'; import { type AssetBuildNode, type AssetPublishNode, type Concurrency, type StackNode, type WorkGraph } from '../api/work-graph'; import { WorkGraphBuilder } from '../api/work-graph/work-graph-builder'; +import { StackActivityProgress } from '../commands/deploy'; import { generateCdkApp, generateStack, @@ -453,8 +453,6 @@ export class CdkToolkit { force: options.force, parameters: Object.assign({}, parameterMap['*'], parameterMap[stack.stackName]), usePreviousParameters: options.usePreviousParameters, - progress, - ci: options.ci, rollback, hotswap: options.hotswap, hotswapPropertyOverrides: hotswapPropertyOverrides, @@ -574,9 +572,14 @@ export class CdkToolkit { const assetBuildTime = options.assetBuildTime ?? AssetBuildTime.ALL_BEFORE_DEPLOY; const prebuildAssets = assetBuildTime === AssetBuildTime.ALL_BEFORE_DEPLOY; const concurrency = options.concurrency || 1; - const progress = concurrency > 1 ? StackActivityProgress.EVENTS : options.progress; - if (concurrency > 1 && options.progress && options.progress != StackActivityProgress.EVENTS) { - warning('⚠️ The --concurrency flag only supports --progress "events". Switching to "events".'); + if (concurrency > 1) { + // always force "events" progress output when we have concurrency + this.ioHost.stackProgress = StackActivityProgress.EVENTS; + + // ...but only warn if the user explicitly requested "bar" progress + if (options.progress && options.progress != StackActivityProgress.EVENTS) { + warning('⚠️ The --concurrency flag only supports --progress "events". Switching to "events".'); + } } const stacksAndTheirAssetManifests = stacks.flatMap((stack) => [ @@ -810,7 +813,6 @@ export class CdkToolkit { tags, deploymentMethod: options.deploymentMethod, usePreviousParameters: true, - progress: options.progress, rollback: options.rollback, }); diff --git a/packages/aws-cdk/lib/cli/cli-config.ts b/packages/aws-cdk/lib/cli/cli-config.ts index de9cf0f4..84b4e69c 100644 --- a/packages/aws-cdk/lib/cli/cli-config.ts +++ b/packages/aws-cdk/lib/cli/cli-config.ts @@ -1,7 +1,7 @@ // eslint-disable-next-line import/no-extraneous-dependencies import { CliHelpers, type CliConfig } from '@aws-cdk/user-input-gen'; import * as cdk_from_cfn from 'cdk-from-cfn'; -import { StackActivityProgress } from '../api/stack-events'; +import { StackActivityProgress } from '../commands/deploy'; import { RequireApproval } from '../diff'; import { availableInitLanguages } from '../init'; diff --git a/packages/aws-cdk/lib/cli/cli.ts b/packages/aws-cdk/lib/cli/cli.ts index 98bc9a2a..05bad8c6 100644 --- a/packages/aws-cdk/lib/cli/cli.ts +++ b/packages/aws-cdk/lib/cli/cli.ts @@ -62,6 +62,7 @@ export async function exec(args: string[], synthesizer?: Synthesizer): Promise levelPriority.info; + if (verboseLogging) { + return StackActivityProgress.EVENTS; + } + + // On Windows we cannot use fancy output + const isWindows = process.platform === 'win32'; + if (isWindows) { + return StackActivityProgress.EVENTS; + } + + // 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 + const fancyOutputAvailable = this.isTTY && !this.isCI; + if (!fancyOutputAvailable) { + return StackActivityProgress.EVENTS; + } + + // Use the user preference + return this._progress; + } + /** * The current action being performed by the CLI. */ @@ -303,6 +361,14 @@ export class CliIoHost implements IIoHost { return this._internalIoHost.notify(msg); } + if (this.isStackActivity(msg)) { + if (!this.activityPrinter) { + this.activityPrinter = this.makeActivityPrinter(); + } + await this.activityPrinter.notify(msg); + return; + } + if (levelPriority[msg.level] > levelPriority[this.logLevel]) { return; } @@ -317,6 +383,17 @@ export class CliIoHost implements IIoHost { stream.write(output); } + /** + * Detect stack activity messages so they can be send to the printer. + */ + private isStackActivity(msg: IoMessage) { + return [ + 'CDK_TOOLKIT_I5501', + 'CDK_TOOLKIT_I5502', + 'CDK_TOOLKIT_I5503', + ].includes(msg.code); + } + /** * Determines the output stream, based on message level and configuration. */ @@ -423,6 +500,22 @@ export class CliIoHost implements IIoHost { const pad = (n: number): string => n.toString().padStart(2, '0'); return `${pad(d.getHours())}:${pad(d.getMinutes())}:${pad(d.getSeconds())}`; } + + /** + * Get an instance of the ActivityPrinter + */ + private makeActivityPrinter() { + const props: ActivityPrinterProps = { + stream: this.selectStream('info'), + }; + + switch (this.stackProgress) { + case StackActivityProgress.EVENTS: + return new HistoryActivityPrinter(props); + case StackActivityProgress.BAR: + return new CurrentActivityPrinter(props); + } + } } /** @@ -474,3 +567,4 @@ const styleMap: Record string> = { export function isCI(): boolean { return process.env.CI !== undefined && process.env.CI !== 'false' && process.env.CI !== '0'; } + diff --git a/packages/aws-cdk/lib/util/cloudformation.ts b/packages/aws-cdk/lib/util/cloudformation.ts index 4d1f458a..0ca94b20 100644 --- a/packages/aws-cdk/lib/util/cloudformation.ts +++ b/packages/aws-cdk/lib/util/cloudformation.ts @@ -4,3 +4,29 @@ export function validateSnsTopicArn(arn: string): boolean { return /^arn:aws:sns:[a-z0-9\-]+:[0-9]+:[a-z0-9\-\_]+$/i.test(arn); } + +/** + * Does a Stack Event have an error message based on the status. + */ +export function stackEventHasErrorMessage(status: string): boolean { + return status.endsWith('_FAILED') || status === 'ROLLBACK_IN_PROGRESS' || status === 'UPDATE_ROLLBACK_IN_PROGRESS'; +} + +/** + * Calculate the maximal length of all resource types for a given template. + * + * @param template the stack template to analyze + * @param startWidth the initial width to start with. Defaults to the length of 'AWS::CloudFormation::Stack'. + * @returns the determined width + */ +export function maxResourceTypeLength(template: any, startWidth = 'AWS::CloudFormation::Stack'.length): number { + const resources = (template && template.Resources) || {}; + let maxWidth = startWidth; + for (const id of Object.keys(resources)) { + const type = resources[id].Type || ''; + if (type.length > maxWidth) { + maxWidth = type.length; + } + } + return maxWidth; +} diff --git a/packages/aws-cdk/lib/util/string-manipulation.ts b/packages/aws-cdk/lib/util/string-manipulation.ts index 87f6453b..098beacd 100644 --- a/packages/aws-cdk/lib/util/string-manipulation.ts +++ b/packages/aws-cdk/lib/util/string-manipulation.ts @@ -1,9 +1,15 @@ /** * Pad 's' on the left with 'char' until it is n characters wide */ -export function leftPad(s: string, n: number, char: string) { - const padding = Math.max(0, n - s.length); - return char.repeat(padding) + s; +export function padLeft(n: number, x: string, char: string = ' '): string { + return char.repeat(Math.max(0, n - x.length)) + x; +} + +/** + * Pad 's' on the right with 'char' until it is n characters wide + */ +export function padRight(n: number, x: string, char: string = ' '): string { + return x + char.repeat(Math.max(0, n - x.length)); } /** diff --git a/packages/aws-cdk/test/api/stack-events/progress-monitor.test.ts b/packages/aws-cdk/test/api/stack-events/progress-monitor.test.ts new file mode 100644 index 00000000..cb43c61e --- /dev/null +++ b/packages/aws-cdk/test/api/stack-events/progress-monitor.test.ts @@ -0,0 +1,89 @@ +import { ResourceStatus } from '@aws-sdk/client-cloudformation'; +import { StackProgressMonitor } from '../../../lib/api/stack-events/stack-progress-monitor'; + +let TIMESTAMP: number; +beforeAll(() => { + TIMESTAMP = new Date().getTime(); +}); + +test('prints 0/4 progress report, when addActivity is called with an "IN_PROGRESS" ResourceStatus', () => { + const stackProgress = new StackProgressMonitor(3); + + stackProgress.process({ + LogicalResourceId: 'stack1', + ResourceStatus: ResourceStatus.CREATE_IN_PROGRESS, + Timestamp: new Date(TIMESTAMP), + ResourceType: 'AWS::CloudFormation::Stack', + StackId: '', + EventId: '', + StackName: 'stack-name', + }); + + expect(stackProgress.formatted).toStrictEqual('0/4'); +}); + +test('prints 1/4 progress report, when addActivity is called with an "UPDATE_COMPLETE" ResourceStatus', () => { + const stackProgress = new StackProgressMonitor(3); + + stackProgress.process({ + LogicalResourceId: 'stack1', + ResourceStatus: ResourceStatus.UPDATE_COMPLETE, + Timestamp: new Date(TIMESTAMP), + ResourceType: 'AWS::CloudFormation::Stack', + StackId: '', + EventId: '', + StackName: 'stack-name', + }); + + expect(stackProgress.formatted).toStrictEqual('1/4'); +}); + +test('prints 1/4 progress report, when addActivity is called with an "UPDATE_COMPLETE" ResourceStatus', () => { + const stackProgress = new StackProgressMonitor(3); + + stackProgress.process({ + LogicalResourceId: 'stack1', + ResourceStatus: ResourceStatus.UPDATE_COMPLETE, + Timestamp: new Date(TIMESTAMP), + ResourceType: 'AWS::CloudFormation::Stack', + StackId: '', + EventId: '', + StackName: 'stack-name', + }); + + expect(stackProgress.formatted).toStrictEqual('1/4'); +}); + +test('prints 1/4 progress report, when addActivity is called with an "ROLLBACK_COMPLETE" ResourceStatus', () => { + const stackProgress = new StackProgressMonitor(3); + + stackProgress.process({ + LogicalResourceId: 'stack1', + ResourceStatus: ResourceStatus.ROLLBACK_COMPLETE, + Timestamp: new Date(TIMESTAMP), + ResourceType: 'AWS::CloudFormation::Stack', + StackId: '', + EventId: '', + StackName: 'stack-name', + + }); + + expect(stackProgress.formatted).toStrictEqual('1/4'); +}); + +test('prints 0/4 progress report, when addActivity is called with an "UPDATE_FAILED" ResourceStatus', () => { + const stackProgress = new StackProgressMonitor(3); + + stackProgress.process({ + LogicalResourceId: 'stack1', + ResourceStatus: ResourceStatus.UPDATE_FAILED, + Timestamp: new Date(TIMESTAMP), + ResourceType: 'AWS::CloudFormation::Stack', + StackId: '', + EventId: '', + StackName: 'stack-name', + }); + + expect(stackProgress.formatted).toStrictEqual('0/4'); +}); + diff --git a/packages/aws-cdk/test/api/stack-events/stack-activity-monitor.test.ts b/packages/aws-cdk/test/api/stack-events/stack-activity-monitor.test.ts index b760dda0..19bca77d 100644 --- a/packages/aws-cdk/test/api/stack-events/stack-activity-monitor.test.ts +++ b/packages/aws-cdk/test/api/stack-events/stack-activity-monitor.test.ts @@ -1,309 +1,285 @@ -/* eslint-disable import/order */ -import * as chalk from 'chalk'; -import { stderr } from '../_helpers/console-listener'; -import { HistoryActivityPrinter } from '../../../lib/api/stack-events'; -import { ResourceStatus } from '@aws-sdk/client-cloudformation'; -import { CliIoHost } from '../../../lib/toolkit/cli-io-host'; - -let TIMESTAMP: number; -let HUMAN_TIME: string; - -beforeAll(() => { - TIMESTAMP = new Date().getTime(); - HUMAN_TIME = new Date(TIMESTAMP).toLocaleTimeString(); - CliIoHost.instance().isCI = false; -}); +import { + DescribeStackEventsCommand, + ResourceStatus, + type StackEvent, + StackStatus, +} from '@aws-sdk/client-cloudformation'; +import { MockSdk, mockCloudFormationClient, restoreSdkMocksToDefault } from '../../util/mock-sdk'; +import { StackActivityMonitor } from '../../../lib/api/stack-events'; +import { IIoHost } from '../../../lib/toolkit/cli-io-host'; +import { testStack } from '../../util'; -test('prints 0/4 progress report, when addActivity is called with an "IN_PROGRESS" ResourceStatus', () => { - const historyActivityPrinter = new HistoryActivityPrinter({ - resourceTypeColumnWidth: 23, - resourcesTotal: 3, - stream: process.stderr, - }); +let sdk: MockSdk; +let monitor: StackActivityMonitor; +let ioHost: IIoHost = { + notify: jest.fn(), + requestResponse: jest.fn().mockImplementation((msg) => msg.defaultResponse), +} +beforeEach(async () => { + sdk = new MockSdk(); - const output = stderr.inspectSync(() => { - historyActivityPrinter.addActivity({ - event: { - LogicalResourceId: 'stack1', - ResourceStatus: ResourceStatus.CREATE_IN_PROGRESS, - Timestamp: new Date(TIMESTAMP), - ResourceType: 'AWS::CloudFormation::Stack', - StackId: '', - EventId: '', - StackName: 'stack-name', - }, - parentStackLogicalIds: [], - }); - }); + monitor = await new StackActivityMonitor({ + cfn: sdk.cloudFormation(), + ioHost, + action: 'deploy', + stack: testStack({ + stackName: 'StackName', + }), + stackName: 'StackName', + changeSetCreationTime: new Date(T100), + pollingInterval: 0, + }).start(); - expect(output[0].trim()).toStrictEqual( - `stack-name | 0/4 | ${HUMAN_TIME} | ${chalk.reset('CREATE_IN_PROGRESS ')} | AWS::CloudFormation::Stack | ${chalk.reset(chalk.bold('stack1'))}`, - ); + restoreSdkMocksToDefault(); }); -test('prints 1/4 progress report, when addActivity is called with an "UPDATE_COMPLETE" ResourceStatus', () => { - const historyActivityPrinter = new HistoryActivityPrinter({ - resourceTypeColumnWidth: 23, - resourcesTotal: 3, - stream: process.stderr, - }); - - const output = stderr.inspectSync(() => { - historyActivityPrinter.addActivity({ - event: { - LogicalResourceId: 'stack1', - ResourceStatus: ResourceStatus.UPDATE_COMPLETE, - Timestamp: new Date(TIMESTAMP), - ResourceType: 'AWS::CloudFormation::Stack', - StackId: '', - EventId: '', - StackName: 'stack-name', - }, - parentStackLogicalIds: [], +describe('stack monitor event ordering and pagination', () => { + test('continue to the next page if it exists', async () => { + mockCloudFormationClient.on(DescribeStackEventsCommand).resolvesOnce({ + StackEvents: [event(102), event(101)], }); - }); - expect(output[0].trim()).toStrictEqual( - `stack-name | 1/4 | ${HUMAN_TIME} | ${chalk.green('UPDATE_COMPLETE ')} | AWS::CloudFormation::Stack | ${chalk.green(chalk.bold('stack1'))}`, - ); -}); + await eventually(() => expect(mockCloudFormationClient).toHaveReceivedCommand(DescribeStackEventsCommand), 2); + await monitor.stop(); -test('prints 1/4 progress report, when addActivity is called with an "UPDATE_COMPLETE" ResourceStatus', () => { - const historyActivityPrinter = new HistoryActivityPrinter({ - resourceTypeColumnWidth: 23, - resourcesTotal: 3, - stream: process.stderr, + // Printer sees them in chronological order + expect(ioHost.notify).toHaveBeenCalledTimes(4); + expect(ioHost.notify).toHaveBeenNthCalledWith(1, expectStart()); + expect(ioHost.notify).toHaveBeenNthCalledWith(2, expectEvent(101)); + expect(ioHost.notify).toHaveBeenNthCalledWith(3, expectEvent(102)); + expect(ioHost.notify).toHaveBeenNthCalledWith(4, expectStop()); + }); - const output = stderr.inspectSync(() => { - historyActivityPrinter.addActivity({ - event: { - LogicalResourceId: 'stack1', - ResourceStatus: ResourceStatus.UPDATE_COMPLETE, - Timestamp: new Date(TIMESTAMP), - ResourceType: 'AWS::CloudFormation::Stack', - StackId: '', - EventId: '', - StackName: 'stack-name', - }, - parentStackLogicalIds: [], - }); - }); + test('do not page further if we already saw the last event', async () => { + mockCloudFormationClient + .on(DescribeStackEventsCommand) + .resolvesOnce({ + StackEvents: [event(101)], + }) + .resolvesOnce({ + StackEvents: [event(102), event(101)], + }) + .resolvesOnce({}); - expect(output[0].trim()).toStrictEqual( - `stack-name | 1/4 | ${HUMAN_TIME} | ${chalk.green('UPDATE_COMPLETE ')} | AWS::CloudFormation::Stack | ${chalk.green(chalk.bold('stack1'))}`, - ); -}); + await eventually(() => expect(mockCloudFormationClient).toHaveReceivedCommand(DescribeStackEventsCommand), 2); + await monitor.stop(); -test('prints 1/4 progress report, when addActivity is called with an "ROLLBACK_COMPLETE" ResourceStatus', () => { - const historyActivityPrinter = new HistoryActivityPrinter({ - resourceTypeColumnWidth: 23, - resourcesTotal: 3, - stream: process.stderr, + // Seen in chronological order + expect(ioHost.notify).toHaveBeenCalledTimes(4); + expect(ioHost.notify).toHaveBeenNthCalledWith(1, expectStart()); + expect(ioHost.notify).toHaveBeenNthCalledWith(2, expectEvent(101)); + expect(ioHost.notify).toHaveBeenNthCalledWith(3, expectEvent(102)); + expect(ioHost.notify).toHaveBeenNthCalledWith(4, expectStop()); }); - const output = stderr.inspectSync(() => { - historyActivityPrinter.addActivity({ - event: { - LogicalResourceId: 'stack1', - ResourceStatus: ResourceStatus.ROLLBACK_COMPLETE, - Timestamp: new Date(TIMESTAMP), - ResourceType: 'AWS::CloudFormation::Stack', - StackId: '', - EventId: '', - StackName: 'stack-name', - }, - parentStackLogicalIds: [], - }); - }); + test('do not page further if the last event is too old', async () => { + mockCloudFormationClient + .on(DescribeStackEventsCommand) + .resolvesOnce({ + StackEvents: [event(101), event(95)], + }) + .resolvesOnce({ + StackEvents: [], + }); - expect(output[0].trim()).toStrictEqual( - `stack-name | 1/4 | ${HUMAN_TIME} | ${chalk.yellow('ROLLBACK_COMPLETE ')} | AWS::CloudFormation::Stack | ${chalk.yellow(chalk.bold('stack1'))}`, - ); -}); + await eventually(() => expect(mockCloudFormationClient).toHaveReceivedCommand(DescribeStackEventsCommand), 2); + await monitor.stop(); -test('prints 0/4 progress report, when addActivity is called with an "UPDATE_FAILED" ResourceStatus', () => { - const historyActivityPrinter = new HistoryActivityPrinter({ - resourceTypeColumnWidth: 23, - resourcesTotal: 3, - stream: process.stderr, + // Seen only the new one + expect(ioHost.notify).toHaveBeenCalledTimes(3); + expect(ioHost.notify).toHaveBeenNthCalledWith(1, expectStart()); + expect(ioHost.notify).toHaveBeenNthCalledWith(2, expectEvent(101)); + expect(ioHost.notify).toHaveBeenNthCalledWith(3, expectStop()); }); - const output = stderr.inspectSync(() => { - historyActivityPrinter.addActivity({ - event: { - LogicalResourceId: 'stack1', - ResourceStatus: ResourceStatus.UPDATE_FAILED, - Timestamp: new Date(TIMESTAMP), - ResourceType: 'AWS::CloudFormation::Stack', - StackId: '', - EventId: '', - StackName: 'stack-name', - }, - parentStackLogicalIds: [], + test('do a final request after the monitor is stopped', async () => { + mockCloudFormationClient.on(DescribeStackEventsCommand).resolves({ + StackEvents: [event(101)], + }); + // Establish that we've received events prior to stop and then reset the mock + await eventually(() => expect(mockCloudFormationClient).toHaveReceivedCommand(DescribeStackEventsCommand), 2); + mockCloudFormationClient.resetHistory(); + await monitor.stop(); + mockCloudFormationClient.on(DescribeStackEventsCommand).resolves({ + StackEvents: [event(102), event(101)], }); + // Since we can't reset the mock to a new value before calling stop, we'll have to check + // and make sure it's called again instead. + expect(mockCloudFormationClient).toHaveReceivedCommand(DescribeStackEventsCommand); }); - - expect(output[0].trim()).toStrictEqual( - `stack-name | 0/4 | ${HUMAN_TIME} | ${chalk.red('UPDATE_FAILED ')} | AWS::CloudFormation::Stack | ${chalk.red(chalk.bold('stack1'))}`, - ); }); -test('does not print "Failed Resources:" list, when all deployments are successful', () => { - const historyActivityPrinter = new HistoryActivityPrinter({ - resourceTypeColumnWidth: 23, - resourcesTotal: 1, - stream: process.stderr, - }); - - const output = stderr.inspectSync(() => { - historyActivityPrinter.addActivity({ - event: { - LogicalResourceId: 'stack1', - ResourceStatus: ResourceStatus.UPDATE_IN_PROGRESS, - Timestamp: new Date(TIMESTAMP), - ResourceType: 'AWS::CloudFormation::Stack', - StackId: '', - EventId: '', - StackName: 'stack-name', - }, - parentStackLogicalIds: [], - }); - historyActivityPrinter.addActivity({ - event: { - LogicalResourceId: 'stack1', - ResourceStatus: ResourceStatus.UPDATE_COMPLETE, - Timestamp: new Date(TIMESTAMP), - ResourceType: 'AWS::CloudFormation::Stack', - StackId: '', - EventId: '', - StackName: 'stack-name', - }, - parentStackLogicalIds: [], +describe('stack monitor, collecting errors from events', () => { + test('return errors from the root stack', async () => { + mockCloudFormationClient.on(DescribeStackEventsCommand).resolvesOnce({ + StackEvents: [addErrorToStackEvent(event(100))], }); - historyActivityPrinter.addActivity({ - event: { - LogicalResourceId: 'stack2', - ResourceStatus: ResourceStatus.UPDATE_COMPLETE, - Timestamp: new Date(TIMESTAMP), - ResourceType: 'AWS::CloudFormation::Stack', - StackId: '', - EventId: '', - StackName: 'stack-name', - }, - parentStackLogicalIds: [], - }); - historyActivityPrinter.stop(); + + await eventually(() => expect(mockCloudFormationClient).toHaveReceivedCommand(DescribeStackEventsCommand), 2); + await monitor.stop(); + expect(monitor.errors).toStrictEqual(['Test Error']); }); - expect(output.length).toStrictEqual(3); - expect(output[0].trim()).toStrictEqual( - `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} | ${chalk.green('UPDATE_COMPLETE ')} | AWS::CloudFormation::Stack | ${chalk.green(chalk.bold('stack1'))}`, - ); - expect(output[2].trim()).toStrictEqual( - `stack-name | 2/2 | ${HUMAN_TIME} | ${chalk.green('UPDATE_COMPLETE ')} | AWS::CloudFormation::Stack | ${chalk.green(chalk.bold('stack2'))}`, - ); -}); + test('return errors from the nested stack', async () => { + mockCloudFormationClient + .on(DescribeStackEventsCommand) + .resolvesOnce({ + StackEvents: [ + addErrorToStackEvent(event(102), { + logicalResourceId: 'nestedStackLogicalResourceId', + physicalResourceId: 'nestedStackPhysicalResourceId', + resourceType: 'AWS::CloudFormation::Stack', + resourceStatusReason: 'nested stack failed', + resourceStatus: ResourceStatus.UPDATE_FAILED, + }), + addErrorToStackEvent(event(100), { + logicalResourceId: 'nestedStackLogicalResourceId', + physicalResourceId: 'nestedStackPhysicalResourceId', + resourceType: 'AWS::CloudFormation::Stack', + resourceStatus: ResourceStatus.UPDATE_IN_PROGRESS, + }), + ], + }) + .resolvesOnce({ + StackEvents: [ + addErrorToStackEvent(event(101), { + logicalResourceId: 'nestedResource', + resourceType: 'Some::Nested::Resource', + resourceStatusReason: 'actual failure error message', + }), + ], + }); -test('prints "Failed Resources:" list, when at least one deployment fails', () => { - const historyActivityPrinter = new HistoryActivityPrinter({ - resourceTypeColumnWidth: 23, - resourcesTotal: 1, - stream: process.stderr, + await eventually( + () => + expect(mockCloudFormationClient).toHaveReceivedNthCommandWith(1, DescribeStackEventsCommand, { + StackName: 'StackName', + }), + 2, + ); + + await eventually( + () => + expect(mockCloudFormationClient).toHaveReceivedNthCommandWith(2, DescribeStackEventsCommand, { + StackName: 'nestedStackPhysicalResourceId', + }), + 2, + ); + await monitor.stop(); + expect(monitor.errors).toStrictEqual(['actual failure error message', 'nested stack failed']); }); - const output = stderr.inspectSync(() => { - historyActivityPrinter.addActivity({ - event: { - LogicalResourceId: 'stack1', - ResourceStatus: ResourceStatus.UPDATE_IN_PROGRESS, - Timestamp: new Date(TIMESTAMP), - ResourceType: 'AWS::CloudFormation::Stack', - StackId: '', - EventId: '', - StackName: 'stack-name', - }, - parentStackLogicalIds: [], + test('does not consider events without physical resource id for monitoring nested stacks', async () => { + mockCloudFormationClient + .on(DescribeStackEventsCommand) + .resolvesOnce({ + StackEvents: [ + addErrorToStackEvent(event(100), { + logicalResourceId: 'nestedStackLogicalResourceId', + physicalResourceId: '', + resourceType: 'AWS::CloudFormation::Stack', + resourceStatusReason: 'nested stack failed', + }), + ], + NextToken: 'nextToken', + }) + .resolvesOnce({ + StackEvents: [ + addErrorToStackEvent(event(101), { + logicalResourceId: 'OtherResource', + resourceType: 'Some::Other::Resource', + resourceStatusReason: 'some failure', + }), + ], + }); + + await eventually(() => expect(mockCloudFormationClient).toHaveReceivedCommand(DescribeStackEventsCommand), 2); + await monitor.stop(); + + expect(monitor.errors).toStrictEqual(['nested stack failed', 'some failure']); + expect(mockCloudFormationClient).toHaveReceivedNthCommandWith(1, DescribeStackEventsCommand, { + StackName: 'StackName', }); - historyActivityPrinter.addActivity({ - event: { - LogicalResourceId: 'stack1', - ResourceStatus: ResourceStatus.UPDATE_FAILED, - Timestamp: new Date(TIMESTAMP), - ResourceType: 'AWS::CloudFormation::Stack', - StackId: '', - EventId: '', - StackName: 'stack-name', - }, - parentStackLogicalIds: [], + // Note that the second call happened for the top level stack instead of a nested stack + expect(mockCloudFormationClient).toHaveReceivedNthCommandWith(2, DescribeStackEventsCommand, { + StackName: 'StackName', }); - historyActivityPrinter.stop(); }); - expect(output.length).toStrictEqual(4); - expect(output[0].trim()).toStrictEqual( - `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} | ${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} | ${chalk.red('UPDATE_FAILED ')} | AWS::CloudFormation::Stack | ${chalk.red(chalk.bold('stack1'))}`, - ); -}); + test('does not check for nested stacks that have already completed successfully', async () => { + mockCloudFormationClient.on(DescribeStackEventsCommand).resolvesOnce({ + StackEvents: [ + addErrorToStackEvent(event(100), { + logicalResourceId: 'nestedStackLogicalResourceId', + physicalResourceId: 'nestedStackPhysicalResourceId', + resourceType: 'AWS::CloudFormation::Stack', + resourceStatusReason: 'nested stack status reason', + resourceStatus: StackStatus.CREATE_COMPLETE, + }), + ], + }); -test('print failed resources because of hook failures', () => { - const historyActivityPrinter = new HistoryActivityPrinter({ - resourceTypeColumnWidth: 23, - resourcesTotal: 1, - stream: process.stderr, - }); + await eventually(() => expect(mockCloudFormationClient).toHaveReceivedCommand(DescribeStackEventsCommand), 2); + await monitor.stop(); - const output = stderr.inspectSync(() => { - historyActivityPrinter.addActivity({ - event: { - LogicalResourceId: 'stack1', - ResourceStatus: ResourceStatus.UPDATE_IN_PROGRESS, - Timestamp: new Date(TIMESTAMP), - ResourceType: 'AWS::CloudFormation::Stack', - StackId: '', - EventId: '', - StackName: 'stack-name', - HookStatus: 'HOOK_COMPLETE_FAILED', - HookType: 'hook1', - HookStatusReason: 'stack1 must obey certain rules', - }, - parentStackLogicalIds: [], - }); - historyActivityPrinter.addActivity({ - event: { - LogicalResourceId: 'stack1', - ResourceStatus: ResourceStatus.UPDATE_FAILED, - Timestamp: new Date(TIMESTAMP), - ResourceType: 'AWS::CloudFormation::Stack', - StackId: '', - EventId: '', - StackName: 'stack-name', - ResourceStatusReason: 'The following hook(s) failed: hook1', - }, - parentStackLogicalIds: [], - }); - historyActivityPrinter.stop(); + expect(monitor.errors).toStrictEqual([]); }); +}); + +const T0 = 1597837230504; + +// Events 0-99 are before we started paying attention +const T100 = T0 + 100 * 1000; + +function event(nr: number): StackEvent { + return { + EventId: `${nr}`, + StackId: 'StackId', + StackName: 'StackName', + Timestamp: new Date(T0 + nr * 1000), + }; +} + +function addErrorToStackEvent( + eventToUpdate: StackEvent, + props: { + resourceStatus?: ResourceStatus; + resourceType?: string; + resourceStatusReason?: string; + logicalResourceId?: string; + physicalResourceId?: string; + } = {}, +): StackEvent { + eventToUpdate.ResourceStatus = props.resourceStatus ?? ResourceStatus.UPDATE_FAILED; + eventToUpdate.ResourceType = props.resourceType ?? 'Test::Resource::Type'; + eventToUpdate.ResourceStatusReason = props.resourceStatusReason ?? 'Test Error'; + eventToUpdate.LogicalResourceId = props.logicalResourceId ?? 'testLogicalId'; + eventToUpdate.PhysicalResourceId = props.physicalResourceId ?? 'testPhysicalResourceId'; + return eventToUpdate; +} + +const wait = (): Promise => new Promise((resolve) => setTimeout(resolve, 5)); + +// Using the eventually function to ensure these functions have had sufficient time to execute. +const eventually = async (call: () => void, attempts: number): Promise => { + while (attempts-- >= 0) { + try { + return call(); + } catch (err) { + if (attempts <= 0) throw err; + } + await wait(); + } + + throw new Error('An unexpected error has occurred.'); +}; - expect(output.length).toStrictEqual(4); - expect(output[0].trim()).toStrictEqual( - `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} | ${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} | ${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'))}`, - ); +const expectStart = () => expect.objectContaining({ code: 'CDK_TOOLKIT_I5501' }); +const expectStop = () => expect.objectContaining({ code: 'CDK_TOOLKIT_I5503' }); +const expectEvent = (id: number) => expect.objectContaining({ + code: 'CDK_TOOLKIT_I5502', + data: expect.objectContaining({ + event: expect.objectContaining({ 'EventId': String(id) }) + }) }); diff --git a/packages/aws-cdk/test/api/stack-events/stack-monitor.test.ts b/packages/aws-cdk/test/api/stack-events/stack-monitor.test.ts deleted file mode 100644 index 50a8ab4d..00000000 --- a/packages/aws-cdk/test/api/stack-events/stack-monitor.test.ts +++ /dev/null @@ -1,271 +0,0 @@ -import { - DescribeStackEventsCommand, - ResourceStatus, - type StackEvent, - StackStatus, -} from '@aws-sdk/client-cloudformation'; -import { MockSdk, mockCloudFormationClient, restoreSdkMocksToDefault } from '../../util/mock-sdk'; -import { - StackActivityMonitor, - type IActivityPrinter, - type StackActivity, -} from '../../../lib/api/stack-events'; - -let sdk: MockSdk; -let printer: FakePrinter; -let monitor: StackActivityMonitor; -beforeEach(() => { - sdk = new MockSdk(); - - printer = new FakePrinter(); - monitor = new StackActivityMonitor(sdk.cloudFormation(), 'StackName', printer, undefined, new Date(T100)).start(); - - restoreSdkMocksToDefault(); -}); - -describe('stack monitor event ordering and pagination', () => { - test('continue to the next page if it exists', async () => { - mockCloudFormationClient.on(DescribeStackEventsCommand).resolvesOnce({ - StackEvents: [event(102), event(101)], - }); - - await eventually(() => expect(mockCloudFormationClient).toHaveReceivedCommand(DescribeStackEventsCommand), 2); - await monitor.stop(); - - // Printer sees them in chronological order - expect(printer.eventIds).toEqual(['101', '102']); - }); - - test('do not page further if we already saw the last event', async () => { - mockCloudFormationClient - .on(DescribeStackEventsCommand) - .resolvesOnce({ - StackEvents: [event(101)], - }) - .resolvesOnce({ - StackEvents: [event(102), event(101)], - }) - .resolvesOnce({}); - - await eventually(() => expect(mockCloudFormationClient).toHaveReceivedCommand(DescribeStackEventsCommand), 2); - await monitor.stop(); - - // Seen in chronological order - expect(printer.eventIds).toEqual(['101', '102']); - }); - - test('do not page further if the last event is too old', async () => { - mockCloudFormationClient - .on(DescribeStackEventsCommand) - .resolvesOnce({ - StackEvents: [event(101), event(95)], - }) - .resolvesOnce({ - StackEvents: [], - }); - - await eventually(() => expect(mockCloudFormationClient).toHaveReceivedCommand(DescribeStackEventsCommand), 2); - await monitor.stop(); - - // Seen only the new one - expect(printer.eventIds).toEqual(['101']); - }); - - test('do a final request after the monitor is stopped', async () => { - mockCloudFormationClient.on(DescribeStackEventsCommand).resolves({ - StackEvents: [event(101)], - }); - // Establish that we've received events prior to stop and then reset the mock - await eventually(() => expect(mockCloudFormationClient).toHaveReceivedCommand(DescribeStackEventsCommand), 2); - mockCloudFormationClient.resetHistory(); - await monitor.stop(); - mockCloudFormationClient.on(DescribeStackEventsCommand).resolves({ - StackEvents: [event(102), event(101)], - }); - // Since we can't reset the mock to a new value before calling stop, we'll have to check - // and make sure it's called again instead. - expect(mockCloudFormationClient).toHaveReceivedCommand(DescribeStackEventsCommand); - }); -}); - -describe('stack monitor, collecting errors from events', () => { - test('return errors from the root stack', async () => { - mockCloudFormationClient.on(DescribeStackEventsCommand).resolvesOnce({ - StackEvents: [addErrorToStackEvent(event(100))], - }); - - await eventually(() => expect(mockCloudFormationClient).toHaveReceivedCommand(DescribeStackEventsCommand), 2); - await monitor.stop(); - expect(monitor.errors).toStrictEqual(['Test Error']); - }); - - test('return errors from the nested stack', async () => { - mockCloudFormationClient - .on(DescribeStackEventsCommand) - .resolvesOnce({ - StackEvents: [ - addErrorToStackEvent(event(102), { - logicalResourceId: 'nestedStackLogicalResourceId', - physicalResourceId: 'nestedStackPhysicalResourceId', - resourceType: 'AWS::CloudFormation::Stack', - resourceStatusReason: 'nested stack failed', - resourceStatus: ResourceStatus.UPDATE_FAILED, - }), - addErrorToStackEvent(event(100), { - logicalResourceId: 'nestedStackLogicalResourceId', - physicalResourceId: 'nestedStackPhysicalResourceId', - resourceType: 'AWS::CloudFormation::Stack', - resourceStatus: ResourceStatus.UPDATE_IN_PROGRESS, - }), - ], - }) - .resolvesOnce({ - StackEvents: [ - addErrorToStackEvent(event(101), { - logicalResourceId: 'nestedResource', - resourceType: 'Some::Nested::Resource', - resourceStatusReason: 'actual failure error message', - }), - ], - }); - - await eventually( - () => - expect(mockCloudFormationClient).toHaveReceivedNthCommandWith(1, DescribeStackEventsCommand, { - StackName: 'StackName', - }), - 2, - ); - - await eventually( - () => - expect(mockCloudFormationClient).toHaveReceivedNthCommandWith(2, DescribeStackEventsCommand, { - StackName: 'nestedStackPhysicalResourceId', - }), - 2, - ); - await monitor.stop(); - expect(monitor.errors).toStrictEqual(['actual failure error message', 'nested stack failed']); - }); - - test('does not consider events without physical resource id for monitoring nested stacks', async () => { - mockCloudFormationClient - .on(DescribeStackEventsCommand) - .resolvesOnce({ - StackEvents: [ - addErrorToStackEvent(event(100), { - logicalResourceId: 'nestedStackLogicalResourceId', - physicalResourceId: '', - resourceType: 'AWS::CloudFormation::Stack', - resourceStatusReason: 'nested stack failed', - }), - ], - NextToken: 'nextToken', - }) - .resolvesOnce({ - StackEvents: [ - addErrorToStackEvent(event(101), { - logicalResourceId: 'OtherResource', - resourceType: 'Some::Other::Resource', - resourceStatusReason: 'some failure', - }), - ], - }); - - await eventually(() => expect(mockCloudFormationClient).toHaveReceivedCommand(DescribeStackEventsCommand), 2); - await monitor.stop(); - - expect(monitor.errors).toStrictEqual(['nested stack failed', 'some failure']); - expect(mockCloudFormationClient).toHaveReceivedNthCommandWith(1, DescribeStackEventsCommand, { - StackName: 'StackName', - }); - // Note that the second call happened for the top level stack instead of a nested stack - expect(mockCloudFormationClient).toHaveReceivedNthCommandWith(2, DescribeStackEventsCommand, { - StackName: 'StackName', - }); - }); - - test('does not check for nested stacks that have already completed successfully', async () => { - mockCloudFormationClient.on(DescribeStackEventsCommand).resolvesOnce({ - StackEvents: [ - addErrorToStackEvent(event(100), { - logicalResourceId: 'nestedStackLogicalResourceId', - physicalResourceId: 'nestedStackPhysicalResourceId', - resourceType: 'AWS::CloudFormation::Stack', - resourceStatusReason: 'nested stack status reason', - resourceStatus: StackStatus.CREATE_COMPLETE, - }), - ], - }); - - await eventually(() => expect(mockCloudFormationClient).toHaveReceivedCommand(DescribeStackEventsCommand), 2); - await monitor.stop(); - - expect(monitor.errors).toStrictEqual([]); - }); -}); - -const T0 = 1597837230504; - -// Events 0-99 are before we started paying attention -const T100 = T0 + 100 * 1000; - -function event(nr: number): StackEvent { - return { - EventId: `${nr}`, - StackId: 'StackId', - StackName: 'StackName', - Timestamp: new Date(T0 + nr * 1000), - }; -} - -function addErrorToStackEvent( - eventToUpdate: StackEvent, - props: { - resourceStatus?: ResourceStatus; - resourceType?: string; - resourceStatusReason?: string; - logicalResourceId?: string; - physicalResourceId?: string; - } = {}, -): StackEvent { - eventToUpdate.ResourceStatus = props.resourceStatus ?? ResourceStatus.UPDATE_FAILED; - eventToUpdate.ResourceType = props.resourceType ?? 'Test::Resource::Type'; - eventToUpdate.ResourceStatusReason = props.resourceStatusReason ?? 'Test Error'; - eventToUpdate.LogicalResourceId = props.logicalResourceId ?? 'testLogicalId'; - eventToUpdate.PhysicalResourceId = props.physicalResourceId ?? 'testPhysicalResourceId'; - return eventToUpdate; -} - -class FakePrinter implements IActivityPrinter { - public updateSleep: number = 0; - public readonly activities: StackActivity[] = []; - - public get eventIds() { - return this.activities.map((a) => a.event.EventId); - } - - public addActivity(activity: StackActivity): void { - this.activities.push(activity); - } - - public print(): void {} - public start(): void {} - public stop(): void {} -} - -const wait = (): Promise => new Promise((resolve) => setTimeout(resolve, 5)); - -// Using the eventually function to ensure these functions have had sufficient time to execute. -const eventually = async (call: () => void, attempts: number): Promise => { - while (attempts-- >= 0) { - try { - return call(); - } catch (err) { - if (attempts <= 0) throw err; - } - await wait(); - } - - throw new Error('An unexpected error has occurred.'); -}; diff --git a/packages/aws-cdk/test/api/_helpers/console-listener.ts b/packages/aws-cdk/test/cli/_helpers/console-listener.ts similarity index 86% rename from packages/aws-cdk/test/api/_helpers/console-listener.ts rename to packages/aws-cdk/test/cli/_helpers/console-listener.ts index 25d4948b..64f97f85 100644 --- a/packages/aws-cdk/test/api/_helpers/console-listener.ts +++ b/packages/aws-cdk/test/cli/_helpers/console-listener.ts @@ -59,6 +59,16 @@ class ConsoleListener { } return inspect.output; } + + async inspectAwait(fn: (output: Output) => void): Promise { + const inspect = this.inspect(); + try { + await fn(inspect.output); + } finally { + inspect.restore(); + } + return inspect.output; + } } export const stdout = new ConsoleListener(process.stdout); diff --git a/packages/aws-cdk/test/api/stack-events/display.test.ts b/packages/aws-cdk/test/cli/activity-monitor/display.test.ts similarity index 96% rename from packages/aws-cdk/test/api/stack-events/display.test.ts rename to packages/aws-cdk/test/cli/activity-monitor/display.test.ts index 9bd375e4..7dd67f49 100644 --- a/packages/aws-cdk/test/api/stack-events/display.test.ts +++ b/packages/aws-cdk/test/cli/activity-monitor/display.test.ts @@ -1,5 +1,5 @@ /* eslint-disable import/order */ -import { RewritableBlock } from '../../../lib/api/stack-events/display'; +import { RewritableBlock } from '../../../lib/cli/activity-printer/display'; import { stderr } from '../_helpers/console-listener'; describe('Rewritable Block Tests', () => { diff --git a/packages/aws-cdk/test/cli/activity-monitor/history.test.ts b/packages/aws-cdk/test/cli/activity-monitor/history.test.ts new file mode 100644 index 00000000..fe2242cd --- /dev/null +++ b/packages/aws-cdk/test/cli/activity-monitor/history.test.ts @@ -0,0 +1,166 @@ +import { ResourceStatus } from "@aws-sdk/client-cloudformation"; +import { HistoryActivityPrinter } from "../../../lib/cli/activity-printer"; +import { CliIoHost } from "../../../lib/toolkit/cli-io-host"; +import { testStack } from "../../util"; +import { stderr } from "../_helpers/console-listener"; +import * as chalk from 'chalk'; + +let TIMESTAMP: number; +let HUMAN_TIME: string; + +beforeAll(() => { + TIMESTAMP = new Date().getTime(); + HUMAN_TIME = new Date(TIMESTAMP).toLocaleTimeString(); + CliIoHost.instance().isCI = false; +}); + +test('prints "IN_PROGRESS" ResourceStatus', async () => { + const historyActivityPrinter = new HistoryActivityPrinter({ + stream: process.stderr, + }); + + const output = await stderr.inspectAwait(async () => { + historyActivityPrinter.start({ stack: testStack({ stackName: 'stack-name' }) }); + historyActivityPrinter.addActivity({ + event: { + LogicalResourceId: 'stack1', + ResourceStatus: ResourceStatus.CREATE_IN_PROGRESS, + Timestamp: new Date(TIMESTAMP), + ResourceType: 'AWS::CloudFormation::Stack', + StackId: '', + EventId: '', + StackName: 'stack-name', + }, + deployment: "test", + progress: { + completed: 0, + total: 2, + formatted: "0/4" + } + }); + await historyActivityPrinter.stop(); + }); + + expect(output[0].trim()).toStrictEqual( + `stack-name | 0/4 | ${HUMAN_TIME} | ${chalk.reset('CREATE_IN_PROGRESS ')} | AWS::CloudFormation::Stack | ${chalk.reset(chalk.bold('stack1'))}`, + ); +}); + + +test('prints "Failed Resources:" list, when at least one deployment fails', async () => { + const historyActivityPrinter = new HistoryActivityPrinter({ + stream: process.stderr, + }); + + const output = await stderr.inspectAwait(async () => { + historyActivityPrinter.start({ stack: testStack({ stackName: 'stack-name' }) }); + historyActivityPrinter.addActivity({ + event: { + LogicalResourceId: 'stack1', + ResourceStatus: ResourceStatus.UPDATE_IN_PROGRESS, + Timestamp: new Date(TIMESTAMP), + ResourceType: 'AWS::CloudFormation::Stack', + StackId: '', + EventId: '', + StackName: 'stack-name', + }, + deployment: "test", + progress: { + completed: 0, + total: 2, + formatted: "0/2" + } + }); + historyActivityPrinter.addActivity({ + event: { + LogicalResourceId: 'stack1', + ResourceStatus: ResourceStatus.UPDATE_FAILED, + Timestamp: new Date(TIMESTAMP), + ResourceType: 'AWS::CloudFormation::Stack', + StackId: '', + EventId: '', + StackName: 'stack-name', + }, + deployment: "test", + progress: { + completed: 0, + total: 2, + formatted: "0/2" + } + }); + await historyActivityPrinter.stop(); + }); + + expect(output.length).toStrictEqual(4); + expect(output[0].trim()).toStrictEqual( + `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} | ${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} | ${chalk.red('UPDATE_FAILED ')} | AWS::CloudFormation::Stack | ${chalk.red(chalk.bold('stack1'))}`, + ); +}); + +test('print failed resources because of hook failures', async () => { + const historyActivityPrinter = new HistoryActivityPrinter({ + stream: process.stderr, + }); + + const output = await stderr.inspectAwait(async () => { + historyActivityPrinter.start({ stack: testStack({ stackName: 'stack-name' }) }); + historyActivityPrinter.addActivity({ + event: { + LogicalResourceId: 'stack1', + ResourceStatus: ResourceStatus.UPDATE_IN_PROGRESS, + Timestamp: new Date(TIMESTAMP), + ResourceType: 'AWS::CloudFormation::Stack', + StackId: '', + EventId: '', + StackName: 'stack-name', + HookStatus: 'HOOK_COMPLETE_FAILED', + HookType: 'hook1', + HookStatusReason: 'stack1 must obey certain rules', + }, + deployment: "test", + progress: { + completed: 0, + total: 2, + formatted: "0/2" + } + }); + historyActivityPrinter.addActivity({ + event: { + LogicalResourceId: 'stack1', + ResourceStatus: ResourceStatus.UPDATE_FAILED, + Timestamp: new Date(TIMESTAMP), + ResourceType: 'AWS::CloudFormation::Stack', + StackId: '', + EventId: '', + StackName: 'stack-name', + ResourceStatusReason: 'The following hook(s) failed: hook1', + }, + deployment: "test", + progress: { + completed: 0, + total: 2, + formatted: "0/2" + } + }); + await historyActivityPrinter.stop(); + }); + + expect(output.length).toStrictEqual(4); + expect(output[0].trim()).toStrictEqual( + `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} | ${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} | ${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'))}`, + ); +});