diff --git a/packages/@aws-cdk/toolkit-lib/docs/message-registry.md b/packages/@aws-cdk/toolkit-lib/docs/message-registry.md index 292e60b97..22e921d10 100644 --- a/packages/@aws-cdk/toolkit-lib/docs/message-registry.md +++ b/packages/@aws-cdk/toolkit-lib/docs/message-registry.md @@ -120,6 +120,7 @@ Please let us know by [opening an issue](https://github.com/aws/aws-cdk-cli/issu | `CDK_TOOLKIT_W5400` | Hotswap disclosure message | `warn` | n/a | | `CDK_TOOLKIT_E5001` | No stacks found | `error` | n/a | | `CDK_TOOLKIT_E5500` | Stack Monitoring error | `error` | {@link ErrorPayload} | +| `CDK_TOOLKIT_W5500` | Stack events could not be read; the reported event log may be incomplete | `warn` | {@link ErrorPayload} | | `CDK_TOOLKIT_I6000` | Provides rollback times | `info` | {@link Duration} | | `CDK_TOOLKIT_I6100` | Stack rollback progress | `info` | {@link StackRollbackProgress} | | `CDK_TOOLKIT_E6001` | No stacks found | `error` | n/a | diff --git a/packages/@aws-cdk/toolkit-lib/lib/api/io/private/messages.ts b/packages/@aws-cdk/toolkit-lib/lib/api/io/private/messages.ts index 415ad977e..6001cbca9 100644 --- a/packages/@aws-cdk/toolkit-lib/lib/api/io/private/messages.ts +++ b/packages/@aws-cdk/toolkit-lib/lib/api/io/private/messages.ts @@ -348,6 +348,11 @@ export const IO = { description: 'Stack Monitoring error', interface: 'ErrorPayload', }), + CDK_TOOLKIT_W5500: make.warn({ + code: 'CDK_TOOLKIT_W5500', + description: 'Stack events could not be read; the reported event log may be incomplete', + interface: 'ErrorPayload', + }), // 6: Rollback (6xxx) CDK_TOOLKIT_I6000: make.info({ diff --git a/packages/@aws-cdk/toolkit-lib/lib/api/stack-events/stack-activity-monitor.ts b/packages/@aws-cdk/toolkit-lib/lib/api/stack-events/stack-activity-monitor.ts index a7b8a2aae..d2885931c 100644 --- a/packages/@aws-cdk/toolkit-lib/lib/api/stack-events/stack-activity-monitor.ts +++ b/packages/@aws-cdk/toolkit-lib/lib/api/stack-events/stack-activity-monitor.ts @@ -220,7 +220,6 @@ export class StackActivityMonitor { try { 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.monitorId) { @@ -231,6 +230,9 @@ export class StackActivityMonitor { util.format('Error occurred while monitoring stack: %s', e), { error: e as any }, )); + } finally { + // Clear on both paths, so `readPromise` only ever holds a read that is still in flight. + this.readPromise = undefined; } this.scheduleNextTick(); } @@ -287,11 +289,23 @@ export class StackActivityMonitor { // 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 // because our state is single-threaded. - if (this.readPromise) { + try { await this.readPromise; + } catch { + // A failure of the in-flight poll has already been reported by tick(). } - await this.readNewEvents(monitorId); + // Reading events only completes the event log shown to the user; it cannot change + // whether the monitored operation succeeded. Warn that the log may be short instead + // of letting the failure propagate out of stop(). + try { + await this.readNewEvents(monitorId); + } catch (e) { + await this.ioHelper.notify(IO.CDK_TOOLKIT_W5500.msg( + util.format('Error occurred during final stack event poll, event log may be incomplete: %s', e), + { error: e as any }, + )); + } } /** diff --git a/packages/@aws-cdk/toolkit-lib/test/api/deployments/cloudformation-deployments.test.ts b/packages/@aws-cdk/toolkit-lib/test/api/deployments/cloudformation-deployments.test.ts index 01635855a..2ec8c7323 100644 --- a/packages/@aws-cdk/toolkit-lib/test/api/deployments/cloudformation-deployments.test.ts +++ b/packages/@aws-cdk/toolkit-lib/test/api/deployments/cloudformation-deployments.test.ts @@ -1102,6 +1102,26 @@ test('rollback stack allows rolling back from UPDATE_FAILED', async () => { expect(mockCloudFormationClient).toHaveReceivedCommand(RollbackStackCommand); }); +test('rollback stack is not failed by a throttled stack event poll', async () => { + // GIVEN - reading stack events fails throughout, including the final poll in monitor.stop() + givenStacks({ + '*': { template: {}, stackStatus: 'UPDATE_FAILED' }, + }); + mockCloudFormationClient.on(DescribeStackEventsCommand).rejects( + Object.assign(new Error('Rate exceeded'), { name: 'Throttling' }), + ); + + // WHEN + const response = await deployments.rollbackStack({ + stack: testStack({ stackName: 'boop' }), + validateBootstrapStackVersion: false, + }); + + // THEN - the rollback succeeded, and the final poll failure was only reported + expect(response).toMatchObject({ success: true }); + ioHost.expectMessage({ level: 'warn', containing: 'Error occurred during final stack event poll' }); +}); + test('rollback stack allows continue rollback from UPDATE_ROLLBACK_FAILED', async () => { // GIVEN givenStacks({ diff --git a/packages/@aws-cdk/toolkit-lib/test/api/deployments/deploy-stack-event-poll-failures.test.ts b/packages/@aws-cdk/toolkit-lib/test/api/deployments/deploy-stack-event-poll-failures.test.ts new file mode 100644 index 000000000..edc9604ff --- /dev/null +++ b/packages/@aws-cdk/toolkit-lib/test/api/deployments/deploy-stack-event-poll-failures.test.ts @@ -0,0 +1,117 @@ +import type { CloudFormationStackArtifact } from '@aws-cdk/cloud-assembly-api'; +import { deployStack, destroyStack } from '../../../lib/api/deployments/deploy-stack'; +import type { DeployStackOptions as DeployStackApiOptions } from '../../../lib/api/deployments/deploy-stack'; +import { CloudFormationStackDiagnoser } from '../../../lib/api/diagnosing/stack-diagnoser'; +import { NoBootstrapStackEnvironmentResources } from '../../../lib/api/environment'; +import { StackArtifactSourceTracer } from '../../../lib/api/source-tracing/private/stack-source-tracing'; +import { testStack } from '../../_helpers/assembly'; +import { FakeCloudFormation } from '../../_helpers/fake-aws/fake-cloudformation'; +import { advanceTime } from '../../_helpers/fake-time'; +import { + mockCloudFormationClient, + mockResolvedEnvironment, + MockSdk, + MockSdkProvider, + restoreSdkMocksToDefault, +} from '../../_helpers/mock-sdk'; +import { TestIoHost } from '../../_helpers/test-io-host'; + +const ioHost = new TestIoHost(); +const ioHelper = ioHost.asHelper('deploy'); + +const FAKE_STACK = testStack({ + stackName: 'withouterrors', + template: { + Resources: { + MyResource: { + Type: 'Test::Resource::Type', + Properties: { + Bar: 'Bar', + }, + }, + }, + }, +}); + +let sdk: MockSdk; +let sdkProvider: MockSdkProvider; +const fakeCfn = new FakeCloudFormation(); + +beforeEach(() => { + fakeCfn.reset(); + ioHost.clear(); + + sdkProvider = new MockSdkProvider(); + sdk = new MockSdk(); + + restoreSdkMocksToDefault(); + fakeCfn.installUsingAwsMock(mockCloudFormationClient); + + jest.useFakeTimers(); +}); + +afterEach(() => { + jest.useRealTimers(); + jest.restoreAllMocks(); +}); + +function standardDeployStackArguments(stack: CloudFormationStackArtifact = FAKE_STACK): DeployStackApiOptions { + const resolvedEnvironment = mockResolvedEnvironment(); + return { + stack, + sdk, + sdkProvider, + resolvedEnvironment, + envResources: new NoBootstrapStackEnvironmentResources(resolvedEnvironment, sdk, ioHelper), + diagnoser: new CloudFormationStackDiagnoser({ + sdk, + sourceTracer: new StackArtifactSourceTracer(stack), + ioHelper, + topLevelStackHierarchicalId: stack.hierarchicalId, + }), + }; +} + +/** + * Throttle every stack event read, leaving the rest of the CloudFormation API working + */ +function throttleStackEventReads() { + const realClient = sdk.cloudFormation(); + jest.spyOn(sdk, 'cloudFormation').mockReturnValue({ + ...realClient, + describeStackEvents: () => Promise.reject(Object.assign(new Error('Rate exceeded'), { name: 'Throttling' })), + }); +} + +describe.each(['change-set', 'direct'] as const)('a successful %s deployment', (method) => { + test('is not failed by a throttled stack event poll', async () => { + // GIVEN - reading stack events fails throughout, including the final poll in monitor.stop() + throttleStackEventReads(); + + // WHEN + const result = await advanceTime(deployStack({ + ...standardDeployStackArguments(), + deploymentMethod: { method }, + }, ioHelper)); + + // THEN - the deployment succeeded, and the final poll failure was only reported + expect(result).toMatchObject({ type: 'did-deploy-stack' }); + ioHost.expectMessage({ level: 'warn', containing: 'Error occurred during final stack event poll' }); + }); +}); + +test('a successful destroy is not failed by a throttled stack event poll', async () => { + // GIVEN + fakeCfn.createStackSync({ StackName: 'withouterrors' }); + throttleStackEventReads(); + + // WHEN + const result = await advanceTime(destroyStack({ + stack: FAKE_STACK, + sdk, + }, ioHelper)); + + // THEN + expect(result.stackArn).toBeDefined(); + ioHost.expectMessage({ level: 'warn', containing: 'Error occurred during final stack event poll' }); +}); diff --git a/packages/@aws-cdk/toolkit-lib/test/api/stack-events/stack-activity-monitor.test.ts b/packages/@aws-cdk/toolkit-lib/test/api/stack-events/stack-activity-monitor.test.ts index 69e8ea69f..cc15ee41e 100644 --- a/packages/@aws-cdk/toolkit-lib/test/api/stack-events/stack-activity-monitor.test.ts +++ b/packages/@aws-cdk/toolkit-lib/test/api/stack-events/stack-activity-monitor.test.ts @@ -112,6 +112,48 @@ describe('stack monitor event ordering and pagination', () => { }); }); +describe('stack monitor, failures while reading events', () => { + test('a failing final poll is reported but does not fail stop()', async () => { + mockCloudFormationClient.on(DescribeStackEventsCommand).rejects(throttlingError()); + + await eventually(() => expect(mockCloudFormationClient).toHaveReceivedCommand(DescribeStackEventsCommand), 2); + + // The final poll only completes the event log, so its failure must not surface to the caller + await expect(monitor.stop()).resolves.toBeUndefined(); + expect(ioHost.notify).toHaveBeenCalledWith(expect.objectContaining({ + code: 'CDK_TOOLKIT_W5500', + message: expect.stringContaining('event log may be incomplete: Throttling: Rate exceeded'), + })); + expect(ioHost.notify).toHaveBeenCalledWith(expectStop()); + }); + + test('a poll that fails while stop() waits for it does not fail stop() either', async () => { + // GIVEN - a poll that is still in flight when the monitor is stopped + let failFirstPoll: (error: Error) => void; + const firstPoll = new Promise((_, reject) => { + failFirstPoll = reject; + }); + let polls = 0; + mockCloudFormationClient.on(DescribeStackEventsCommand).callsFake(() => { + polls += 1; + return polls === 1 ? firstPoll : { StackEvents: [event(101)] }; + }); + await eventually(() => expect(mockCloudFormationClient).toHaveReceivedCommandTimes(DescribeStackEventsCommand, 1), 2); + + // WHEN + const stopped = monitor.stop(); + failFirstPoll!(throttlingError()); + + // THEN - the failure is reported by the tick that started the poll, and the final poll still runs + await expect(stopped).resolves.toBeUndefined(); + expect(ioHost.notify).toHaveBeenCalledWith(expect.objectContaining({ + code: 'CDK_TOOLKIT_E5500', + message: expect.stringContaining('Error occurred while monitoring stack: Throttling: Rate exceeded'), + })); + expect(ioHost.notify).toHaveBeenCalledWith(expectEvent(101)); + }); +}); + describe('stack monitor, collecting errors from events', () => { test('return errors from the root stack', async () => { mockCloudFormationClient.on(DescribeStackEventsCommand).resolvesOnce({ @@ -294,6 +336,10 @@ function errorEvent(nr: number, props?: Parameters[ return addErrorToStackEvent(event(nr), props); } +function throttlingError(): Error { + return Object.assign(new Error('Rate exceeded'), { name: 'Throttling' }); +} + function addErrorToStackEvent( eventToUpdate: StackEvent, props: {