Skip to content

Commit caa0f4c

Browse files
authored
feat(aws-cdk-lib): emits performance counters if synthesis is slow (#37919)
(This is a re-roll of #37843, to account for the warning emitted by `fs-extra` if it detects monkey patching) If the framework determines that synthesis is taking a long time (more than 10 seconds per stack, which is extremely unlikely high; we may adjust this threshold over time) it will emit a file with performance counters to the file indicated by the `$CDK_PERF_COUNTERS_FILE` environment variable. The CLI is responsible for sending this report in as telemetry, or not if disabled. The reporting can be disabled altogether by passing a property to `App`, or setting a context key in `cdk.json`: ```ts new App({ performanceReporting: false, }); ``` ```js { "context": { "aws:cdk:performance-reporting": false, }, } ``` Performance profiling works by making functions emit `measure` events to the Node [performance measurement APIs](https://nodejs.org/api/perf_hooks.html). The new `perf.ts` file provides a number of helper functions to decorate classes and functions to make them emit measurement information. A number of CDK APIs that we suspect of being slow are annotated by default, and some global NodeJS APIs that are typical sources of slowness (filesystem access, subprocess spawns) are annotated as well. CDK users are free to use these functions as well and the `printPerfCounters()` function to do their own profiling. At the end of synthesis, only those counters annotated with `{ telemetry: true }` are written to the telemetry file and sent to the server. Here is an example of a set of perf counters (extracted from a test): ```js { 'phase:Construction': 12154, 'phase:Construction(cnt)': 1, 'bundle:NodejsFunction': 12133, 'bundle:NodejsFunction(cnt)': 2, 'DockerImage.fromBuild': 10957, 'DockerImage.fromBuild(cnt)': 1, 'phase:Load': 3940, 'phase:Load(cnt)': 1, 'AssetBundlingBindMount.run': 1176, 'AssetBundlingBindMount.run(cnt)': 1, 'phase:Synthesis': 26, 'phase:Synthesis(cnt)': 1, 'Stack.resolve': 7, 'Stack.resolve(cnt)': 47, 'FileSystem.fingerprint': 1, 'FileSystem.fingerprint(cnt)': 1, 'FileSystem.isEmpty': 0, 'FileSystem.isEmpty(cnt)': 1 } ``` ---- *By submitting this pull request, I confirm that my contribution is made under the terms of the Apache-2.0 license* ### Issue # (if applicable) Closes #<issue number here>. ### Reason for this change ### Description of changes ### Describe any new or updated permissions being added ### Description of how you validated changes ### Checklist - [ ] My code adheres to the [CONTRIBUTING GUIDE](https://github.com/aws/aws-cdk/blob/main/CONTRIBUTING.md) and [DESIGN GUIDELINES](https://github.com/aws/aws-cdk/blob/main/docs/DESIGN_GUIDELINES.md) ---- *By submitting this pull request, I confirm that my contribution is made under the terms of the Apache-2.0 license*
1 parent dddc6e0 commit caa0f4c

19 files changed

Lines changed: 718 additions & 22 deletions

File tree

packages/@aws-cdk/aws-lambda-go-alpha/lib/bundling.ts

Lines changed: 21 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -3,6 +3,7 @@ import * as path from 'path';
33
import type { Architecture, AssetCode } from 'aws-cdk-lib/aws-lambda';
44
import { Code, Runtime } from 'aws-cdk-lib/aws-lambda';
55
import * as cdk from 'aws-cdk-lib/core';
6+
import { profileSpan } from 'aws-cdk-lib/core/lib/helpers-internal';
67
import type { BundlingOptions } from './types';
78
import { exec, findUp, getGoBuildVersion } from './util';
89

@@ -102,6 +103,8 @@ export class Bundling implements cdk.BundlingOptions {
102103

103104
private static runsLocally?: boolean;
104105

106+
public readonly [cdk.PERF_BUNDLING_SRC_SYM] = 'GoFunction';
107+
105108
// Core bundling options
106109
public readonly image: cdk.DockerImage;
107110
public readonly command: string[];
@@ -142,16 +145,28 @@ export class Bundling implements cdk.BundlingOptions {
142145

143146
// Docker bundling
144147
const shouldBuildImage = props.forcedDockerBundling || !Bundling.runsLocally;
145-
this.image = shouldBuildImage
146-
? props.dockerImage ?? cdk.DockerImage.fromBuild(path.join(__dirname, '..', 'lib'), {
148+
149+
if (shouldBuildImage && props.dockerImage) {
150+
// Use the user's image
151+
this.image = props.dockerImage;
152+
} else if (shouldBuildImage && !props.dockerImage) {
153+
// Build our own image to run esbuild in. We do some counter trickery here: we do want to count
154+
// the time spent here as part of 'bundle:GoFunction', but by default only the RUNNING of the Docker
155+
// image would count as that. So we add an additional timer span just for the building of the runner image.
156+
using _span = profileSpan(`bundle:${this[cdk.PERF_BUNDLING_SRC_SYM]}`, { telemetry: true, skipCount: true });
157+
158+
this.image = cdk.DockerImage.fromBuild(path.join(__dirname, '..', 'lib'), {
147159
buildArgs: {
148160
...props.buildArgs ?? {},
149161
IMAGE: Runtime.GO_1_X.bundlingImage.image, // always use the GO_1_X build image
150162
},
151163
platform: props.architecture.dockerPlatform,
152164
network: props.network,
153-
})
154-
: cdk.DockerImage.fromRegistry('dummy'); // Do not build if we don't need to
165+
});
166+
} else {
167+
// We won't use a Docker image, but this field must have a value.
168+
this.image = cdk.DockerImage.fromRegistry('dummy');
169+
}
155170

156171
const bundlingCommand = this.createBundlingCommand(cdk.AssetStaging.BUNDLING_INPUT_DIR, cdk.AssetStaging.BUNDLING_OUTPUT_DIR);
157172
this.command = props.command ?? ['bash', '-c', bundlingCommand];
@@ -177,6 +192,8 @@ export class Bundling implements cdk.BundlingOptions {
177192
return false;
178193
}
179194

195+
using _span = profileSpan('GoFunction#tryBundle', { telemetry: true });
196+
180197
const localCommand = createLocalCommand(outputDir);
181198
exec(
182199
osPlatform === 'win32' ? 'cmd' : 'bash',

packages/@aws-cdk/aws-lambda-python-alpha/lib/bundling.ts

Lines changed: 21 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -2,7 +2,8 @@ import * as path from 'path';
22
import type { AssetCode, Runtime } from 'aws-cdk-lib/aws-lambda';
33
import { Architecture, Code } from 'aws-cdk-lib/aws-lambda';
44
import type { BundlingFileAccess, BundlingOptions as CdkBundlingOptions, DockerVolume } from 'aws-cdk-lib/core';
5-
import { AssetStaging, DockerImage } from 'aws-cdk-lib/core';
5+
import { AssetStaging, DockerImage, PERF_BUNDLING_SRC_SYM } from 'aws-cdk-lib/core';
6+
import { profileSpan } from 'aws-cdk-lib/core/lib/helpers-internal';
67
import { Packaging, DependenciesFile } from './packaging';
78
import type { BundlingOptions, ICommandHooks } from './types';
89

@@ -64,6 +65,7 @@ export class Bundling implements CdkBundlingOptions {
6465
});
6566
}
6667

68+
public readonly [PERF_BUNDLING_SRC_SYM] = 'PythonFunction';
6769
public readonly image: DockerImage;
6870
public readonly entrypoint?: string[];
6971
public readonly command: string[];
@@ -101,14 +103,24 @@ export class Bundling implements CdkBundlingOptions {
101103
assetExcludes,
102104
});
103105

104-
this.image = image ?? DockerImage.fromBuild(path.join(__dirname, '..', 'lib'), {
105-
buildArgs: {
106-
...props.buildArgs,
107-
IMAGE: runtime.bundlingImage.image,
108-
},
109-
platform: architecture.dockerPlatform,
110-
network: props.network,
111-
});
106+
if (image) {
107+
// Use the user's image
108+
this.image = image;
109+
} else {
110+
// Build our own image to do the build in in. We do some counter trickery here: we do want to count
111+
// the time spent here as part of 'bundle:PythonFunction', but by default only the RUNNING of the Docker
112+
// image would count as that. So we add an additional timer span just for the building of the runner image.
113+
using _span = profileSpan(`bundle:${this[PERF_BUNDLING_SRC_SYM]}`, { telemetry: true, skipCount: true });
114+
this.image = DockerImage.fromBuild(path.join(__dirname, '..', 'lib'), {
115+
buildArgs: {
116+
...props.buildArgs,
117+
IMAGE: runtime.bundlingImage.image,
118+
},
119+
platform: architecture.dockerPlatform,
120+
network: props.network,
121+
});
122+
}
123+
112124
this.command = props.command ?? ['bash', '-c', chain(bundlingCommands)];
113125
this.entrypoint = props.entrypoint;
114126
this.volumes = props.volumes;

packages/aws-cdk-lib/aws-lambda-nodejs/lib/bundling.ts

Lines changed: 20 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -12,6 +12,7 @@ import { Code, Runtime } from '../../aws-lambda';
1212
import * as cdk from '../../core';
1313
import { AssumptionError, ValidationError } from '../../core';
1414
import { lit } from '../../core/lib/private/literal-string';
15+
import { profileFn, profileSpan } from '../../core/lib/private/perf';
1516
import { LAMBDA_NODEJS_SDK_V3_EXCLUDE_SMITHY_PACKAGES } from '../../cx-api';
1617

1718
const ESBUILD_MAJOR_VERSION = '0';
@@ -84,6 +85,8 @@ export class Bundling implements cdk.BundlingOptions {
8485
private static esbuildInstallation?: PackageInstallation;
8586
private static tscInstallation?: PackageInstallation;
8687

88+
public readonly [cdk.PERF_BUNDLING_SRC_SYM] = 'NodejsFunction';
89+
8790
// Core bundling options
8891
public readonly image: cdk.DockerImage;
8992
public readonly entrypoint?: string[];
@@ -183,8 +186,17 @@ export class Bundling implements cdk.BundlingOptions {
183186

184187
// Docker bundling
185188
const shouldBuildImage = props.forceDockerBundling || !Bundling.esbuildInstallation;
186-
this.image = shouldBuildImage ? props.dockerImage ?? cdk.DockerImage.fromBuild(path.join(__dirname, '..', 'lib'),
187-
{
189+
190+
if (shouldBuildImage && props.dockerImage) {
191+
// Use the user's image
192+
this.image = props.dockerImage;
193+
} else if (shouldBuildImage && !props.dockerImage) {
194+
// Build our own image to run esbuild in. We do some counter trickery here: we do want to count
195+
// the time spent here as part of 'bundle:NodejsFunction', but by default only the RUNNING of the Docker
196+
// image would count as that. So we add an additional timer span just for the building of the runner image.
197+
using _span = profileSpan(`bundle:${this[cdk.PERF_BUNDLING_SRC_SYM]}`, { telemetry: true, skipCount: true });
198+
199+
this.image = cdk.DockerImage.fromBuild(path.join(__dirname, '..', 'lib'), {
188200
buildArgs: {
189201
...props.buildArgs ?? {},
190202
// If runtime isn't passed use regional default, lowest common denominator is node18
@@ -193,8 +205,11 @@ export class Bundling implements cdk.BundlingOptions {
193205
},
194206
platform: props.architecture.dockerPlatform,
195207
network: props.network,
196-
})
197-
: cdk.DockerImage.fromRegistry('dummy'); // Do not build if we don't need to
208+
});
209+
} else {
210+
// We won't use a Docker image, but this field must have a value.
211+
this.image = cdk.DockerImage.fromRegistry('dummy');
212+
}
198213

199214
const bundlingCommand = this.createBundlingCommand(scope, {
200215
inputDir: cdk.AssetStaging.BUNDLING_INPUT_DIR,
@@ -455,6 +470,7 @@ export class Bundling implements cdk.BundlingOptions {
455470
return steps;
456471
}
457472

473+
@profileFn('NodejsFunction#tryBundle', { telemetry: true })
458474
private executeBundlingSteps(scope: IConstruct, steps: BundlingStep[]) {
459475
const cwd = this.projectRoot;
460476
const osPlatform = os.platform();

packages/aws-cdk-lib/aws-lambda-nodejs/test/e2e/bundling-e2e.test.ts

Lines changed: 58 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -4,7 +4,9 @@ import * as child_process from 'child_process';
44
import * as fs from 'fs';
55
import * as os from 'os';
66
import * as path from 'path';
7+
import { performance } from 'perf_hooks';
78
import type { SerializableNodejsFunctionProps } from './types';
9+
import { cx_api } from '../../..';
810
import { OutputFormat } from '../../lib';
911

1012
// Paths resolved once
@@ -73,6 +75,10 @@ const LOCK_FILES: Record<PackageManager, { name: string; content: string }> = {
7375
jest.setTimeout(3_000_000);
7476

7577
let project: TestProject;
78+
79+
beforeEach(() => {
80+
performance.clearMeasures();
81+
});
7682
afterEach(() => project?.cleanup());
7783

7884
describeDockerSuite((forceDockerBundling) => {
@@ -250,14 +256,64 @@ describeDockerSuite((forceDockerBundling) => {
250256
afterBundling: [],
251257
beforeBundling: [],
252258
beforeInstall: ['echo INSTALL > {outputDir}/install-marker.txt'],
253-
254259
},
255260
},
256261
});
257262

258263
const files = assetFiles(project.outdir);
259264
expect(files).toContain('install-marker.txt');
260265
});
266+
267+
test('performance counters are emitted', () => {
268+
project = createProject(pkgManager, '.ts');
269+
270+
const countersFile = path.join(project.outdir, 'counters.json');
271+
process.env[cx_api.PERF_COUNTERS_FILE_ENV] = countersFile;
272+
try {
273+
cdkSynth(project, {
274+
entry: project.entryFile,
275+
bundling: {
276+
forceDockerBundling,
277+
commandHooks: {
278+
beforeBundling: ['echo "export function init() { }" > {inputDir}/module.ts'],
279+
beforeInstall: [],
280+
afterBundling: [],
281+
},
282+
},
283+
context: {
284+
// If we don't set this, direct esbuild invocations are too fast to get emitted
285+
'@aws-cdk/core.slowSynthThreshold': '0',
286+
},
287+
});
288+
289+
// If beforeBundling failed, cdk synth would have failed (commands are chained with &&)
290+
const counters = JSON.parse(fs.readFileSync(countersFile, 'utf-8')).counters;
291+
292+
if (forceDockerBundling) {
293+
// Docker bundling has 2 counters: build the docker image, then run the docker image.
294+
// A single counter should encompass both of them.
295+
expect(counters).toMatchObject({
296+
'bundle:NodejsFunction': expect.anything(),
297+
'bundle:NodejsFunction(cnt)': 1,
298+
'DockerImage.fromBuild': expect.anything(),
299+
'AssetBundlingBindMount.run': expect.anything(),
300+
});
301+
302+
expect(counters['bundle:NodejsFunction']).toBeGreaterThanOrEqual(counters['DockerImage.fromBuild'] + counters['AssetBundlingBindMount.run']);
303+
} else {
304+
// Local bundling has 1 counter: do the bundling
305+
expect(counters).toMatchObject({
306+
'bundle:NodejsFunction': expect.anything(),
307+
'bundle:NodejsFunction(cnt)': 1,
308+
'NodejsFunction#tryBundle': expect.anything(),
309+
});
310+
311+
expect(counters['bundle:NodejsFunction']).toBeGreaterThanOrEqual(counters['NodejsFunction#tryBundle']);
312+
}
313+
} finally {
314+
delete process.env[cx_api.PERF_COUNTERS_FILE_ENV];
315+
}
316+
});
261317
});
262318
});
263319

@@ -513,6 +569,7 @@ function cdkSynth(proj: TestProject, config: SerializableNodejsFunctionProps): {
513569
'--no-path-metadata',
514570
'--no-asset-metadata',
515571
'--quiet',
572+
...Object.entries(config.context ?? {}).flatMap(([key, value]) => ['--context', `${key}=${value}`]),
516573
],
517574
{
518575
cwd: proj.dir,

packages/aws-cdk-lib/aws-lambda-nodejs/test/e2e/types.ts

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -8,6 +8,7 @@ export type SerializableNodejsFunctionProps = Omit<NodejsFunctionProps, 'runtime
88
forceDockerBundling: boolean;
99
commandHooks?: {[K in keyof ICommandHooks]: ReturnType<ICommandHooks[K]> };
1010
};
11+
context?: Record<string, string>;
1112
};
1213

1314
export type RuntimeKey = 'NODEJS_LATEST' | 'NODEJS_20_X' | 'NODEJS_22_X' | 'NODEJS_24_X';

0 commit comments

Comments
 (0)