From 5f5485cf0d2aee3cca6de4103e4347762b042ba6 Mon Sep 17 00:00:00 2001 From: 9pace Date: Thu, 5 Nov 2026 11:29:05 -0500 Subject: [PATCH 1/8] fix(cli): concurrent deploy telemetry events share an event id --- packages/aws-cdk/lib/cli/telemetry/session.ts | 6 ++++-- packages/aws-cdk/test/cli/telemetry/session.test.ts | 12 ++++++++++++ 2 files changed, 16 insertions(+), 2 deletions(-) diff --git a/packages/aws-cdk/lib/cli/telemetry/session.ts b/packages/aws-cdk/lib/cli/telemetry/session.ts index 0ab769a34..f396145a0 100644 --- a/packages/aws-cdk/lib/cli/telemetry/session.ts +++ b/packages/aws-cdk/lib/cli/telemetry/session.ts @@ -241,6 +241,8 @@ export class TelemetrySession { public async emit(event: TelemetryEvent): Promise { this.count += 1; + const eventId = `${this.sessionInfo.identifiers.sessionId}:${this.count}`; + const timestamp = new Date().toISOString(); const counters = { ...this._nextEventCounters, @@ -260,8 +262,8 @@ export class TelemetrySession { }, identifiers: { ...this.sessionInfo.identifiers, - eventId: `${this.sessionInfo.identifiers.sessionId}:${this.count}`, - timestamp: new Date().toISOString(), + eventId, + timestamp, }, environment: this.sessionInfo.environment, project: this.sessionInfo.project, diff --git a/packages/aws-cdk/test/cli/telemetry/session.test.ts b/packages/aws-cdk/test/cli/telemetry/session.test.ts index 556c9ceab..0a611dce0 100644 --- a/packages/aws-cdk/test/cli/telemetry/session.test.ts +++ b/packages/aws-cdk/test/cli/telemetry/session.test.ts @@ -114,6 +114,18 @@ describe('TelemetrySession', () => { })); }); + test('concurrent DEPLOY events get distinct event ids', async () => { + // WHEN: two stacks finish deploying at the same time, as with --concurrency + const first = session.emit({ eventType: 'DEPLOY', duration: 1234 }); + const second = session.emit({ eventType: 'DEPLOY', duration: 1234 }); + await first; + await second; + + // THEN + const sequenceNumbers = clientEmitSpy.mock.calls.map(([e]) => e.identifiers.eventId.split(':').pop()); + expect(sequenceNumbers.sort()).toEqual(['1', '2']); + }); + test('calling end more than once results in no-op', async () => { // GIVEN const spanEndSpy = jest.spyOn(session.commandSpan!, 'end'); From d35918751e84b7d401b7ad65b1999e92c6c03d7c Mon Sep 17 00:00:00 2001 From: 9pace Date: Thu, 5 Nov 2026 14:49:41 -0500 Subject: [PATCH 2/8] fix(cli): serialize deploy telemetry state updates and keep the event if they fail --- packages/aws-cdk/lib/cli/telemetry/session.ts | 33 +++++++++----- .../test/cli/telemetry/session.test.ts | 44 +++++++++++++++++++ 2 files changed, 65 insertions(+), 12 deletions(-) diff --git a/packages/aws-cdk/lib/cli/telemetry/session.ts b/packages/aws-cdk/lib/cli/telemetry/session.ts index f396145a0..b30162e45 100644 --- a/packages/aws-cdk/lib/cli/telemetry/session.ts +++ b/packages/aws-cdk/lib/cli/telemetry/session.ts @@ -64,6 +64,7 @@ export class TelemetrySession { private sigintListener?: () => void; private _nextEventCounters?: Record; private count = 0; + private stateUpdates: Promise = Promise.resolve(); private loadTime?: number; constructor(private readonly props: TelemetrySessionProps) { @@ -241,8 +242,12 @@ export class TelemetrySession { public async emit(event: TelemetryEvent): Promise { this.count += 1; - const eventId = `${this.sessionInfo.identifiers.sessionId}:${this.count}`; - const timestamp = new Date().toISOString(); + const { event: { command }, environment, project } = this.sessionInfo; + const identifiers = { + ...this.sessionInfo.identifiers, + eventId: `${this.sessionInfo.identifiers.sessionId}:${this.count}`, + timestamp: new Date().toISOString(), + }; const counters = { ...this._nextEventCounters, @@ -256,17 +261,13 @@ export class TelemetrySession { return this.client.emit({ event: { - command: this.sessionInfo.event.command, + command, state: getState(event.error), eventType: event.eventType, }, - identifiers: { - ...this.sessionInfo.identifiers, - eventId, - timestamp, - }, - environment: this.sessionInfo.environment, - project: this.sessionInfo.project, + identifiers, + environment, + project, duration: { total: event.duration, }, @@ -286,7 +287,8 @@ export class TelemetrySession { * failed DEPLOY events in a sequence. */ private async trackDeployStatistics(isSuccessful: boolean, counters: Record) { - await withTelemetryState((state) => { + // Concurrent deployments read and write the same state file, so update it one at a time. + const update = this.stateUpdates.then(() => withTelemetryState((state) => { const recentFailures = state.sequentialDeploymentFailures ?? 0; if (isSuccessful) { @@ -296,7 +298,14 @@ export class TelemetrySession { } counters.sequentialDeploymentFailures = state.sequentialDeploymentFailures; - }); + })); + this.stateUpdates = update.catch(() => undefined); + + try { + await update; + } catch (e: any) { + await this.ioHost.defaults.trace(`Failed to update telemetry state: ${e.message}`); + } } private get sessionInfo(): SessionSchema { diff --git a/packages/aws-cdk/test/cli/telemetry/session.test.ts b/packages/aws-cdk/test/cli/telemetry/session.test.ts index 0a611dce0..c1975d20f 100644 --- a/packages/aws-cdk/test/cli/telemetry/session.test.ts +++ b/packages/aws-cdk/test/cli/telemetry/session.test.ts @@ -7,6 +7,7 @@ import { CliIoHost } from '../../../lib/cli/io-host'; import { type TelemetrySchema } from '../../../lib/cli/telemetry/schema'; import { TelemetrySession, isValidWrapperUserAgent } from '../../../lib/cli/telemetry/session'; import { IoHostTelemetrySink } from '../../../lib/cli/telemetry/sink/io-host-sink'; +import * as telemetryState from '../../../lib/cli/telemetry/telemetry-state'; import { withEnv } from '../../_helpers/with-env'; let ioHost: CliIoHost; @@ -126,6 +127,49 @@ describe('TelemetrySession', () => { expect(sequenceNumbers.sort()).toEqual(['1', '2']); }); + test('concurrent failed DEPLOY events count every sequential failure', async () => { + // GIVEN: an in-memory state file whose reads and writes take a while, so updates overlap + let state: telemetryState.TelemetryState = {}; + const stateSpy = jest.spyOn(telemetryState, 'withTelemetryState').mockImplementation(async (block) => { + const copy = { ...state }; + await new Promise((resolve) => setTimeout(resolve, 10)); + const ret = block(copy); + state = copy; + return ret; + }); + + // WHEN + const error = { name: ToolkitError.name }; + const first = session.emit({ eventType: 'DEPLOY', duration: 1234, error }); + const second = session.emit({ eventType: 'DEPLOY', duration: 1234, error }); + const third = session.emit({ eventType: 'DEPLOY', duration: 1234, error }); + await first; + await second; + await third; + stateSpy.mockRestore(); + + // THEN + const failures = clientEmitSpy.mock.calls.map(([e]) => e.counters?.sequentialDeploymentFailures); + expect(failures.sort()).toEqual([1, 2, 3]); + expect(state.sequentialDeploymentFailures).toEqual(3); + }); + + test('DEPLOY event is still sent when the state file cannot be updated', async () => { + // GIVEN + const stateSpy = jest.spyOn(telemetryState, 'withTelemetryState').mockRejectedValue(new Error('EACCES')); + + // WHEN + await session.emit({ eventType: 'DEPLOY', duration: 1234 }); + stateSpy.mockRestore(); + + // THEN + expect(clientEmitSpy).toHaveBeenCalledTimes(1); + expect(clientEmitSpy.mock.calls[0][0]).toEqual(expect.objectContaining({ + event: expect.objectContaining({ eventType: 'DEPLOY' }), + })); + expect(clientEmitSpy.mock.calls[0][0].counters?.sequentialDeploymentFailures).toBeUndefined(); + }); + test('calling end more than once results in no-op', async () => { // GIVEN const spanEndSpy = jest.spyOn(session.commandSpan!, 'end'); From bee5b6242ab13e9d601c0cc36537b5baecd25f72 Mon Sep 17 00:00:00 2001 From: 9pace Date: Thu, 5 Nov 2026 15:12:04 -0500 Subject: [PATCH 3/8] test(cli): restore telemetry mocks after each session test --- packages/aws-cdk/test/cli/telemetry/session.test.ts | 10 ++++++---- 1 file changed, 6 insertions(+), 4 deletions(-) diff --git a/packages/aws-cdk/test/cli/telemetry/session.test.ts b/packages/aws-cdk/test/cli/telemetry/session.test.ts index c1975d20f..bef47f4d0 100644 --- a/packages/aws-cdk/test/cli/telemetry/session.test.ts +++ b/packages/aws-cdk/test/cli/telemetry/session.test.ts @@ -35,6 +35,10 @@ describe('TelemetrySession', () => { clientFlushSpy = jest.spyOn(client, 'flush'); }); + afterEach(() => { + jest.restoreAllMocks(); + }); + test('can emit data to the client', async () => { // WHEN await session.emit({ @@ -130,7 +134,7 @@ describe('TelemetrySession', () => { test('concurrent failed DEPLOY events count every sequential failure', async () => { // GIVEN: an in-memory state file whose reads and writes take a while, so updates overlap let state: telemetryState.TelemetryState = {}; - const stateSpy = jest.spyOn(telemetryState, 'withTelemetryState').mockImplementation(async (block) => { + jest.spyOn(telemetryState, 'withTelemetryState').mockImplementation(async (block) => { const copy = { ...state }; await new Promise((resolve) => setTimeout(resolve, 10)); const ret = block(copy); @@ -146,7 +150,6 @@ describe('TelemetrySession', () => { await first; await second; await third; - stateSpy.mockRestore(); // THEN const failures = clientEmitSpy.mock.calls.map(([e]) => e.counters?.sequentialDeploymentFailures); @@ -156,11 +159,10 @@ describe('TelemetrySession', () => { test('DEPLOY event is still sent when the state file cannot be updated', async () => { // GIVEN - const stateSpy = jest.spyOn(telemetryState, 'withTelemetryState').mockRejectedValue(new Error('EACCES')); + jest.spyOn(telemetryState, 'withTelemetryState').mockRejectedValue(new Error('EACCES')); // WHEN await session.emit({ eventType: 'DEPLOY', duration: 1234 }); - stateSpy.mockRestore(); // THEN expect(clientEmitSpy).toHaveBeenCalledTimes(1); From 96523c5b846f891fb07e92497628780ce6ef182f Mon Sep 17 00:00:00 2001 From: 9pace Date: Thu, 5 Nov 2026 16:08:08 -0500 Subject: [PATCH 4/8] test(cli): yield with a microtask instead of a timer in the state file mock --- packages/aws-cdk/test/cli/telemetry/session.test.ts | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/packages/aws-cdk/test/cli/telemetry/session.test.ts b/packages/aws-cdk/test/cli/telemetry/session.test.ts index bef47f4d0..09fdf7b19 100644 --- a/packages/aws-cdk/test/cli/telemetry/session.test.ts +++ b/packages/aws-cdk/test/cli/telemetry/session.test.ts @@ -132,11 +132,11 @@ describe('TelemetrySession', () => { }); test('concurrent failed DEPLOY events count every sequential failure', async () => { - // GIVEN: an in-memory state file whose reads and writes take a while, so updates overlap + // GIVEN: an in-memory state file that yields between read and write, so updates can overlap let state: telemetryState.TelemetryState = {}; jest.spyOn(telemetryState, 'withTelemetryState').mockImplementation(async (block) => { const copy = { ...state }; - await new Promise((resolve) => setTimeout(resolve, 10)); + await Promise.resolve(); const ret = block(copy); state = copy; return ret; From 80cac1a7f7646028d536078f03f7d6dd97c0f9a8 Mon Sep 17 00:00:00 2001 From: 9pace Date: Thu, 5 Nov 2026 16:28:47 -0500 Subject: [PATCH 5/8] refactor(cli): rename stateUpdates to lastStateUpdate --- packages/aws-cdk/lib/cli/telemetry/session.ts | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/packages/aws-cdk/lib/cli/telemetry/session.ts b/packages/aws-cdk/lib/cli/telemetry/session.ts index b30162e45..b488f17a6 100644 --- a/packages/aws-cdk/lib/cli/telemetry/session.ts +++ b/packages/aws-cdk/lib/cli/telemetry/session.ts @@ -64,7 +64,7 @@ export class TelemetrySession { private sigintListener?: () => void; private _nextEventCounters?: Record; private count = 0; - private stateUpdates: Promise = Promise.resolve(); + private lastStateUpdate: Promise = Promise.resolve(); private loadTime?: number; constructor(private readonly props: TelemetrySessionProps) { @@ -288,7 +288,7 @@ export class TelemetrySession { */ private async trackDeployStatistics(isSuccessful: boolean, counters: Record) { // Concurrent deployments read and write the same state file, so update it one at a time. - const update = this.stateUpdates.then(() => withTelemetryState((state) => { + const update = this.lastStateUpdate.then(() => withTelemetryState((state) => { const recentFailures = state.sequentialDeploymentFailures ?? 0; if (isSuccessful) { @@ -299,7 +299,7 @@ export class TelemetrySession { counters.sequentialDeploymentFailures = state.sequentialDeploymentFailures; })); - this.stateUpdates = update.catch(() => undefined); + this.lastStateUpdate = update.catch(() => undefined); try { await update; From b62c4e53803feb5455830b71fd647fbaabac59dc Mon Sep 17 00:00:00 2001 From: 9pace Date: Thu, 5 Nov 2026 16:36:04 -0500 Subject: [PATCH 6/8] test(cli): drop redundant event type check --- packages/aws-cdk/test/cli/telemetry/session.test.ts | 3 --- 1 file changed, 3 deletions(-) diff --git a/packages/aws-cdk/test/cli/telemetry/session.test.ts b/packages/aws-cdk/test/cli/telemetry/session.test.ts index 09fdf7b19..ac2c22bb9 100644 --- a/packages/aws-cdk/test/cli/telemetry/session.test.ts +++ b/packages/aws-cdk/test/cli/telemetry/session.test.ts @@ -166,9 +166,6 @@ describe('TelemetrySession', () => { // THEN expect(clientEmitSpy).toHaveBeenCalledTimes(1); - expect(clientEmitSpy.mock.calls[0][0]).toEqual(expect.objectContaining({ - event: expect.objectContaining({ eventType: 'DEPLOY' }), - })); expect(clientEmitSpy.mock.calls[0][0].counters?.sequentialDeploymentFailures).toBeUndefined(); }); From 5f87f85c453b8a5fe2e75a1e904ded78bdae6513 Mon Sep 17 00:00:00 2001 From: 9pace Date: Thu, 5 Nov 2026 16:38:53 -0500 Subject: [PATCH 7/8] test(cli): mock the state file in the event id test --- packages/aws-cdk/test/cli/telemetry/session.test.ts | 3 +++ 1 file changed, 3 insertions(+) diff --git a/packages/aws-cdk/test/cli/telemetry/session.test.ts b/packages/aws-cdk/test/cli/telemetry/session.test.ts index ac2c22bb9..d59226b73 100644 --- a/packages/aws-cdk/test/cli/telemetry/session.test.ts +++ b/packages/aws-cdk/test/cli/telemetry/session.test.ts @@ -120,6 +120,9 @@ describe('TelemetrySession', () => { }); test('concurrent DEPLOY events get distinct event ids', async () => { + // GIVEN + jest.spyOn(telemetryState, 'withTelemetryState').mockResolvedValue(undefined); + // WHEN: two stacks finish deploying at the same time, as with --concurrency const first = session.emit({ eventType: 'DEPLOY', duration: 1234 }); const second = session.emit({ eventType: 'DEPLOY', duration: 1234 }); From 0730b0da732cbe7e61df024578dd1f1172a762a7 Mon Sep 17 00:00:00 2001 From: 9pace Date: Thu, 5 Nov 2026 16:51:53 -0500 Subject: [PATCH 8/8] test(cli): check later deploys still count after a failed state update --- packages/aws-cdk/test/cli/telemetry/session.test.ts | 12 ++++++++---- 1 file changed, 8 insertions(+), 4 deletions(-) diff --git a/packages/aws-cdk/test/cli/telemetry/session.test.ts b/packages/aws-cdk/test/cli/telemetry/session.test.ts index d59226b73..c8ca7436e 100644 --- a/packages/aws-cdk/test/cli/telemetry/session.test.ts +++ b/packages/aws-cdk/test/cli/telemetry/session.test.ts @@ -156,20 +156,24 @@ describe('TelemetrySession', () => { // THEN const failures = clientEmitSpy.mock.calls.map(([e]) => e.counters?.sequentialDeploymentFailures); - expect(failures.sort()).toEqual([1, 2, 3]); + expect(failures).toEqual([1, 2, 3]); expect(state.sequentialDeploymentFailures).toEqual(3); }); - test('DEPLOY event is still sent when the state file cannot be updated', async () => { + test('DEPLOY event is still sent when the state file cannot be updated, and later ones are counted', async () => { // GIVEN - jest.spyOn(telemetryState, 'withTelemetryState').mockRejectedValue(new Error('EACCES')); + jest.spyOn(telemetryState, 'withTelemetryState') + .mockRejectedValueOnce(new Error('EACCES')) + .mockImplementation(async (block) => block({})); // WHEN await session.emit({ eventType: 'DEPLOY', duration: 1234 }); + await session.emit({ eventType: 'DEPLOY', duration: 1234, error: { name: ToolkitError.name } }); // THEN - expect(clientEmitSpy).toHaveBeenCalledTimes(1); + expect(clientEmitSpy).toHaveBeenCalledTimes(2); expect(clientEmitSpy.mock.calls[0][0].counters?.sequentialDeploymentFailures).toBeUndefined(); + expect(clientEmitSpy.mock.calls[1][0].counters?.sequentialDeploymentFailures).toEqual(1); }); test('calling end more than once results in no-op', async () => {