fix(toolkit-lib): stale DescribeStacks read fails fresh stack creates, masked as NoStack

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<CloudFormationStack | undefined> {
-  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

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.

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/);
+  });
+});

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/);
+});

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(),
     );
   });
 });