diff --git a/packages/@aws-cdk/toolkit-lib/lib/api/deployments/cfn-api.ts b/packages/@aws-cdk/toolkit-lib/lib/api/deployments/cfn-api.ts index 47e482e23..150a5fb6a 100644 --- a/packages/@aws-cdk/toolkit-lib/lib/api/deployments/cfn-api.ts +++ b/packages/@aws-cdk/toolkit-lib/lib/api/deployments/cfn-api.ts @@ -24,6 +24,12 @@ import type { IoHelper } from '../io/private'; import type { ResourcesToImport } from '../resource-import'; import { StackArtifactSourceTracer } from '../source-tracing/private/stack-source-tracing'; +/** + * How many consecutive REVIEW_IN_PROGRESS reads to attribute to DescribeStacks eventual consistency + * before accepting the status as genuine. + */ +const STALE_REVIEW_READ_TOLERANCE = 5; + export type PrepareChangeSetOptions = { stack: cxapi.CloudFormationStackArtifact; deployments: Deployments; @@ -382,8 +388,9 @@ export async function waitForStackDeploy( ioHelper: IoHelper, stackName: string, stabilizationPollingInterval?: number, + executingStackId?: string, ): Promise { - const stack = await stabilizeStack(cfn, ioHelper, stackName, stabilizationPollingInterval); + const stack = await stabilizeStack(cfn, ioHelper, stackName, stabilizationPollingInterval, executingStackId); if (!stack) { return undefined; } @@ -404,15 +411,25 @@ export async function waitForStackDeploy( /** * Wait for a stack to become stable (no longer _IN_PROGRESS), returning it + * + * @param executingStackId - the id of a stack whose ChangeSet execution has already been issued. `REVIEW_IN_PROGRESS` + * reported for that stack is a stale read rather than a stable status, because execution has moved it on already. */ export async function stabilizeStack( cfn: ICloudFormationClient, ioHelper: IoHelper, stackNameOrArn: string, pollingInterval?: number, + executingStackId?: string, ) { const stackDisplayName = stackNameFromArn(stackNameOrArn); await ioHelper.defaults.debug(format('Waiting for stack %s to finish creating or updating...', stackDisplayName)); + + // The stack we have seen an operation in progress on. Compared by id, because polling by name can otherwise + // observe a different stack that a concurrent operation created under the same name. + let inProgressStackId = executingStackId; + let staleReviewReads = 0; + return waitFor(async () => { const stack = await CloudFormationStack.lookup(cfn, stackNameOrArn); if (!stack.exists) { @@ -421,9 +438,20 @@ export async function stabilizeStack( } const status = stack.stackStatus; if (status.isInProgress) { + inProgressStackId = stack.stackId; + staleReviewReads = 0; await ioHelper.defaults.debug(format('Stack %s has an ongoing operation in progress and is not stable (%s)', stackDisplayName, status)); return undefined; } else if (status.isReviewInProgress) { + // A stack cannot go from an in-progress state back to REVIEW_IN_PROGRESS, so for the same stack id this is a + // stale read from an eventually consistent DescribeStacks replica. Tolerate a bounded number of them so that + // a stack genuinely left in review - which nothing will move on its own - still terminates the wait. + if (stack.stackId === inProgressStackId && staleReviewReads < STALE_REVIEW_READ_TOLERANCE) { + staleReviewReads++; + await ioHelper.defaults.debug(format('Stack %s reported REVIEW_IN_PROGRESS after being in progress; treating as a stale read (%s)', stackDisplayName, status)); + return undefined; + } + // This may happen if a stack creation operation is interrupted before the ChangeSet execution starts. Recovering // from this would requiring manual intervention (deleting or executing the pending ChangeSet), and failing to do // so will result in an endless wait here (the ChangeSet wont delete or execute itself). Instead of blocking diff --git a/packages/@aws-cdk/toolkit-lib/lib/api/deployments/deploy-stack.ts b/packages/@aws-cdk/toolkit-lib/lib/api/deployments/deploy-stack.ts index 2a5ef2263..6e531f792 100644 --- a/packages/@aws-cdk/toolkit-lib/lib/api/deployments/deploy-stack.ts +++ b/packages/@aws-cdk/toolkit-lib/lib/api/deployments/deploy-stack.ts @@ -705,7 +705,7 @@ class FullCloudFormationDeployment { let finalState = this.cloudFormationStack; try { - const successStack = await waitForStackDeploy(this.cfn, this.ioHelper, this.stackName, this.options.stackEventPollingInterval); + const successStack = await waitForStackDeploy(this.cfn, this.ioHelper, this.stackName, this.options.stackEventPollingInterval, stackArn); // This shouldn't really happen, but catch it anyway. You never know. if (!successStack) { @@ -715,10 +715,16 @@ class FullCloudFormationDeployment { } catch (e: any) { // If this is a deployment error, route the diagnosis and error reporting through the central code for that if (ToolkitError.isDeploymentError(e)) { - const diagnosis = await this.diagnoser.diagnoseFromErrorCollection(monitor.errors, finalState.wrapped, true, { - rollbackEnabled: this.options.rollback !== false, - }); - diagnosis.throwOnError(); + // `finalState` is still the pre-deploy lookup, which holds no stack at all when we were creating one from + // scratch, and describes a state the deployment has since left when it does. Describe the stack we actually + // deployed instead. Diagnosing is best-effort: if it cannot tell us anything, report the deployment error. + const deployedState = await CloudFormationStack.lookup(this.cfn, stackArn).catch(() => undefined); + if (deployedState?.exists) { + const diagnosis = await this.diagnoser.diagnoseFromErrorCollection(monitor.errors, deployedState.wrapped, true, { + rollbackEnabled: this.options.rollback !== false, + }); + diagnosis.throwOnError(); + } } // Otherwise rethrow the current error and hope it has enough information. diff --git a/packages/@aws-cdk/toolkit-lib/test/api/deployments/cfn-api-stabilization.test.ts b/packages/@aws-cdk/toolkit-lib/test/api/deployments/cfn-api-stabilization.test.ts new file mode 100644 index 000000000..a4003d6d0 --- /dev/null +++ b/packages/@aws-cdk/toolkit-lib/test/api/deployments/cfn-api-stabilization.test.ts @@ -0,0 +1,148 @@ +import { DescribeStacksCommand, StackStatus } from '@aws-sdk/client-cloudformation'; +import type { ICloudFormationClient } from '../../../lib/api/aws-auth/private'; +import { stabilizeStack, waitForStackDeploy } from '../../../lib/api/deployments/cfn-api'; +import { advanceTime } from '../../_helpers/fake-time'; +import { MockSdk, mockCloudFormationClient, restoreSdkMocksToDefault } from '../../_helpers/mock-sdk'; +import { TestIoHost } from '../../_helpers/test-io-host'; + +const ioHost = new TestIoHost(); +const ioHelper = ioHost.asHelper('deploy'); + +let cfn: ICloudFormationClient; + +beforeEach(() => { + restoreSdkMocksToDefault(); + cfn = new MockSdk().cloudFormation(); + jest.useFakeTimers(); +}); + +afterEach(() => { + jest.useRealTimers(); +}); + +function stackResponse(status: StackStatus, stackId = 'my-stack-id') { + return { + Stacks: [ + { + StackName: 'my-stack', + StackId: stackId, + CreationTime: new Date(), + StackStatus: status, + }, + ], + }; +} + +describe('stabilizeStack', () => { + test('keeps polling when REVIEW_IN_PROGRESS is read after an in-progress state', async () => { + // GIVEN - a poll after ExecuteChangeSet lands on a replica still reporting the pre-execution status + mockCloudFormationClient + .on(DescribeStacksCommand) + .resolvesOnce(stackResponse(StackStatus.CREATE_IN_PROGRESS)) + .resolvesOnce(stackResponse(StackStatus.REVIEW_IN_PROGRESS)) + .resolves(stackResponse(StackStatus.CREATE_COMPLETE)); + + // WHEN + const stack = await advanceTime(stabilizeStack(cfn, ioHelper, 'my-stack', 10_000)); + + // THEN + expect(stack?.stackStatus.name).toEqual(StackStatus.CREATE_COMPLETE); + expect(mockCloudFormationClient).toHaveReceivedCommandTimes(DescribeStacksCommand, 3); + }); + + test('keeps polling when the very first read is a stale REVIEW_IN_PROGRESS for the executing stack', async () => { + // GIVEN - nothing guarantees the first DescribeStacks after ExecuteChangeSet observes the new + // status, so the executing stack's id is passed in to identify a stale read without having to + // see the operation in progress first. + mockCloudFormationClient + .on(DescribeStacksCommand) + .resolvesOnce(stackResponse(StackStatus.REVIEW_IN_PROGRESS)) + .resolvesOnce(stackResponse(StackStatus.CREATE_IN_PROGRESS)) + .resolves(stackResponse(StackStatus.CREATE_COMPLETE)); + + // WHEN + const stack = await advanceTime(stabilizeStack(cfn, ioHelper, 'my-stack', 10_000, 'my-stack-id')); + + // THEN + expect(stack?.stackStatus.name).toEqual(StackStatus.CREATE_COMPLETE); + }); + + test('treats REVIEW_IN_PROGRESS on a different stack id as a genuine status', async () => { + // GIVEN - polling by name can observe a different stack if a concurrent operation deleted and + // re-created it. That review status belongs to a stack we never deployed, and nothing will move + // it on, so it must not be waited on. + mockCloudFormationClient + .on(DescribeStacksCommand) + .resolvesOnce(stackResponse(StackStatus.UPDATE_IN_PROGRESS, 'original-stack-id')) + .resolves(stackResponse(StackStatus.REVIEW_IN_PROGRESS, 'replacement-stack-id')); + + // WHEN + const stack = await advanceTime(stabilizeStack(cfn, ioHelper, 'my-stack', 10_000)); + + // THEN + expect(stack?.stackStatus.name).toEqual(StackStatus.REVIEW_IN_PROGRESS); + expect(mockCloudFormationClient).toHaveReceivedCommandTimes(DescribeStacksCommand, 2); + }); + + test('gives up on a persistent REVIEW_IN_PROGRESS rather than polling forever', async () => { + // GIVEN - REVIEW_IN_PROGRESS that never resolves after an in-progress state, e.g. a concurrent + // operation deleted the stack and left a fresh CREATE changeset unexecuted. `waitFor` has no + // timeout, so treating this as a stale read indefinitely would hang the deployment. + mockCloudFormationClient + .on(DescribeStacksCommand) + .resolvesOnce(stackResponse(StackStatus.CREATE_IN_PROGRESS)) + .resolves(stackResponse(StackStatus.REVIEW_IN_PROGRESS)); + + // WHEN - advance a bounded number of intervals, so an unbounded wait fails the assertion + // below instead of hanging until the jest timeout. + let settled: string | undefined; + void stabilizeStack(cfn, ioHelper, 'my-stack', 10_000).then((s) => { + settled = s?.stackStatus.name ?? 'undefined'; + }); + for (let i = 0; i < 20 && settled === undefined; i++) { + await jest.advanceTimersByTimeAsync(10_000); + } + + // THEN + expect(settled).toEqual(StackStatus.REVIEW_IN_PROGRESS); + }); + + test('treats REVIEW_IN_PROGRESS as stable when no operation was ever in progress', async () => { + // GIVEN - an abandoned ChangeSet: nothing will move this stack on its own, so we must not wait forever + mockCloudFormationClient.on(DescribeStacksCommand).resolves(stackResponse(StackStatus.REVIEW_IN_PROGRESS)); + + // WHEN + const stack = await advanceTime(stabilizeStack(cfn, ioHelper, 'my-stack', 10_000)); + + // THEN + expect(stack?.stackStatus.name).toEqual(StackStatus.REVIEW_IN_PROGRESS); + expect(mockCloudFormationClient).toHaveReceivedCommandTimes(DescribeStacksCommand, 1); + }); +}); + +describe('waitForStackDeploy', () => { + test('succeeds when a stale REVIEW_IN_PROGRESS read interrupts a successful create', async () => { + // GIVEN + mockCloudFormationClient + .on(DescribeStacksCommand) + .resolvesOnce(stackResponse(StackStatus.CREATE_IN_PROGRESS)) + .resolvesOnce(stackResponse(StackStatus.REVIEW_IN_PROGRESS)) + .resolves(stackResponse(StackStatus.CREATE_COMPLETE)); + + // WHEN + const stack = await advanceTime(waitForStackDeploy(cfn, ioHelper, 'my-stack', 10_000)); + + // THEN + expect(stack?.stackStatus.name).toEqual(StackStatus.CREATE_COMPLETE); + }); + + test('still fails on an abandoned pre-execution ChangeSet', async () => { + // GIVEN + mockCloudFormationClient.on(DescribeStacksCommand).resolves(stackResponse(StackStatus.REVIEW_IN_PROGRESS)); + + // WHEN / THEN + await expect( + advanceTime(waitForStackDeploy(cfn, ioHelper, 'my-stack', 10_000)), + ).rejects.toThrow(/failed to deploy: REVIEW_IN_PROGRESS/); + }); +}); diff --git a/packages/@aws-cdk/toolkit-lib/test/api/deployments/deploy-stack-error-surfacing.test.ts b/packages/@aws-cdk/toolkit-lib/test/api/deployments/deploy-stack-error-surfacing.test.ts new file mode 100644 index 000000000..77836a7f7 --- /dev/null +++ b/packages/@aws-cdk/toolkit-lib/test/api/deployments/deploy-stack-error-surfacing.test.ts @@ -0,0 +1,117 @@ +import type { CloudFormationStackArtifact } from '@aws-cdk/cloud-assembly-api'; +import { deployStack } 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'; + +jest.mock('../../../lib/api/deployments/checks', () => ({ + determineAllowCrossAccountAssetPublishing: jest.fn().mockResolvedValue(true), +})); + +const ioHost = new TestIoHost(); +const ioHelper = ioHost.asHelper('deploy'); + +const FAILING_STACK = testStack({ + stackName: 'freshstack', + template: { + Resources: { + Bad: { + Type: 'Test::Fake::Resource', + Properties: { Fail: true }, + }, + }, + }, +}); + +let sdk: MockSdk; +let sdkProvider: MockSdkProvider; +const fakeCfn = new FakeCloudFormation(); + +beforeEach(() => { + fakeCfn.reset(); + sdkProvider = new MockSdkProvider(); + sdk = new MockSdk(); + sdk.getUrlSuffix = () => Promise.resolve('amazonaws.com'); + restoreSdkMocksToDefault(); + fakeCfn.installUsingAwsMock(mockCloudFormationClient); + jest.useFakeTimers(); +}); + +afterEach(() => { + jest.useRealTimers(); +}); + +function standardDeployStackArguments(stack: CloudFormationStackArtifact): 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, + }), + }; +} + +describe.each(['change-set', 'direct'] as const)('a failing %s deployment of a new stack', (method) => { + test('reports the CloudFormation failure rather than an internal NoStack error', async () => { + // GIVEN - a stack that does not exist yet, so the pre-deploy lookup holds no stack at all + const deployment = advanceTime(deployStack({ + ...standardDeployStackArguments(FAILING_STACK), + deploymentMethod: { method }, + }, ioHelper)); + + // THEN - either the resource-level diagnosis or the rollback status the stack ended up in, + // depending on whether the monitor saw the resource failure before the rollback removed it + await expect(deployment).rejects.toThrow(/freshstack\/Bad|ROLLBACK_COMPLETE/); + await expect(deployment).rejects.not.toThrow(/does not hold a stack/); + await expect(deployment).rejects.toMatchObject({ name: 'DeploymentError' }); + }); + + test('reports the CloudFormation failure when rollback is disabled', async () => { + // GIVEN - without rollback the stack stays CREATE_FAILED rather than rolling back, which reaches + // the diagnoser through a different status + const deployment = advanceTime(deployStack({ + ...standardDeployStackArguments(FAILING_STACK), + deploymentMethod: { method }, + rollback: false, + }, ioHelper)); + + // THEN + await expect(deployment).rejects.toThrow(/freshstack\/Bad|CREATE_FAILED/); + await expect(deployment).rejects.not.toThrow(/does not hold a stack/); + }); +}); + +test('a failing update of an existing stack still reports the CloudFormation failure', async () => { + // GIVEN - the same failure without the absent-stack path, guarding against a fix that only + // works when the stack is missing + fakeCfn.createStackSync({ StackName: 'freshstack' }); + + // WHEN + const deployment = advanceTime(deployStack({ + ...standardDeployStackArguments(FAILING_STACK), + deploymentMethod: { method: 'change-set' }, + }, ioHelper)); + + // THEN + await expect(deployment).rejects.toThrow(/freshstack\/Bad|UPDATE_ROLLBACK_COMPLETE/); + await expect(deployment).rejects.not.toThrow(/does not hold a stack/); +}); diff --git a/packages/@aws-cdk/toolkit-lib/test/api/deployments/deploy-stack-polling-interval.test.ts b/packages/@aws-cdk/toolkit-lib/test/api/deployments/deploy-stack-polling-interval.test.ts index 0afb47d4f..ad15ca942 100644 --- a/packages/@aws-cdk/toolkit-lib/test/api/deployments/deploy-stack-polling-interval.test.ts +++ b/packages/@aws-cdk/toolkit-lib/test/api/deployments/deploy-stack-polling-interval.test.ts @@ -145,6 +145,7 @@ describe('deployStack', () => { expect.anything(), expect.anything(), 10_000, + expect.anything(), ); }); });