From b8f9bfc352b9767d493cd30fd89436f4872fe8c8 Mon Sep 17 00:00:00 2001 From: kevin-ramdass Date: Tue, 10 Feb 2026 10:28:48 -0800 Subject: [PATCH 1/2] feat: Include experiment IDs in telemetry attributes, asynchronously loading them for event emission. --- packages/core/src/telemetry/loggers.test.ts | 53 ++++++++++++++++++- packages/core/src/telemetry/loggers.ts | 32 ++++++----- packages/core/src/telemetry/sanitize.test.ts | 2 + packages/core/src/telemetry/sdk.test.ts | 3 ++ .../core/src/telemetry/telemetryAttributes.ts | 5 ++ 5 files changed, 81 insertions(+), 14 deletions(-) diff --git a/packages/core/src/telemetry/loggers.test.ts b/packages/core/src/telemetry/loggers.test.ts index 246bed694d3..16da1032446 100644 --- a/packages/core/src/telemetry/loggers.test.ts +++ b/packages/core/src/telemetry/loggers.test.ts @@ -187,7 +187,7 @@ describe('loggers', () => { }); describe('logCliConfiguration', () => { - it('should log the cli configuration', () => { + it('should log the cli configuration', async () => { const mockConfig = { getSessionId: () => 'test-session-id', getModel: () => 'test-model', @@ -226,11 +226,14 @@ describe('loggers', () => { }), }), isInteractive: () => false, + getExperiments: () => undefined, + getExperimentsAsync: async () => undefined, } as unknown as Config; const startSessionEvent = new StartSessionEvent(mockConfig); logCliConfiguration(mockConfig, startSessionEvent); + await new Promise(process.nextTick); expect(mockLogger.emit).toHaveBeenCalledWith({ body: 'CLI configuration loaded.', attributes: { @@ -271,6 +274,8 @@ describe('loggers', () => { getTelemetryLogPromptsEnabled: () => true, getUsageStatisticsEnabled: () => true, isInteractive: () => false, + getExperiments: () => undefined, + getExperimentsAsync: async () => undefined, } as unknown as Config; it('should log a user prompt', () => { @@ -308,6 +313,8 @@ describe('loggers', () => { getTargetDir: () => 'target-dir', getUsageStatisticsEnabled: () => true, isInteractive: () => false, + getExperiments: () => undefined, + getExperimentsAsync: async () => undefined, } as unknown as Config; const event = new UserPromptEvent( 11, @@ -343,6 +350,8 @@ describe('loggers', () => { getTelemetryEnabled: () => true, getTelemetryLogPromptsEnabled: () => true, isInteractive: () => false, + getExperiments: () => undefined, + getExperimentsAsync: async () => undefined, } as Config; const mockMetrics = { @@ -519,6 +528,8 @@ describe('loggers', () => { getTelemetryEnabled: () => true, getTelemetryLogPromptsEnabled: () => true, isInteractive: () => false, + getExperiments: () => undefined, + getExperimentsAsync: async () => undefined, } as Config; const mockMetrics = { @@ -651,6 +662,8 @@ describe('loggers', () => { getTelemetryEnabled: () => true, getTelemetryLogPromptsEnabled: () => true, isInteractive: () => false, + getExperiments: () => undefined, + getExperimentsAsync: async () => undefined, getContentGeneratorConfig: () => ({ authType: AuthType.LOGIN_WITH_GOOGLE, }), @@ -727,6 +740,8 @@ describe('loggers', () => { getTelemetryEnabled: () => true, getTelemetryLogPromptsEnabled: () => true, // Enabled isInteractive: () => false, + getExperiments: () => undefined, + getExperimentsAsync: async () => undefined, getContentGeneratorConfig: () => ({ authType: AuthType.USE_GEMINI, }), @@ -814,6 +829,8 @@ describe('loggers', () => { getTelemetryEnabled: () => true, getTelemetryLogPromptsEnabled: () => false, // Disabled isInteractive: () => false, + getExperiments: () => undefined, + getExperimentsAsync: async () => undefined, getContentGeneratorConfig: () => ({ authType: AuthType.USE_VERTEX_AI, }), @@ -867,6 +884,8 @@ describe('loggers', () => { getTelemetryEnabled: () => true, getTelemetryLogPromptsEnabled: () => true, isInteractive: () => false, + getExperiments: () => undefined, + getExperimentsAsync: async () => undefined, getUsageStatisticsEnabled: () => true, getContentGeneratorConfig: () => ({ authType: AuthType.USE_GEMINI, @@ -903,6 +922,8 @@ describe('loggers', () => { getSessionId: () => 'test-session-id', getUsageStatisticsEnabled: () => true, isInteractive: () => false, + getExperiments: () => undefined, + getExperimentsAsync: async () => undefined, } as unknown as Config; it('should log flash fallback event', () => { @@ -930,6 +951,8 @@ describe('loggers', () => { getSessionId: () => 'test-session-id', getUsageStatisticsEnabled: () => true, isInteractive: () => false, + getExperiments: () => undefined, + getExperimentsAsync: async () => undefined, } as unknown as Config; beforeEach(() => { @@ -1024,6 +1047,8 @@ describe('loggers', () => { getTelemetryEnabled: () => true, getTelemetryLogPromptsEnabled: () => true, isInteractive: () => false, + getExperiments: () => undefined, + getExperimentsAsync: async () => undefined, } as Config; const mockMetrics = { @@ -1595,6 +1620,8 @@ describe('loggers', () => { getTelemetryEnabled: () => true, getTelemetryLogPromptsEnabled: () => true, isInteractive: () => false, + getExperiments: () => undefined, + getExperimentsAsync: async () => undefined, } as Config; const mockMetrics = { @@ -1655,6 +1682,8 @@ describe('loggers', () => { getSessionId: () => 'test-session-id', getUsageStatisticsEnabled: () => true, isInteractive: () => false, + getExperiments: () => undefined, + getExperimentsAsync: async () => undefined, } as unknown as Config; it('should log a tool output truncated event', () => { @@ -1692,6 +1721,8 @@ describe('loggers', () => { getSessionId: () => 'test-session-id', getUsageStatisticsEnabled: () => true, isInteractive: () => false, + getExperiments: () => undefined, + getExperimentsAsync: async () => undefined, } as unknown as Config; beforeEach(() => { @@ -1792,6 +1823,8 @@ describe('loggers', () => { getUsageStatisticsEnabled: () => true, getContentGeneratorConfig: () => null, isInteractive: () => false, + getExperiments: () => undefined, + getExperimentsAsync: async () => undefined, } as unknown as Config; beforeEach(() => { @@ -1842,6 +1875,8 @@ describe('loggers', () => { getUsageStatisticsEnabled: () => true, getContentGeneratorConfig: () => null, isInteractive: () => false, + getExperiments: () => undefined, + getExperimentsAsync: async () => undefined, } as unknown as Config; beforeEach(() => { @@ -1894,6 +1929,8 @@ describe('loggers', () => { getUsageStatisticsEnabled: () => true, getContentGeneratorConfig: () => null, isInteractive: () => false, + getExperiments: () => undefined, + getExperimentsAsync: async () => undefined, } as unknown as Config; beforeEach(() => { @@ -1938,6 +1975,8 @@ describe('loggers', () => { getSessionId: () => 'test-session-id', getUsageStatisticsEnabled: () => true, isInteractive: () => false, + getExperiments: () => undefined, + getExperimentsAsync: async () => undefined, } as unknown as Config; beforeEach(() => { @@ -1983,6 +2022,8 @@ describe('loggers', () => { getSessionId: () => 'test-session-id', getUsageStatisticsEnabled: () => true, isInteractive: () => false, + getExperiments: () => undefined, + getExperimentsAsync: async () => undefined, } as unknown as Config; beforeEach(() => { @@ -2028,6 +2069,8 @@ describe('loggers', () => { getSessionId: () => 'test-session-id', getUsageStatisticsEnabled: () => true, isInteractive: () => false, + getExperiments: () => undefined, + getExperimentsAsync: async () => undefined, } as unknown as Config; beforeEach(() => { @@ -2064,6 +2107,8 @@ describe('loggers', () => { getSessionId: () => 'test-session-id', getUsageStatisticsEnabled: () => true, isInteractive: () => false, + getExperiments: () => undefined, + getExperimentsAsync: async () => undefined, } as unknown as Config; beforeEach(() => { @@ -2115,6 +2160,8 @@ describe('loggers', () => { getSessionId: () => 'test-session-id', getUsageStatisticsEnabled: () => true, isInteractive: () => false, + getExperiments: () => undefined, + getExperimentsAsync: async () => undefined, } as unknown as Config; beforeEach(() => { @@ -2150,6 +2197,8 @@ describe('loggers', () => { getSessionId: () => 'test-session-id', getUsageStatisticsEnabled: () => true, isInteractive: () => false, + getExperiments: () => undefined, + getExperimentsAsync: async () => undefined, getTelemetryLogPromptsEnabled: () => false, } as unknown as Config; @@ -2205,7 +2254,7 @@ describe('loggers', () => { }); describe('Telemetry Buffering', () => { - it('should buffer events when SDK is not initialized', () => { + it('should buffer events when SDK is not initialized', async () => { vi.spyOn(sdk, 'isTelemetrySdkInitialized').mockReturnValue(false); const bufferSpy = vi .spyOn(sdk, 'bufferTelemetryEvent') diff --git a/packages/core/src/telemetry/loggers.ts b/packages/core/src/telemetry/loggers.ts index c3d1dbf6c6b..acf9c107d82 100644 --- a/packages/core/src/telemetry/loggers.ts +++ b/packages/core/src/telemetry/loggers.ts @@ -88,12 +88,16 @@ export function logCliConfiguration( ): void { void ClearcutLogger.getInstance(config)?.logStartSessionEvent(event); bufferTelemetryEvent(() => { - const logger = logs.getLogger(SERVICE_NAME); - const logRecord: LogRecord = { - body: event.toLogBody(), - attributes: event.toOpenTelemetryAttributes(config), - }; - logger.emit(logRecord); + // Wait for experiments to load before emitting so we capture experimentIds + // eslint-disable-next-line @typescript-eslint/no-floating-promises + config.getExperimentsAsync().then(() => { + const logger = logs.getLogger(SERVICE_NAME); + const logRecord: LogRecord = { + body: event.toLogBody(), + attributes: event.toOpenTelemetryAttributes(config), + }; + logger.emit(logRecord); + }); }); } @@ -780,11 +784,15 @@ export function logStartupStats( event: StartupStatsEvent, ): void { bufferTelemetryEvent(() => { - const logger = logs.getLogger(SERVICE_NAME); - const logRecord: LogRecord = { - body: event.toLogBody(), - attributes: event.toOpenTelemetryAttributes(config), - }; - logger.emit(logRecord); + // Wait for experiments to load before emitting so we capture experimentIds + // eslint-disable-next-line @typescript-eslint/no-floating-promises + config.getExperimentsAsync().then(() => { + const logger = logs.getLogger(SERVICE_NAME); + const logRecord: LogRecord = { + body: event.toLogBody(), + attributes: event.toOpenTelemetryAttributes(config), + }; + logger.emit(logRecord); + }); }); } diff --git a/packages/core/src/telemetry/sanitize.test.ts b/packages/core/src/telemetry/sanitize.test.ts index d60dc3bd786..9e179c75523 100644 --- a/packages/core/src/telemetry/sanitize.test.ts +++ b/packages/core/src/telemetry/sanitize.test.ts @@ -26,6 +26,8 @@ function createMockConfig(logPromptsEnabled: boolean): Config { return { getTelemetryLogPromptsEnabled: () => logPromptsEnabled, getSessionId: () => 'test-session-id', + getExperiments: () => undefined, + getExperimentsAsync: async () => undefined, getModel: () => 'gemini-1.5-flash', isInteractive: () => true, getUserEmail: () => undefined, diff --git a/packages/core/src/telemetry/sdk.test.ts b/packages/core/src/telemetry/sdk.test.ts index bf9ed83a449..020fee4738e 100644 --- a/packages/core/src/telemetry/sdk.test.ts +++ b/packages/core/src/telemetry/sdk.test.ts @@ -75,6 +75,8 @@ describe('Telemetry SDK', () => { getSessionId: () => 'test-session', getTelemetryUseCliAuth: () => false, isInteractive: () => false, + getExperiments: () => undefined, + getExperimentsAsync: async () => undefined, } as unknown as Config; }); @@ -353,6 +355,7 @@ describe('Telemetry SDK', () => { expect(callback).not.toHaveBeenCalled(); await initializeTelemetry(mockConfig); + await new Promise((resolve) => setTimeout(resolve, 10)); expect(callback).toHaveBeenCalled(); }); }); diff --git a/packages/core/src/telemetry/telemetryAttributes.ts b/packages/core/src/telemetry/telemetryAttributes.ts index 83593021f96..576f2ee13f6 100644 --- a/packages/core/src/telemetry/telemetryAttributes.ts +++ b/packages/core/src/telemetry/telemetryAttributes.ts @@ -14,10 +14,15 @@ const installationManager = new InstallationManager(); export function getCommonAttributes(config: Config): Attributes { const email = userAccountManager.getCachedGoogleAccount(); + const experiments = config.getExperiments(); return { 'session.id': config.getSessionId(), 'installation.id': installationManager.getInstallationId(), interactive: config.isInteractive(), ...(email && { 'user.email': email }), + ...(experiments && + experiments.experimentIds.length > 0 && { + 'experiments.ids': experiments.experimentIds, + }), }; } From 7d898095c00302eab33be206fa41511ccc09df2b Mon Sep 17 00:00:00 2001 From: kevin-ramdass Date: Tue, 10 Feb 2026 11:49:22 -0800 Subject: [PATCH 2/2] fix: add error handling to telemetry event logging by catching and logging promise rejections. --- packages/core/src/telemetry/loggers.ts | 45 +++++++++++++++----------- 1 file changed, 27 insertions(+), 18 deletions(-) diff --git a/packages/core/src/telemetry/loggers.ts b/packages/core/src/telemetry/loggers.ts index acf9c107d82..4699d50d703 100644 --- a/packages/core/src/telemetry/loggers.ts +++ b/packages/core/src/telemetry/loggers.ts @@ -81,6 +81,7 @@ import { bufferTelemetryEvent } from './sdk.js'; import type { UiEvent } from './uiTelemetry.js'; import { uiTelemetryService } from './uiTelemetry.js'; import { ClearcutLogger } from './clearcut-logger/clearcut-logger.js'; +import { debugLogger } from '../utils/debugLogger.js'; export function logCliConfiguration( config: Config, @@ -89,15 +90,19 @@ export function logCliConfiguration( void ClearcutLogger.getInstance(config)?.logStartSessionEvent(event); bufferTelemetryEvent(() => { // Wait for experiments to load before emitting so we capture experimentIds - // eslint-disable-next-line @typescript-eslint/no-floating-promises - config.getExperimentsAsync().then(() => { - const logger = logs.getLogger(SERVICE_NAME); - const logRecord: LogRecord = { - body: event.toLogBody(), - attributes: event.toOpenTelemetryAttributes(config), - }; - logger.emit(logRecord); - }); + void config + .getExperimentsAsync() + .then(() => { + const logger = logs.getLogger(SERVICE_NAME); + const logRecord: LogRecord = { + body: event.toLogBody(), + attributes: event.toOpenTelemetryAttributes(config), + }; + logger.emit(logRecord); + }) + .catch((e: unknown) => { + debugLogger.error('Failed to log telemetry event', e); + }); }); } @@ -785,14 +790,18 @@ export function logStartupStats( ): void { bufferTelemetryEvent(() => { // Wait for experiments to load before emitting so we capture experimentIds - // eslint-disable-next-line @typescript-eslint/no-floating-promises - config.getExperimentsAsync().then(() => { - const logger = logs.getLogger(SERVICE_NAME); - const logRecord: LogRecord = { - body: event.toLogBody(), - attributes: event.toOpenTelemetryAttributes(config), - }; - logger.emit(logRecord); - }); + void config + .getExperimentsAsync() + .then(() => { + const logger = logs.getLogger(SERVICE_NAME); + const logRecord: LogRecord = { + body: event.toLogBody(), + attributes: event.toOpenTelemetryAttributes(config), + }; + logger.emit(logRecord); + }) + .catch((e: unknown) => { + debugLogger.error('Failed to log telemetry event', e); + }); }); }