Skip to content

chore(toolkit): consistent durations and error codes #33287

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 2 commits into from
Feb 4, 2025
Merged

chore(toolkit): consistent durations and error codes #33287

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
c50edfe
chore(toolkit): consistent times and error codes
mrgrain Feb 4, 2025
1bed8ce
Merge branch 'main' into mrgrain/chore/toolkit/emit-more-times
mrgrain Feb 4, 2025
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
27 changes: 17 additions & 10 deletions packages/@aws-cdk/toolkit/lib/api/io/private/codes.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,20 +1,27 @@
import { IoMessageCode } from '../io-message';

export const CODES = {
// Toolkit Info codes
CDK_TOOLKIT_I0001: 'Display stack data',
CDK_TOOLKIT_I0002: 'Successfully deployed stacks',
CDK_TOOLKIT_I3001: 'Informs about any log groups that are traced as part of the deployment',
CDK_TOOLKIT_I5001: 'Display synthesis times',
CDK_TOOLKIT_I5050: 'Confirm rollback',
// Synth
CDK_TOOLKIT_I1000: 'Provides synthesis times',
CDK_TOOLKIT_I1901: 'Provides stack data',
CDK_TOOLKIT_I1902: 'Successfully deployed stacks',
Comment on lines +4 to +7
Copy link
Contributor

@kaizencc kaizencc Feb 4, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is there a way to codify these rules, i.e. that Synth messages must start with 1XXX, better than the honor system we're employing right now?

Copy link
Contributor Author

@mrgrain mrgrain Feb 4, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't really know how to unfortunately.

Copy link
Contributor

@kaizencc kaizencc Feb 4, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Fair. I thought about it some and I couldn't think of anything reasonable without supplying additional information into the record set similar to how lambda runtimes work. i.e. static readonly CDK_TOOLKIT_I1000 = new Code('synth', 'Provides synthesis times')

But i think its not worth investigating further so i'm approving.


// Deploy
CDK_TOOLKIT_I5000: 'Provides deployment times',
CDK_TOOLKIT_I5001: 'Provides total time in deploy action, including synth and rollback',
CDK_TOOLKIT_I5031: 'Informs about any log groups that are traced as part of the deployment',
CDK_TOOLKIT_I5050: 'Confirm rollback during deployment',
CDK_TOOLKIT_I5060: 'Confirm deploy security sensitive changes',
CDK_TOOLKIT_I7010: 'Confirm destroy stacks',
CDK_TOOLKIT_I5900: 'Deployment results on success',

// Toolkit Warning codes
// Rollback
CDK_TOOLKIT_I6000: 'Provides rollback times',

// Toolkit Error codes
// Destroy
CDK_TOOLKIT_I7000: 'Provides destroy times',
CDK_TOOLKIT_I7010: 'Confirm destroy stacks',

// Assembly Info codes
// Assembly codes
CDK_ASSEMBLY_I0042: 'Writing updated context',
CDK_ASSEMBLY_I0241: 'Fetching missing context',
CDK_ASSEMBLY_I1000: 'Cloud assembly output starts',
Expand Down
30 changes: 30 additions & 0 deletions packages/@aws-cdk/toolkit/lib/api/io/private/timer.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,3 +1,6 @@
import { VALID_CODE } from './codes';
import { info } from './messages';
import { ActionAwareIoHost } from './types';
import { formatTime } from '../../aws-cdk';

/**
Expand Down Expand Up @@ -29,4 +32,31 @@ export class Timer {
asSec: formatTime(elapsedTime),
};
}

/**
* Ends the current timer as a specified timing and notifies the IoHost.
* @returns the elapsed time
*/
public async endAs(ioHost: ActionAwareIoHost, type: 'synth' | 'deploy' | 'rollback' | 'destroy') {
const duration = this.end();
const { code, text } = timerMessageProps(type);

await ioHost.notify(info(`\n✨ ${text} time: ${duration.asSec}s\n`, code, {
duration: duration.asMs,
}));

return duration;
}
}

function timerMessageProps(type: 'synth' | 'deploy' | 'rollback'| 'destroy'): {
code: VALID_CODE;
text: string;
} {
switch (type) {
case 'synth': return { code: 'CDK_TOOLKIT_I1000', text: 'Synthesis' };
case 'deploy': return { code: 'CDK_TOOLKIT_I5000', text: 'Deployment' };
case 'rollback': return { code: 'CDK_TOOLKIT_I6000', text: 'Rollback' };
case 'destroy': return { code: 'CDK_TOOLKIT_I7000', text: 'Destroy' };
}
}
96 changes: 46 additions & 50 deletions packages/@aws-cdk/toolkit/lib/toolkit/toolkit.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -14,7 +14,7 @@ import { type RollbackOptions } from '../actions/rollback';
import { type SynthOptions } from '../actions/synth';
import { patternsArrayForWatch, WatchOptions } from '../actions/watch';
import { type SdkOptions } 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 } from '../api/aws-cdk';
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 } from '../api/aws-cdk';
import { CachedCloudAssemblySource, IdentityCloudAssemblySource, StackAssembly, ICloudAssemblySource, StackSelectionStrategy } from '../api/cloud-assembly';
import { ALL_STACKS, CloudAssemblySourceBuilder } from '../api/cloud-assembly/private';
import { ToolkitError } from '../api/errors';
Expand Down Expand Up @@ -158,10 +158,12 @@ export class Toolkit extends CloudAssemblySourceBuilder implements AsyncDisposab
*/
public async synth(cx: ICloudAssemblySource, options: SynthOptions = {}): Promise<ICloudAssemblySource> {
const ioHost = withAction(this.ioHost, 'synth');
const synthTimer = Timer.start();
const assembly = await this.assemblyFromSource(cx);
const stacks = assembly.selectStacksV2(options.stacks ?? ALL_STACKS);
const autoValidateStacks = options.validateStacks ? [assembly.selectStacksForValidation()] : [];
await this.validateStacksMetadata(stacks.concat(...autoValidateStacks), ioHost);
await synthTimer.endAs(ioHost, 'synth');

// if we have a single stack, print it to STDOUT
const message = `Successfully synthesized to ${chalk.blue(path.resolve(stacks.assembly.directory))}`;
Expand All @@ -175,7 +177,7 @@ export class Toolkit extends CloudAssemblySourceBuilder implements AsyncDisposab
const firstStack = stacks.firstStack!;
const template = firstStack.template;
const obscuredTemplate = obscureTemplate(template);
await ioHost.notify(result(message, 'CDK_TOOLKIT_I0001', {
await ioHost.notify(result(message, 'CDK_TOOLKIT_I1901', {
...assemblyData,
stack: {
stackName: firstStack.stackName,
Expand All @@ -187,7 +189,7 @@ export class Toolkit extends CloudAssemblySourceBuilder implements AsyncDisposab
}));
} else {
// not outputting template to stdout, let's explain things to the user a little bit...
await ioHost.notify(result(chalk.green(message), 'CDK_TOOLKIT_I0002', assemblyData));
await ioHost.notify(result(chalk.green(message), 'CDK_TOOLKIT_I1902', assemblyData));
await ioHost.notify(info(`Supply a stack id (${stacks.stackArtifacts.map((s) => chalk.green(s.hierarchicalId)).join(', ')}) to display its template.`));
}

Expand Down Expand Up @@ -235,14 +237,10 @@ export class Toolkit extends CloudAssemblySourceBuilder implements AsyncDisposab
*/
private async _deploy(assembly: StackAssembly, action: 'deploy' | 'watch', options: ExtendedDeployOptions = {}) {
const ioHost = withAction(this.ioHost, action);
const timer = Timer.start();
const synthTimer = Timer.start();
const stackCollection = assembly.selectStacksV2(options.stacks ?? ALL_STACKS);
await this.validateStacksMetadata(stackCollection, ioHost);

const synthTime = timer.end();
await ioHost.notify(info(`\n✨ Synthesis time: ${synthTime.asSec}s\n`, 'CDK_TOOLKIT_I5001', {
time: synthTime.asMs,
}));
const synthDuration = await synthTimer.endAs(ioHost, 'synth');

if (stackCollection.stackCount === 0) {
await ioHost.notify(error('This app contains no stacks'));
Expand Down Expand Up @@ -352,14 +350,14 @@ export class Toolkit extends CloudAssemblySourceBuilder implements AsyncDisposab
await ioHost.notify(
info(`${chalk.bold(stack.displayName)}: deploying... [${stackIndex}/${stackCollection.stackCount}]`),
);
const startDeployTime = Timer.start();
const deployTimer = Timer.start();

let tags = options.tags;
if (!tags || tags.length === 0) {
tags = tagsForStack(stack);
}

let elapsedDeployTime;
let deployDuration;
try {
let deployResult: SuccessfulDeployStackResult | undefined;

Expand Down Expand Up @@ -405,7 +403,6 @@ export class Toolkit extends CloudAssemblySourceBuilder implements AsyncDisposab
if (options.force) {
await ioHost.notify(warn(`${motivation}. Rolling back first (--force).`));
} else {
// @todo reintroduce concurrency and corked logging in CliHost
const confirmed = await ioHost.requestResponse(confirm('CDK_TOOLKIT_I5050', question, motivation, true, concurrency));
if (!confirmed) { throw new ToolkitError('Aborted by user'); }
}
Expand All @@ -429,7 +426,6 @@ export class Toolkit extends CloudAssemblySourceBuilder implements AsyncDisposab
if (options.force) {
await ioHost.notify(warn(`${motivation}. Proceeding with regular deployment (--force).`));
} else {
// @todo reintroduce concurrency and corked logging in CliHost
const confirmed = await ioHost.requestResponse(confirm('CDK_TOOLKIT_I5050', question, motivation, true, concurrency));
if (!confirmed) { throw new ToolkitError('Aborted by user'); }
}
Expand All @@ -448,24 +444,20 @@ export class Toolkit extends CloudAssemblySourceBuilder implements AsyncDisposab
? ` ✅ ${stack.displayName} (no changes)`
: ` ✅ ${stack.displayName}`;

await ioHost.notify(success('\n' + message));
elapsedDeployTime = startDeployTime.end();
await ioHost.notify(info(`\n✨ Deployment time: ${elapsedDeployTime.asSec}s\n`));
await ioHost.notify(result(chalk.green('\n' + message), 'CDK_TOOLKIT_I5900', deployResult));
deployDuration = await deployTimer.endAs(ioHost, 'deploy');

if (Object.keys(deployResult.outputs).length > 0) {
await ioHost.notify(info('Outputs:'));

const buffer = ['Outputs:'];
stackOutputs[stack.stackName] = deployResult.outputs;
}

for (const name of Object.keys(deployResult.outputs).sort()) {
const value = deployResult.outputs[name];
await ioHost.notify(info(`${chalk.cyan(stack.id)}.${chalk.cyan(name)} = ${chalk.underline(chalk.cyan(value))}`));
for (const name of Object.keys(deployResult.outputs).sort()) {
const value = deployResult.outputs[name];
buffer.push(`${chalk.cyan(stack.id)}.${chalk.cyan(name)} = ${chalk.underline(chalk.cyan(value))}`);
}
await ioHost.notify(info(buffer.join('\n')));
}

await ioHost.notify(info('Stack ARN:'));

await ioHost.notify(info(deployResult.stackArn));
await ioHost.notify(info(`Stack ARN:\n${deployResult.stackArn}`));
} catch (e: any) {
// It has to be exactly this string because an integration test tests for
// "bold(stackname) failed: ResourceNotReady: <error>"
Expand All @@ -482,7 +474,7 @@ export class Toolkit extends CloudAssemblySourceBuilder implements AsyncDisposab
foundLogGroupsResult.sdk,
foundLogGroupsResult.logGroupNames,
);
await ioHost.notify(info(`The following log groups are added: ${foundLogGroupsResult.logGroupNames}`, 'CDK_TOOLKIT_I3001'));
await ioHost.notify(info(`The following log groups are added: ${foundLogGroupsResult.logGroupNames}`, 'CDK_TOOLKIT_I5031'));
}

// If an outputs file has been specified, create the file path and write stack outputs to it once.
Expand All @@ -496,7 +488,8 @@ export class Toolkit extends CloudAssemblySourceBuilder implements AsyncDisposab
});
}
}
await ioHost.notify(info(`\n✨ Total time: ${synthTime.asSec + elapsedDeployTime.asSec}s\n`));
const duration = synthDuration.asMs + (deployDuration?.asMs ?? 0);
await ioHost.notify(info(`\n✨ Total time: ${formatTime(duration)}s\n`, 'CDK_TOOLKIT_I5001', { duration }));
};

const assetBuildTime = options.assetBuildTime ?? AssetBuildTime.ALL_BEFORE_DEPLOY;
Expand Down Expand Up @@ -649,13 +642,10 @@ export class Toolkit extends CloudAssemblySourceBuilder implements AsyncDisposab
*/
private async _rollback(assembly: StackAssembly, action: 'rollback' | 'deploy' | 'watch', options: RollbackOptions): Promise<void> {
const ioHost = withAction(this.ioHost, action);
const timer = Timer.start();
const synthTimer = Timer.start();
const stacks = assembly.selectStacksV2(options.stacks);
await this.validateStacksMetadata(stacks, ioHost);
const synthTime = timer.end();
await ioHost.notify(info(`\n✨ Synthesis time: ${synthTime.asSec}s\n`, 'CDK_TOOLKIT_I5001', {
Copy link
Contributor Author

@mrgrain mrgrain Feb 4, 2025 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This changes the code to CDK_TOOLKIT_I1000 which is the universal code for synth time.

time: synthTime.asMs,
}));
await synthTimer.endAs(ioHost, 'synth');

if (stacks.stackCount === 0) {
await ioHost.notify(error('No stacks selected'));
Expand All @@ -666,7 +656,7 @@ export class Toolkit extends CloudAssemblySourceBuilder implements AsyncDisposab

for (const stack of stacks.stackArtifacts) {
await ioHost.notify(info(`Rolling back ${chalk.bold(stack.displayName)}`));
const startRollbackTime = Timer.start();
const rollbackTimer = Timer.start();
const deployments = await this.deploymentsForAction('rollback');
try {
const stackResult = await deployments.rollbackStack({
Expand All @@ -680,8 +670,7 @@ export class Toolkit extends CloudAssemblySourceBuilder implements AsyncDisposab
if (!stackResult.notInRollbackableState) {
anyRollbackable = true;
}
const elapsedRollbackTime = startRollbackTime.end();
await ioHost.notify(info(`\n✨ Rollback time: ${elapsedRollbackTime.asSec}s\n`));
await rollbackTimer.endAs(ioHost, 'rollback');
} catch (e: any) {
await ioHost.notify(error(`\n ❌ ${chalk.bold(stack.displayName)} failed: ${formatErrorMessage(e)}`));
throw new ToolkitError('Rollback failed (use --force to orphan failing resources)');
Expand All @@ -707,8 +696,10 @@ export class Toolkit extends CloudAssemblySourceBuilder implements AsyncDisposab
*/
private async _destroy(assembly: StackAssembly, action: 'deploy' | 'destroy', options: DestroyOptions): Promise<void> {
const ioHost = withAction(this.ioHost, action);
const synthTimer = Timer.start();
// The stacks will have been ordered for deployment, so reverse them for deletion.
const stacks = await assembly.selectStacksV2(options.stacks).reversed();
await synthTimer.endAs(ioHost, 'synth');

const motivation = 'Destroying stacks is an irreversible action';
const question = `Are you sure you want to delete: ${chalk.red(stacks.hierarchicalIds.join(', '))}`;
Expand All @@ -717,21 +708,26 @@ export class Toolkit extends CloudAssemblySourceBuilder implements AsyncDisposab
return ioHost.notify(error('Aborted by user'));
}

for (const [index, stack] of stacks.stackArtifacts.entries()) {
await ioHost.notify(success(`${chalk.blue(stack.displayName)}: destroying... [${index + 1}/${stacks.stackCount}]`));
try {
const deployments = await this.deploymentsForAction(action);
await deployments.destroyStack({
stack,
deployName: stack.stackName,
roleArn: options.roleArn,
ci: options.ci,
});
await ioHost.notify(success(`\n ✅ ${chalk.blue(stack.displayName)}: ${action}ed`));
} catch (e) {
await ioHost.notify(error(`\n ❌ ${chalk.blue(stack.displayName)}: ${action} failed ${e}`));
throw e;
const destroyTimer = Timer.start();
try {
for (const [index, stack] of stacks.stackArtifacts.entries()) {
await ioHost.notify(success(`${chalk.blue(stack.displayName)}: destroying... [${index + 1}/${stacks.stackCount}]`));
try {
const deployments = await this.deploymentsForAction(action);
await deployments.destroyStack({
stack,
deployName: stack.stackName,
roleArn: options.roleArn,
ci: options.ci,
});
await ioHost.notify(success(`\n ✅ ${chalk.blue(stack.displayName)}: ${action}ed`));
} catch (e) {
await ioHost.notify(error(`\n ❌ ${chalk.blue(stack.displayName)}: ${action} failed ${e}`));
throw e;
}
}
} finally {
await destroyTimer.endAs(ioHost, 'destroy');
}
}

Expand Down
2 changes: 1 addition & 1 deletion packages/@aws-cdk/toolkit/test/actions/deploy.test.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -148,7 +148,7 @@ describe('deploy', () => {
expect(ioHost.notifySpy).toHaveBeenCalledWith(expect.objectContaining({
action: 'deploy',
level: 'info',
code: 'CDK_TOOLKIT_I3001',
code: 'CDK_TOOLKIT_I5031',
message: expect.stringContaining('The following log groups are added: /aws/lambda/lambda-function-name'),
}));
});
Expand Down
4 changes: 2 additions & 2 deletions packages/@aws-cdk/toolkit/test/actions/synth.test.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -45,7 +45,7 @@ describe('synth', () => {
expect(ioHost.notifySpy).toHaveBeenCalledWith(expect.objectContaining({
action: 'synth',
level: 'result',
code: 'CDK_TOOLKIT_I0001',
code: 'CDK_TOOLKIT_I1901',
message: expect.stringContaining('Successfully synthesized'),
data: expect.objectContaining({
stacksCount: 1,
Expand All @@ -66,7 +66,7 @@ describe('synth', () => {
expect(ioHost.notifySpy).toHaveBeenCalledWith(expect.objectContaining({
action: 'synth',
level: 'result',
code: 'CDK_TOOLKIT_I0002',
code: 'CDK_TOOLKIT_I1902',
message: expect.stringContaining('Successfully synthesized'),
data: expect.objectContaining({
stacksCount: 2,
Expand Down