From a9c4d46c5a4e8a62cd2eb51d5043115037306006 Mon Sep 17 00:00:00 2001 From: Calvin Combs Date: Mon, 27 Jun 2022 22:03:16 -0700 Subject: [PATCH 01/16] retry logic --- .../provider-framework/runtime/framework.ts | 27 ++++++++++++++++++- 1 file changed, 26 insertions(+), 1 deletion(-) diff --git a/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts b/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts index 9c2d8a4bfc0fc..590f64840d805 100644 --- a/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts +++ b/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts @@ -13,6 +13,14 @@ export = { [consts.FRAMEWORK_ON_TIMEOUT_HANDLER_NAME]: onTimeout, }; +const DEFAULT_DELAY = 10_000; +const MAX_TOTAL_DELAY = 620_000; + +interface RetryOptions { + delay: number, + totalDelay: number, +} + /** * The main runtime entrypoint of the async custom resource lambda function. * @@ -93,7 +101,7 @@ async function onTimeout(timeoutEvent: any) { }); } -async function invokeUserFunction(functionArnEnv: string, payload: any) { +async function invokeUserFunction(functionArnEnv: string, payload: any, retryOptions?: RetryOptions): Promise { const functionArn = getEnv(functionArnEnv); log(`executing user function ${functionArn} with payload`, payload); @@ -109,6 +117,23 @@ async function invokeUserFunction(functionArnEnv: string, payload: any) { const jsonPayload = parseJsonPayload(resp.Payload); if (resp.FunctionError) { + if (resp.FunctionError.includes('Lambda is initializing your function')) { + const newDelay = retryOptions ? retryOptions.delay * 2 : DEFAULT_DELAY; + const newTotalDelay = retryOptions ? retryOptions.totalDelay : 0 + newDelay; + + // don't spend more than 10 minutes and some change waiting + if (newTotalDelay <= MAX_TOTAL_DELAY) { + const newRetryOptions = { + delay: newDelay, + totalDelay: newTotalDelay, + }; + + log('user function is still being initialized by Lambda, retrying with delay of: ', newDelay); + + return setTimeout(invokeUserFunction, newDelay, functionArnEnv, payload, newRetryOptions); + } + } + log('user function threw an error:', resp.FunctionError); const errorMessage = jsonPayload.errorMessage || 'error'; From 6fbe8eb683189f35161eda1633f3c18159b4d3e3 Mon Sep 17 00:00:00 2001 From: Calvin Combs Date: Mon, 11 Jul 2022 13:33:46 -0700 Subject: [PATCH 02/16] fixed small bug --- .../lib/provider-framework/runtime/framework.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts b/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts index 590f64840d805..3eaadbf4b40bf 100644 --- a/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts +++ b/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts @@ -119,7 +119,7 @@ async function invokeUserFunction(functionArnEnv: string, payload: any, retryOpt if (resp.FunctionError) { if (resp.FunctionError.includes('Lambda is initializing your function')) { const newDelay = retryOptions ? retryOptions.delay * 2 : DEFAULT_DELAY; - const newTotalDelay = retryOptions ? retryOptions.totalDelay : 0 + newDelay; + const newTotalDelay = (retryOptions ? retryOptions.totalDelay : 0) + newDelay; // don't spend more than 10 minutes and some change waiting if (newTotalDelay <= MAX_TOTAL_DELAY) { From d1fd547c27cf106469f9ed7e7013813e5764e5c0 Mon Sep 17 00:00:00 2001 From: Calvin Combs Date: Tue, 19 Jul 2022 15:52:18 -0700 Subject: [PATCH 03/16] instead of checking error message, ping the lambda function and check its state --- .../provider-framework/runtime/framework.ts | 18 +++++++++++------- .../lib/provider-framework/runtime/outbound.ts | 9 +++++++++ 2 files changed, 20 insertions(+), 7 deletions(-) diff --git a/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts b/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts index 3eaadbf4b40bf..5673aa71cd306 100644 --- a/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts +++ b/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts @@ -3,7 +3,7 @@ import { IsCompleteResponse, OnEventResponse } from '../types'; import * as cfnResponse from './cfn-response'; import * as consts from './consts'; -import { invokeFunction, startExecution } from './outbound'; +import { invokeFunction, startExecution, getFunction } from './outbound'; import { getEnv, log } from './util'; // use consts for handler names to compiler-enforce the coupling with construction code. @@ -115,9 +115,18 @@ async function invokeUserFunction(functionArnEnv: string, payload: any, retryOpt log('user function response:', resp, typeof(resp)); + // parse function name from arn + // arn:${Partition}:lambda:${Region}:${Account}:function:${FunctionName} + const arn = functionArn.split(':'); + const functionName = arn[arn.length - 1]; + const jsonPayload = parseJsonPayload(resp.Payload); if (resp.FunctionError) { - if (resp.FunctionError.includes('Lambda is initializing your function')) { + const getFunctionResponse = await getFunction({ + FunctionName: functionName, + }); + + if (getFunctionResponse.Configuration?.State === 'Inactive' || getFunctionResponse.Configuration?.State === 'Pending') { const newDelay = retryOptions ? retryOptions.delay * 2 : DEFAULT_DELAY; const newTotalDelay = (retryOptions ? retryOptions.totalDelay : 0) + newDelay; @@ -138,11 +147,6 @@ async function invokeUserFunction(functionArnEnv: string, payload: any, retryOpt const errorMessage = jsonPayload.errorMessage || 'error'; - // parse function name from arn - // arn:${Partition}:lambda:${Region}:${Account}:function:${FunctionName} - const arn = functionArn.split(':'); - const functionName = arn[arn.length - 1]; - // append a reference to the log group. const message = [ errorMessage, diff --git a/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/outbound.ts b/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/outbound.ts index 19dfd676bc92e..e2d45e4f0da1c 100644 --- a/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/outbound.ts +++ b/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/outbound.ts @@ -46,6 +46,15 @@ async function defaultInvokeFunction(req: AWS.Lambda.InvocationRequest): Promise return lambda.invoke(req).promise(); } +async function defaultGetFunction(req: AWS.Lambda.GetFunctionRequest): Promise { + if (!lambda) { + lambda = new AWS.Lambda(awsSdkConfig); + } + + return lambda.getFunction(req).promise(); +} + export let startExecution = defaultStartExecution; export let invokeFunction = defaultInvokeFunction; +export let getFunction = defaultGetFunction; export let httpRequest = defaultHttpRequest; From dee571016fa9240704fc5f72d4aa55988509b360 Mon Sep 17 00:00:00 2001 From: Calvin Combs Date: Mon, 1 Aug 2022 11:28:05 -0700 Subject: [PATCH 04/16] added jitter to backoff --- .../provider-framework/runtime/framework.ts | 25 ++++++++++--------- 1 file changed, 13 insertions(+), 12 deletions(-) diff --git a/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts b/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts index 5673aa71cd306..bf69356fbdab0 100644 --- a/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts +++ b/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts @@ -13,12 +13,12 @@ export = { [consts.FRAMEWORK_ON_TIMEOUT_HANDLER_NAME]: onTimeout, }; -const DEFAULT_DELAY = 10_000; -const MAX_TOTAL_DELAY = 620_000; +const BASE_SLEEP = 10_000; +const MAX_TOTAL_SLEEP = 620_000; interface RetryOptions { - delay: number, - totalDelay: number, + attempt: number, + totalSleep: number, } /** @@ -127,19 +127,20 @@ async function invokeUserFunction(functionArnEnv: string, payload: any, retryOpt }); if (getFunctionResponse.Configuration?.State === 'Inactive' || getFunctionResponse.Configuration?.State === 'Pending') { - const newDelay = retryOptions ? retryOptions.delay * 2 : DEFAULT_DELAY; - const newTotalDelay = (retryOptions ? retryOptions.totalDelay : 0) + newDelay; + const currentAttempt = retryOptions?.attempt ?? 1; + const newSleep = Math.floor(BASE_SLEEP * Math.pow(2, currentAttempt) * Math.random()); + const newTotalSleep = (retryOptions ? retryOptions.totalSleep : 0) + newSleep; // don't spend more than 10 minutes and some change waiting - if (newTotalDelay <= MAX_TOTAL_DELAY) { - const newRetryOptions = { - delay: newDelay, - totalDelay: newTotalDelay, + if (newTotalSleep <= MAX_TOTAL_SLEEP) { + const newRetryOptions: RetryOptions = { + attempt: currentAttempt + 1, + totalSleep: newTotalSleep, }; - log('user function is still being initialized by Lambda, retrying with delay of: ', newDelay); + log('user function is still being initialized by Lambda, retrying with delay of: ', newSleep); - return setTimeout(invokeUserFunction, newDelay, functionArnEnv, payload, newRetryOptions); + return setTimeout(invokeUserFunction, newSleep, functionArnEnv, payload, newRetryOptions); } } From 701306b0de148d3e21ed7f42969e9cb8f27733ea Mon Sep 17 00:00:00 2001 From: Calvin Combs Date: Mon, 1 Aug 2022 11:57:29 -0700 Subject: [PATCH 05/16] test --- .../lib/provider-framework/runtime/framework.ts | 1 + .../test/provider-framework/runtime.test.ts | 8 ++++++++ 2 files changed, 9 insertions(+) diff --git a/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts b/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts index bf69356fbdab0..a8227e1fa2428 100644 --- a/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts +++ b/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts @@ -104,6 +104,7 @@ async function onTimeout(timeoutEvent: any) { async function invokeUserFunction(functionArnEnv: string, payload: any, retryOptions?: RetryOptions): Promise { const functionArn = getEnv(functionArnEnv); log(`executing user function ${functionArn} with payload`, payload); + console.log('-----=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-==--==-=-=-=-=-==-=-==-=-=-=-=-=-=-=-=--=--=-=-==-') // transient errors such as timeouts, throttling errors (429), and other // errors that aren't caused by a bad request (500 series) are retried diff --git a/packages/@aws-cdk/custom-resources/test/provider-framework/runtime.test.ts b/packages/@aws-cdk/custom-resources/test/provider-framework/runtime.test.ts index 751e33e6408e0..c3425203212e6 100644 --- a/packages/@aws-cdk/custom-resources/test/provider-framework/runtime.test.ts +++ b/packages/@aws-cdk/custom-resources/test/provider-framework/runtime.test.ts @@ -343,6 +343,14 @@ describe('if CREATE fails, the subsequent DELETE will be ignored', () => { // THEN expectCloudFormationSuccess(); }); +}); + +test('foo', () => { + // GIVEN + + // WHEN + + // THEN }); From 5b2a30850113855df418ec699fd358bf6fc8b72a Mon Sep 17 00:00:00 2001 From: Calvin Combs Date: Mon, 1 Aug 2022 15:47:01 -0700 Subject: [PATCH 06/16] mocks created --- .../provider-framework/runtime/framework.ts | 1 - .../test/provider-framework/mocks.ts | 27 +++++++++++++++++++ .../test/provider-framework/runtime.test.ts | 11 +++++++- 3 files changed, 37 insertions(+), 2 deletions(-) diff --git a/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts b/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts index a8227e1fa2428..bf69356fbdab0 100644 --- a/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts +++ b/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts @@ -104,7 +104,6 @@ async function onTimeout(timeoutEvent: any) { async function invokeUserFunction(functionArnEnv: string, payload: any, retryOptions?: RetryOptions): Promise { const functionArn = getEnv(functionArnEnv); log(`executing user function ${functionArn} with payload`, payload); - console.log('-----=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-==--==-=-=-=-=-==-=-==-=-=-=-=-=-=-=-=--=--=-=-==-') // transient errors such as timeouts, throttling errors (429), and other // errors that aren't caused by a bad request (500 series) are retried diff --git a/packages/@aws-cdk/custom-resources/test/provider-framework/mocks.ts b/packages/@aws-cdk/custom-resources/test/provider-framework/mocks.ts index 3a70371e8b913..9c25a095c97fc 100644 --- a/packages/@aws-cdk/custom-resources/test/provider-framework/mocks.ts +++ b/packages/@aws-cdk/custom-resources/test/provider-framework/mocks.ts @@ -11,6 +11,7 @@ export const MOCK_REQUEST = { export const MOCK_ON_EVENT_FUNCTION_ARN = 'arn:lambda:user:on:event'; export const MOCK_IS_COMPLETE_FUNCTION_ARN = 'arn:lambda:user:is:complete'; +export const MOCK_INACTIVE_FUNCTION_ARN = 'arn:lambda:user:is:inactive'; export const MOCK_SFN_ARN = 'arn:of:state:machine'; export let stringifyPayload = true; @@ -79,6 +80,9 @@ export async function invokeFunctionMock(req: AWS.Lambda.InvocationRequest): Pro ret = await isCompleteImplMock(input as AWSCDKAsyncCustomResource.IsCompleteRequest); break; + case MOCK_INACTIVE_FUNCTION_ARN: + throw new Error('the lambda is inactive'); + default: throw new Error('unknown mock function'); } @@ -134,3 +138,26 @@ export async function startExecutionMock(req: AWS.StepFunctions.StartExecutionIn startDate: new Date(), }; } + +let invokeCount = -1; +export async function getFunctionMock(_req: AWS.Lambda.GetFunctionRequest): Promise { + invokeCount++; + if (invokeCount === 0) { + return { + Configuration: { + State: 'Inactive', + }, + }; + } else if (invokeCount === 1) { + return { + Configuration: { + State: 'Pending', + }, + }; + } + return { + Configuration: { + State: 'Active', + }, + }; +} \ No newline at end of file diff --git a/packages/@aws-cdk/custom-resources/test/provider-framework/runtime.test.ts b/packages/@aws-cdk/custom-resources/test/provider-framework/runtime.test.ts index c3425203212e6..264043fcb28fb 100644 --- a/packages/@aws-cdk/custom-resources/test/provider-framework/runtime.test.ts +++ b/packages/@aws-cdk/custom-resources/test/provider-framework/runtime.test.ts @@ -17,6 +17,10 @@ const MOCK_ATTRS = { MyAttribute: 'my-mock-attribute' }; outbound.httpRequest = mocks.httpRequestMock; outbound.invokeFunction = mocks.invokeFunctionMock; outbound.startExecution = mocks.startExecutionMock; +outbound.getFunction = mocks.getFunctionMock; +(setTimeout as any) = jest.fn((callback, _timeout, functionargsEnv, payload, options) => { + return callback(functionargsEnv, payload, options); +}); beforeEach(() => mocks.setup()); @@ -345,12 +349,17 @@ describe('if CREATE fails, the subsequent DELETE will be ignored', () => { }); }); -test('foo', () => { +test('foo', async () => { // GIVEN // WHEN + await outbound.invokeFunction({ + FunctionName: mocks.MOCK_INACTIVE_FUNCTION_ARN, + }); // THEN + // expect the mocked user function to have been called twice (once after getting inactive, and once after getting active) + // no errors ofc }); From 11505fd0263ed22a9cda6bff3551a3f928fb750a Mon Sep 17 00:00:00 2001 From: Calvin Combs Date: Wed, 3 Aug 2022 12:33:08 -0700 Subject: [PATCH 07/16] finalized testing --- .../test/provider-framework/mocks.ts | 13 ++++++------- .../test/provider-framework/runtime.test.ts | 16 ++++++++++------ 2 files changed, 16 insertions(+), 13 deletions(-) diff --git a/packages/@aws-cdk/custom-resources/test/provider-framework/mocks.ts b/packages/@aws-cdk/custom-resources/test/provider-framework/mocks.ts index 9c25a095c97fc..c16bdb48e7f1e 100644 --- a/packages/@aws-cdk/custom-resources/test/provider-framework/mocks.ts +++ b/packages/@aws-cdk/custom-resources/test/provider-framework/mocks.ts @@ -20,6 +20,8 @@ export let isCompleteImplMock: AWSCDKAsyncCustomResource.IsCompleteHandler | und export let startStateMachineInput: AWS.StepFunctions.StartExecutionInput | undefined; export let cfnResponse: AWSLambda.CloudFormationCustomResourceResponse; +let getFunctionInvokeCount: number; + export function setup() { process.env[consts.WAITER_STATE_MACHINE_ARN_ENV] = MOCK_SFN_ARN; @@ -28,6 +30,7 @@ export function setup() { isCompleteImplMock = undefined; cfnResponse = {} as any; startStateMachineInput = undefined; + getFunctionInvokeCount = -1; } export async function httpRequestMock(options: https.RequestOptions, body: string) { @@ -80,9 +83,6 @@ export async function invokeFunctionMock(req: AWS.Lambda.InvocationRequest): Pro ret = await isCompleteImplMock(input as AWSCDKAsyncCustomResource.IsCompleteRequest); break; - case MOCK_INACTIVE_FUNCTION_ARN: - throw new Error('the lambda is inactive'); - default: throw new Error('unknown mock function'); } @@ -139,16 +139,15 @@ export async function startExecutionMock(req: AWS.StepFunctions.StartExecutionIn }; } -let invokeCount = -1; export async function getFunctionMock(_req: AWS.Lambda.GetFunctionRequest): Promise { - invokeCount++; - if (invokeCount === 0) { + getFunctionInvokeCount++; + if (getFunctionInvokeCount === 0) { return { Configuration: { State: 'Inactive', }, }; - } else if (invokeCount === 1) { + } else if (getFunctionInvokeCount === 1) { return { Configuration: { State: 'Pending', diff --git a/packages/@aws-cdk/custom-resources/test/provider-framework/runtime.test.ts b/packages/@aws-cdk/custom-resources/test/provider-framework/runtime.test.ts index 264043fcb28fb..d078d2271c95c 100644 --- a/packages/@aws-cdk/custom-resources/test/provider-framework/runtime.test.ts +++ b/packages/@aws-cdk/custom-resources/test/provider-framework/runtime.test.ts @@ -349,18 +349,22 @@ describe('if CREATE fails, the subsequent DELETE will be ignored', () => { }); }); -test('foo', async () => { +test('getFunction() is called only when user function is inactive, pending, and active', async () => { // GIVEN + const getFunctionSpy = jest.spyOn(outbound, 'getFunction'); + mocks.onEventImplMock = async () => ({ PhysicalResourceId: MOCK_PHYSICAL_ID }); + mocks.isCompleteImplMock = async () => { + await outbound.invokeFunction({ FunctionName: mocks.MOCK_INACTIVE_FUNCTION_ARN, Payload: 'foo' }); + return { IsComplete: true }; + }; // WHEN - await outbound.invokeFunction({ - FunctionName: mocks.MOCK_INACTIVE_FUNCTION_ARN, + await simulateEvent({ + RequestType: 'Create', }); // THEN - // expect the mocked user function to have been called twice (once after getting inactive, and once after getting active) - // no errors ofc - + expect(getFunctionSpy).toHaveBeenCalledTimes(3); }); // ----------------------------------------------------------------------------------------------------------------------- From bc2eef646a8d472d444bd115b7fdee58f014f90d Mon Sep 17 00:00:00 2001 From: Calvin Combs Date: Wed, 3 Aug 2022 16:14:08 -0700 Subject: [PATCH 08/16] refactor to use iteration instead of recursion --- .../provider-framework/runtime/framework.ts | 41 +++++++++---------- .../test/provider-framework/runtime.test.ts | 4 +- 2 files changed, 21 insertions(+), 24 deletions(-) diff --git a/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts b/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts index bf69356fbdab0..274a30f8c4233 100644 --- a/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts +++ b/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts @@ -16,11 +16,6 @@ export = { const BASE_SLEEP = 10_000; const MAX_TOTAL_SLEEP = 620_000; -interface RetryOptions { - attempt: number, - totalSleep: number, -} - /** * The main runtime entrypoint of the async custom resource lambda function. * @@ -101,7 +96,11 @@ async function onTimeout(timeoutEvent: any) { }); } -async function invokeUserFunction(functionArnEnv: string, payload: any, retryOptions?: RetryOptions): Promise { +async function sleep(ms: number): Promise { + return new Promise(ok => setTimeout(ok, ms)); +} + +async function invokeUserFunction(functionArnEnv: string, payload: any): Promise { const functionArn = getEnv(functionArnEnv); log(`executing user function ${functionArn} with payload`, payload); @@ -122,26 +121,24 @@ async function invokeUserFunction(functionArnEnv: string, payload: any, retryOpt const jsonPayload = parseJsonPayload(resp.Payload); if (resp.FunctionError) { - const getFunctionResponse = await getFunction({ - FunctionName: functionName, - }); + let totalSleep = 0, attempt = 0; + while (totalSleep <= MAX_TOTAL_SLEEP) { + const getFunctionResponse = await getFunction({ + FunctionName: functionName, + }); + + if (!(getFunctionResponse.Configuration?.State === 'Inactive' || getFunctionResponse.Configuration?.State === 'Pending')) { + break; + } - if (getFunctionResponse.Configuration?.State === 'Inactive' || getFunctionResponse.Configuration?.State === 'Pending') { - const currentAttempt = retryOptions?.attempt ?? 1; - const newSleep = Math.floor(BASE_SLEEP * Math.pow(2, currentAttempt) * Math.random()); - const newTotalSleep = (retryOptions ? retryOptions.totalSleep : 0) + newSleep; + const currentSleep = Math.floor(BASE_SLEEP * Math.pow(2, attempt) * Math.random()); // don't spend more than 10 minutes and some change waiting - if (newTotalSleep <= MAX_TOTAL_SLEEP) { - const newRetryOptions: RetryOptions = { - attempt: currentAttempt + 1, - totalSleep: newTotalSleep, - }; - - log('user function is still being initialized by Lambda, retrying with delay of: ', newSleep); + log(`user function is still being initialized by Lambda, sleeping for: ${currentSleep} ms before retry`); + await sleep(currentSleep); - return setTimeout(invokeUserFunction, newSleep, functionArnEnv, payload, newRetryOptions); - } + totalSleep += currentSleep; + attempt++; } log('user function threw an error:', resp.FunctionError); diff --git a/packages/@aws-cdk/custom-resources/test/provider-framework/runtime.test.ts b/packages/@aws-cdk/custom-resources/test/provider-framework/runtime.test.ts index d078d2271c95c..c9e5a7cc347f0 100644 --- a/packages/@aws-cdk/custom-resources/test/provider-framework/runtime.test.ts +++ b/packages/@aws-cdk/custom-resources/test/provider-framework/runtime.test.ts @@ -18,8 +18,8 @@ outbound.httpRequest = mocks.httpRequestMock; outbound.invokeFunction = mocks.invokeFunctionMock; outbound.startExecution = mocks.startExecutionMock; outbound.getFunction = mocks.getFunctionMock; -(setTimeout as any) = jest.fn((callback, _timeout, functionargsEnv, payload, options) => { - return callback(functionargsEnv, payload, options); +(setTimeout as any) = jest.fn((callback, _timeout) => { + return callback(); }); beforeEach(() => mocks.setup()); From 830686cea316121a0282e7e12c03b6b31acd5e57 Mon Sep 17 00:00:00 2001 From: Calvin Combs Date: Wed, 3 Aug 2022 16:15:32 -0700 Subject: [PATCH 09/16] newline --- .../@aws-cdk/custom-resources/test/provider-framework/mocks.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/@aws-cdk/custom-resources/test/provider-framework/mocks.ts b/packages/@aws-cdk/custom-resources/test/provider-framework/mocks.ts index c16bdb48e7f1e..298cfa9059b9e 100644 --- a/packages/@aws-cdk/custom-resources/test/provider-framework/mocks.ts +++ b/packages/@aws-cdk/custom-resources/test/provider-framework/mocks.ts @@ -159,4 +159,4 @@ export async function getFunctionMock(_req: AWS.Lambda.GetFunctionRequest): Prom State: 'Active', }, }; -} \ No newline at end of file +} From ed3b5a7583d18eebf61618a45a0adc638801b58c Mon Sep 17 00:00:00 2001 From: Calvin Combs Date: Wed, 3 Aug 2022 16:17:45 -0700 Subject: [PATCH 10/16] move code --- .../lib/provider-framework/runtime/framework.ts | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts b/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts index 274a30f8c4233..283c3da58a906 100644 --- a/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts +++ b/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts @@ -96,10 +96,6 @@ async function onTimeout(timeoutEvent: any) { }); } -async function sleep(ms: number): Promise { - return new Promise(ok => setTimeout(ok, ms)); -} - async function invokeUserFunction(functionArnEnv: string, payload: any): Promise { const functionArn = getEnv(functionArnEnv); log(`executing user function ${functionArn} with payload`, payload); @@ -168,6 +164,10 @@ async function invokeUserFunction(functionArnEnv: string, payload: any): Promise return jsonPayload; } +async function sleep(ms: number): Promise { + return new Promise(ok => setTimeout(ok, ms)); +} + function parseJsonPayload(payload: any): any { if (!payload) { return { }; } const text = payload.toString(); From 4f7ebd175a92ef6e5c1519c8978d1b37d1b07279 Mon Sep 17 00:00:00 2001 From: Calvin Combs Date: Wed, 3 Aug 2022 16:29:36 -0700 Subject: [PATCH 11/16] merge conflict --- .../provider-framework/runtime/framework.ts | 19 ++++++++++++------- 1 file changed, 12 insertions(+), 7 deletions(-) diff --git a/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts b/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts index 283c3da58a906..12819a7b04565 100644 --- a/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts +++ b/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts @@ -27,11 +27,12 @@ const MAX_TOTAL_SLEEP = 620_000; * @param cfnRequest The cloudformation custom resource event. */ async function onEvent(cfnRequest: AWSLambda.CloudFormationCustomResourceEvent) { - log('onEventHandler', cfnRequest); + const sanitizedRequest = { ...cfnRequest, ResponseURL: '...' } as const; + log('onEventHandler', sanitizedRequest); cfnRequest.ResourceProperties = cfnRequest.ResourceProperties || { }; - const onEventResult = await invokeUserFunction(consts.USER_ON_EVENT_FUNCTION_ARN_ENV, cfnRequest) as OnEventResponse; + const onEventResult = await invokeUserFunction(consts.USER_ON_EVENT_FUNCTION_ARN_ENV, sanitizedRequest, cfnRequest.ResponseURL) as OnEventResponse; log('onEvent returned:', onEventResult); // merge the request and the result from onEvent to form the complete resource event @@ -60,9 +61,10 @@ async function onEvent(cfnRequest: AWSLambda.CloudFormationCustomResourceEvent) // invoked a few times until `complete` is true or until it times out. async function isComplete(event: AWSCDKAsyncCustomResource.IsCompleteRequest) { - log('isComplete', event); + const sanitizedRequest = { ...event, ResponseURL: '...' } as const; + log('isComplete', sanitizedRequest); - const isCompleteResult = await invokeUserFunction(consts.USER_IS_COMPLETE_FUNCTION_ARN_ENV, event) as IsCompleteResponse; + const isCompleteResult = await invokeUserFunction(consts.USER_IS_COMPLETE_FUNCTION_ARN_ENV, sanitizedRequest, event.ResponseURL) as IsCompleteResponse; log('user isComplete returned:', isCompleteResult); // if we are not complete, return false, and don't send a response back. @@ -96,16 +98,18 @@ async function onTimeout(timeoutEvent: any) { }); } -async function invokeUserFunction(functionArnEnv: string, payload: any): Promise { +async function invokeUserFunction(functionArnEnv: string, sanitizedPayload: A, responseUrl: string) { const functionArn = getEnv(functionArnEnv); - log(`executing user function ${functionArn} with payload`, payload); + log(`executing user function ${functionArn} with payload`, sanitizedPayload); // transient errors such as timeouts, throttling errors (429), and other // errors that aren't caused by a bad request (500 series) are retried // automatically by the JavaScript SDK. const resp = await invokeFunction({ FunctionName: functionArn, - Payload: JSON.stringify(payload), + + // Cannot strip 'ResponseURL' here as this would be a breaking change even though the downstream CR doesn't need it + Payload: JSON.stringify({ ...sanitizedPayload, ResponseURL: responseUrl }), }); log('user function response:', resp, typeof(resp)); @@ -119,6 +123,7 @@ async function invokeUserFunction(functionArnEnv: string, payload: any): Promise if (resp.FunctionError) { let totalSleep = 0, attempt = 0; while (totalSleep <= MAX_TOTAL_SLEEP) { + // if the user's lambda has become Inactive, we must retry the invocation until Lambda finishes provisioning resources for it. const getFunctionResponse = await getFunction({ FunctionName: functionName, }); From 6b0cf52d92d8e5691115723413b0f57a8421f6d5 Mon Sep 17 00:00:00 2001 From: Calvin Combs Date: Thu, 4 Aug 2022 16:05:22 -0700 Subject: [PATCH 12/16] fixed retry logic --- .../lib/provider-framework/runtime/framework.ts | 13 +++++++++++-- 1 file changed, 11 insertions(+), 2 deletions(-) diff --git a/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts b/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts index aeb79942a9845..19debcc018ca6 100644 --- a/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts +++ b/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts @@ -129,8 +129,17 @@ async function invokeUserFunction(functionArnE FunctionName: functionName, }); - if (!(getFunctionResponse.Configuration?.State === 'Inactive' || getFunctionResponse.Configuration?.State === 'Pending')) { - break; + if ((getFunctionResponse.Configuration?.State === 'Active') || getFunctionResponse.Configuration?.State === 'Failed') { + if (getFunctionResponse.Configuration?.State === 'Active') { + log('user function is in the \'Active\' state, reinvoking it now'); + } + if (getFunctionResponse.Configuration?.State === 'Failed') { + log('user function is in the \'Failed\' state with this reason code: ', getFunctionResponse.Configuration.StateReasonCode); + log('user function provided this reason for the error: ', getFunctionResponse.Configuration.StateReason); + log('reinvoking user function to get error trace'); + } + + return invokeUserFunction(functionArnEnv, sanitizedPayload, responseUrl); } const currentSleep = Math.floor(BASE_SLEEP * Math.pow(2, attempt) * Math.random()); From 74f3dc5a2742bb5f4d07a25a5f05ed6e2289a4e1 Mon Sep 17 00:00:00 2001 From: Calvin Combs Date: Fri, 5 Aug 2022 11:05:24 -0700 Subject: [PATCH 13/16] fixed testing --- .../lib/provider-framework/runtime/framework.ts | 2 +- .../test/provider-framework/mocks.ts | 12 +++++++++++- .../test/provider-framework/runtime.test.ts | 12 ++++++------ 3 files changed, 18 insertions(+), 8 deletions(-) diff --git a/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts b/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts index 19debcc018ca6..2af224ad0a21b 100644 --- a/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts +++ b/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts @@ -99,7 +99,7 @@ async function onTimeout(timeoutEvent: any) { }); } -async function invokeUserFunction(functionArnEnv: string, sanitizedPayload: A, responseUrl: string) { +async function invokeUserFunction(functionArnEnv: string, sanitizedPayload: A, responseUrl: string): Promise { const functionArn = getEnv(functionArnEnv); log(`executing user function ${functionArn} with payload`, sanitizedPayload); diff --git a/packages/@aws-cdk/custom-resources/test/provider-framework/mocks.ts b/packages/@aws-cdk/custom-resources/test/provider-framework/mocks.ts index 298cfa9059b9e..701a2cd30659e 100644 --- a/packages/@aws-cdk/custom-resources/test/provider-framework/mocks.ts +++ b/packages/@aws-cdk/custom-resources/test/provider-framework/mocks.ts @@ -11,7 +11,6 @@ export const MOCK_REQUEST = { export const MOCK_ON_EVENT_FUNCTION_ARN = 'arn:lambda:user:on:event'; export const MOCK_IS_COMPLETE_FUNCTION_ARN = 'arn:lambda:user:is:complete'; -export const MOCK_INACTIVE_FUNCTION_ARN = 'arn:lambda:user:is:inactive'; export const MOCK_SFN_ARN = 'arn:of:state:machine'; export let stringifyPayload = true; @@ -114,6 +113,17 @@ export async function invokeFunctionMock(req: AWS.Lambda.InvocationRequest): Pro } } +export async function invokeInactiveFunctionMock(_req: AWS.Lambda.InvocationRequest): Promise { + const ret = { + foo: 'bar', + }; + + return { + FunctionError: getFunctionInvokeCount <= 1 ? 'Lambda is initializing your function...' : undefined, + Payload: stringifyPayload ? JSON.stringify(ret) : ret, + }; +} + export function prepareForExecution() { startStateMachineInput = undefined; diff --git a/packages/@aws-cdk/custom-resources/test/provider-framework/runtime.test.ts b/packages/@aws-cdk/custom-resources/test/provider-framework/runtime.test.ts index c239c62b344b9..fd02ea8778870 100644 --- a/packages/@aws-cdk/custom-resources/test/provider-framework/runtime.test.ts +++ b/packages/@aws-cdk/custom-resources/test/provider-framework/runtime.test.ts @@ -23,9 +23,13 @@ outbound.getFunction = mocks.getFunctionMock; }); const invokeFunctionSpy = jest.spyOn(outbound, 'invokeFunction'); +const getFunctionSpy = jest.spyOn(outbound, 'getFunction'); beforeEach(() => mocks.setup()); -afterEach(() => invokeFunctionSpy.mockClear()); +afterEach(() => { + invokeFunctionSpy.mockClear(); + getFunctionSpy.mockClear(); +}); test('async flow: isComplete returns true only after 3 times', async () => { let isCompleteCalls = 0; @@ -354,12 +358,8 @@ describe('if CREATE fails, the subsequent DELETE will be ignored', () => { test('getFunction() is called only when user function is inactive, pending, and active', async () => { // GIVEN - const getFunctionSpy = jest.spyOn(outbound, 'getFunction'); mocks.onEventImplMock = async () => ({ PhysicalResourceId: MOCK_PHYSICAL_ID }); - mocks.isCompleteImplMock = async () => { - await outbound.invokeFunction({ FunctionName: mocks.MOCK_INACTIVE_FUNCTION_ARN, Payload: 'foo' }); - return { IsComplete: true }; - }; + outbound.invokeFunction = mocks.invokeInactiveFunctionMock; // WHEN await simulateEvent({ From 928fed72cbf5a3ba5fdc03b67782b226267f5292 Mon Sep 17 00:00:00 2001 From: Calvin Combs Date: Fri, 5 Aug 2022 11:31:07 -0700 Subject: [PATCH 14/16] elif --- .../lib/provider-framework/runtime/framework.ts | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts b/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts index 2af224ad0a21b..8617dd717925a 100644 --- a/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts +++ b/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts @@ -132,8 +132,7 @@ async function invokeUserFunction(functionArnE if ((getFunctionResponse.Configuration?.State === 'Active') || getFunctionResponse.Configuration?.State === 'Failed') { if (getFunctionResponse.Configuration?.State === 'Active') { log('user function is in the \'Active\' state, reinvoking it now'); - } - if (getFunctionResponse.Configuration?.State === 'Failed') { + } else if (getFunctionResponse.Configuration?.State === 'Failed') { log('user function is in the \'Failed\' state with this reason code: ', getFunctionResponse.Configuration.StateReasonCode); log('user function provided this reason for the error: ', getFunctionResponse.Configuration.StateReason); log('reinvoking user function to get error trace'); From 0257e5864aa59e473bc19c313bdb048513dda0ca Mon Sep 17 00:00:00 2001 From: Calvin Combs Date: Fri, 5 Aug 2022 13:00:37 -0700 Subject: [PATCH 15/16] fixed testing bug --- .../lib/provider-framework/runtime/framework.ts | 7 ++++--- .../test/provider-framework/runtime.test.ts | 8 ++++++-- 2 files changed, 10 insertions(+), 5 deletions(-) diff --git a/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts b/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts index 8617dd717925a..d05fbb5344e41 100644 --- a/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts +++ b/packages/@aws-cdk/custom-resources/lib/provider-framework/runtime/framework.ts @@ -99,7 +99,7 @@ async function onTimeout(timeoutEvent: any) { }); } -async function invokeUserFunction(functionArnEnv: string, sanitizedPayload: A, responseUrl: string): Promise { +async function invokeUserFunction(functionArnEnv: string, sanitizedPayload: A, responseUrl: string, reinvoke?: boolean): Promise { const functionArn = getEnv(functionArnEnv); log(`executing user function ${functionArn} with payload`, sanitizedPayload); @@ -129,7 +129,7 @@ async function invokeUserFunction(functionArnE FunctionName: functionName, }); - if ((getFunctionResponse.Configuration?.State === 'Active') || getFunctionResponse.Configuration?.State === 'Failed') { + if ((getFunctionResponse.Configuration?.State === 'Active' || getFunctionResponse.Configuration?.State === 'Failed') && !reinvoke) { if (getFunctionResponse.Configuration?.State === 'Active') { log('user function is in the \'Active\' state, reinvoking it now'); } else if (getFunctionResponse.Configuration?.State === 'Failed') { @@ -138,7 +138,8 @@ async function invokeUserFunction(functionArnE log('reinvoking user function to get error trace'); } - return invokeUserFunction(functionArnEnv, sanitizedPayload, responseUrl); + // do not reinvoke more than once + return invokeUserFunction(functionArnEnv, sanitizedPayload, responseUrl, true); } const currentSleep = Math.floor(BASE_SLEEP * Math.pow(2, attempt) * Math.random()); diff --git a/packages/@aws-cdk/custom-resources/test/provider-framework/runtime.test.ts b/packages/@aws-cdk/custom-resources/test/provider-framework/runtime.test.ts index fd02ea8778870..c4a666f9db184 100644 --- a/packages/@aws-cdk/custom-resources/test/provider-framework/runtime.test.ts +++ b/packages/@aws-cdk/custom-resources/test/provider-framework/runtime.test.ts @@ -22,10 +22,14 @@ outbound.getFunction = mocks.getFunctionMock; return callback(); }); -const invokeFunctionSpy = jest.spyOn(outbound, 'invokeFunction'); +let invokeFunctionSpy = jest.spyOn(outbound, 'invokeFunction'); const getFunctionSpy = jest.spyOn(outbound, 'getFunction'); -beforeEach(() => mocks.setup()); +beforeEach(() => { + outbound.invokeFunction = mocks.invokeFunctionMock; + invokeFunctionSpy = jest.spyOn(outbound, 'invokeFunction'); + mocks.setup(); +}); afterEach(() => { invokeFunctionSpy.mockClear(); getFunctionSpy.mockClear(); From 9baa34a4dafedf579c5f76e6f5103b5b29c7827f Mon Sep 17 00:00:00 2001 From: Calvin Combs Date: Fri, 5 Aug 2022 13:01:54 -0700 Subject: [PATCH 16/16] doc --- .../custom-resources/test/provider-framework/runtime.test.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/@aws-cdk/custom-resources/test/provider-framework/runtime.test.ts b/packages/@aws-cdk/custom-resources/test/provider-framework/runtime.test.ts index c4a666f9db184..fe3b048c1b15e 100644 --- a/packages/@aws-cdk/custom-resources/test/provider-framework/runtime.test.ts +++ b/packages/@aws-cdk/custom-resources/test/provider-framework/runtime.test.ts @@ -27,7 +27,7 @@ const getFunctionSpy = jest.spyOn(outbound, 'getFunction'); beforeEach(() => { outbound.invokeFunction = mocks.invokeFunctionMock; - invokeFunctionSpy = jest.spyOn(outbound, 'invokeFunction'); + invokeFunctionSpy = jest.spyOn(outbound, 'invokeFunction'); // has to be reset because one test changes outbound.invokeFunction mocks.setup(); }); afterEach(() => {