Skip to content

Commit

Permalink
feat(cli): logging can be corked (#25644)
Browse files Browse the repository at this point in the history 
🍾

This PR extends #25536 by fixing issues with logging.

- Asset building and publishing are now completely separate tasks, so there is never a need for the "Building and Publishing" message in cdk-assets. I've removed a good chunk of unnecessary private props in `AssetPublisher` and now we simply print `Building` when building an asset and `Publishing` when publishing an asset. No combos anymore.
- Asset build/publish can now happen concurrently with stack deployments when there are no dependencies between the two, but if `--require-approval` is set (which it is by default), sensitive stack deployments prompt the user for a `y/n` response before deployment. Additional asset related messages may come in at this time, cluttering the log. The solution here is to implement a cork that is turned on when prompting the user and turned off after user input. When using the helper function `withCorkedLogging(callback)`, logs will instead be stored in memory and released when the cork is popped.

Testing:

There's not a great way to test these changes in code since they should only affect logging. Instead, I hope the following photos suffice:

Before the lock change, logging looked like this:
<img width="698" alt="Screen Shot 2023-05-18 at 4 59 35 PM" src="https://github.com/aws/aws-cdk/assets/36202692/c554c1f2-1034-422c-95e6-ebf15f09b35b">

Now it looks like this in the same scenario: 
 
<img width="697" alt="Screen Shot 2023-05-18 at 4 49 39 PM" src="https://github.com/aws/aws-cdk/assets/36202692/1257c20e-73c4-4fc2-b8cd-ae510f32c756">

The screenshots also show the logs that say `Building` and `Publishing` separately rather than `Building and Publishing` as it did before.

----

*By submitting this pull request, I confirm that my contribution is made under the terms of the Apache-2.0 license*
  • Loading branch information
@kaizencc
kaizencc authored May 19, 2023
1 parent b60876f commit 0643020
Show file tree
Hide file tree
Showing 4 changed files with 66 additions and 57 deletions.
37 changes: 19 additions & 18 deletions packages/aws-cdk/lib/cdk-toolkit.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -17,7 +17,7 @@ import { CloudWatchLogEventMonitor } from './api/logs/logs-monitor';
import { StackActivityProgress } from './api/util/cloudformation/stack-activity-monitor';
import { printSecurityDiff, printStackDiff, RequireApproval } from './diff';
import { ResourceImporter } from './import';
import { data, debug, error, highlight, print, success, warning } from './logging';
import { data, debug, error, highlight, print, success, warning, withCorkedLogging } from './logging';
import { deserializeStructure, serializeStructure } from './serialize';
import { Configuration, PROJECT_CONFIG } from './settings';
import { numberFromBool, partition } from './util';
Expand Down Expand Up @@ -238,23 +238,24 @@ export class CdkToolkit {
if (requireApproval !== RequireApproval.Never) {
const currentTemplate = await this.props.deployments.readCurrentTemplate(stack);
if (printSecurityDiff(currentTemplate, stack, requireApproval)) {

// only talk to user if STDIN is a terminal (otherwise, fail)
if (!process.stdin.isTTY) {
throw new Error(
'"--require-approval" is enabled and stack includes security-sensitive updates, ' +
'but terminal (TTY) is not attached so we are unable to get a confirmation from the user');
}

// only talk to user if concurrency is 1 (otherwise, fail)
if (concurrency > 1) {
throw new Error(
'"--require-approval" is enabled and stack includes security-sensitive updates, ' +
'but concurrency is greater than 1 so we are unable to get a confirmation from the user');
}

const confirmed = await promptly.confirm('Do you wish to deploy these changes (y/n)?');
if (!confirmed) { throw new Error('Aborted by user'); }
await withCorkedLogging(async () => {
// only talk to user if STDIN is a terminal (otherwise, fail)
if (!process.stdin.isTTY) {
throw new Error(
'"--require-approval" is enabled and stack includes security-sensitive updates, ' +
'but terminal (TTY) is not attached so we are unable to get a confirmation from the user');
}

// only talk to user if concurrency is 1 (otherwise, fail)
if (concurrency > 1) {
throw new Error(
'"--require-approval" is enabled and stack includes security-sensitive updates, ' +
'but concurrency is greater than 1 so we are unable to get a confirmation from the user');
}

const confirmed = await promptly.confirm('Do you wish to deploy these changes (y/n)?');
if (!confirmed) { throw new Error('Aborted by user'); }
});
}
}

Expand Down
38 changes: 37 additions & 1 deletion packages/aws-cdk/lib/logging.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,34 @@ const { stdout, stderr } = process;

type WritableFactory = () => Writable;

export async function withCorkedLogging<A>(block: () => Promise<A>): Promise<A> {
corkLogging();
try {
return await block();
} finally {
uncorkLogging();
}
}

let CORK_COUNTER = 0;
const logBuffer: [Writable, string][] = [];

function corked() {
return CORK_COUNTER !== 0;
}

function corkLogging() {
CORK_COUNTER += 1;
}

function uncorkLogging() {
CORK_COUNTER -= 1;
if (!corked()) {
logBuffer.forEach(([stream, str]) => stream.write(str + '\n'));
logBuffer.splice(0);
}
}

const logger = (stream: Writable | WritableFactory, styles?: StyleFn[], timestamp?: boolean) => (fmt: string, ...args: unknown[]) => {
const ts = timestamp ? `[${formatTime(new Date())}] ` : '';

Expand All @@ -15,11 +43,19 @@ const logger = (stream: Writable | WritableFactory, styles?: StyleFn[], timestam
str = styles.reduce((a, style) => style(a), str);
}


const realStream = typeof stream === 'function' ? stream() : stream;

// Logger is currently corked, so we store the message to be printed
// later when we are uncorked.
if (corked()) {
logBuffer.push([realStream, str]);
return;
}

realStream.write(str + '\n');
};


function formatTime(d: Date) {
return `${lpad(d.getHours(), 2)}:${lpad(d.getMinutes(), 2)}:${lpad(d.getSeconds(), 2)}`;

Expand Down
46 changes: 9 additions & 37 deletions packages/cdk-assets/lib/publishing.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -82,9 +82,6 @@ export class AssetPublishing implements IPublishProgress {
private readonly publishInParallel: boolean;
private readonly buildAssets: boolean;
private readonly publishAssets: boolean;
private readonly startMessagePrefix: string;
private readonly successMessagePrefix: string;
private readonly errorMessagePrefix: string;
private readonly handlerCache = new Map<IManifestEntry, IAssetHandler>();

constructor(private readonly manifest: AssetManifest, private readonly options: AssetPublishingOptions) {
Expand All @@ -94,34 +91,6 @@ export class AssetPublishing implements IPublishProgress {
this.buildAssets = options.buildAssets ?? true;
this.publishAssets = options.publishAssets ?? true;

const getMessages = () => {
if (this.buildAssets && this.publishAssets) {
return {
startMessagePrefix: 'Building and publishing',
successMessagePrefix: 'Built and published',
errorMessagePrefix: 'Error building and publishing',
};
} else if (this.buildAssets) {
return {
startMessagePrefix: 'Building',
successMessagePrefix: 'Built',
errorMessagePrefix: 'Error building',
};
} else {
return {
startMessagePrefix: 'Publishing',
successMessagePrefix: 'Published',
errorMessagePrefix: 'Error publishing',
};
}
};

const messages = getMessages();

this.startMessagePrefix = messages.startMessagePrefix;
this.successMessagePrefix = messages.successMessagePrefix;
this.errorMessagePrefix = messages.errorMessagePrefix;

const self = this;
this.handlerHost = {
aws: this.options.aws,
Expand All @@ -146,7 +115,7 @@ export class AssetPublishing implements IPublishProgress {
}

if ((this.options.throwOnError ?? true) && this.failures.length > 0) {
throw new Error(`${this.errorMessagePrefix}: ${this.failures.map(e => e.error.message)}`);
throw new Error(`Error publishing: ${this.failures.map(e => e.error.message)}`);
}
}

Expand All @@ -155,14 +124,17 @@ export class AssetPublishing implements IPublishProgress {
*/
public async buildEntry(asset: IManifestEntry) {
try {
if (this.progressEvent(EventType.START, `${this.startMessagePrefix} ${asset.id}`)) { return false; }
if (this.progressEvent(EventType.START, `Building ${asset.id}`)) { return false; }

const handler = this.assetHandler(asset);
await handler.build();

if (this.aborted) {
throw new Error('Aborted');
}

this.completedOperations++;
if (this.progressEvent(EventType.SUCCESS, `Built ${asset.id}`)) { return false; }
} catch (e: any) {
this.failures.push({ asset, error: e });
this.completedOperations++;
Expand All @@ -177,7 +149,7 @@ export class AssetPublishing implements IPublishProgress {
*/
public async publishEntry(asset: IManifestEntry) {
try {
if (this.progressEvent(EventType.UPLOAD, `${this.startMessagePrefix} ${asset.id}`)) { return false; }
if (this.progressEvent(EventType.START, `Publishing ${asset.id}`)) { return false; }

const handler = this.assetHandler(asset);
await handler.publish();
Expand All @@ -187,7 +159,7 @@ export class AssetPublishing implements IPublishProgress {
}

this.completedOperations++;
if (this.progressEvent(EventType.SUCCESS, `${this.successMessagePrefix} ${asset.id}`)) { return false; }
if (this.progressEvent(EventType.SUCCESS, `Published ${asset.id}`)) { return false; }
} catch (e: any) {
this.failures.push({ asset, error: e });
this.completedOperations++;
Expand All @@ -212,7 +184,7 @@ export class AssetPublishing implements IPublishProgress {
*/
private async publishAsset(asset: IManifestEntry) {
try {
if (this.progressEvent(EventType.START, `${this.startMessagePrefix} ${asset.id}`)) { return false; }
if (this.progressEvent(EventType.START, `Publishing ${asset.id}`)) { return false; }

const handler = this.assetHandler(asset);

Expand All @@ -229,7 +201,7 @@ export class AssetPublishing implements IPublishProgress {
}

this.completedOperations++;
if (this.progressEvent(EventType.SUCCESS, `${this.successMessagePrefix} ${asset.id}`)) { return false; }
if (this.progressEvent(EventType.SUCCESS, `Published ${asset.id}`)) { return false; }
} catch (e: any) {
this.failures.push({ asset, error: e });
this.completedOperations++;
Expand Down
2 changes: 1 addition & 1 deletion packages/cdk-assets/test/docker-images.test.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -247,7 +247,7 @@ describe('with a complete manifest', () => {
test('Displays an error if the ECR repository cannot be found', async () => {
aws.mockEcr.describeImages = mockedApiFailure('RepositoryNotFoundException', 'Repository not Found');

await expect(pub.publish()).rejects.toThrow('Error building and publishing: Repository not Found');
await expect(pub.publish()).rejects.toThrow('Error publishing: Repository not Found');
});

test('successful run does not need to query account ID', async () => {
Expand Down

0 comments on commit 0643020

Please sign in to comment.