Skip to content

Commit ca778aa

Browse files
authored
Fix exp id logging (#13430)
1 parent 074d5d4 commit ca778aa

File tree

11 files changed

+92
-45
lines changed

11 files changed

+92
-45
lines changed

packages/cli/src/ui/components/ModelDialog.test.tsx

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -53,6 +53,7 @@ const renderComponent = (
5353
getUseSmartEdit: vi.fn(() => false),
5454
getProxy: vi.fn(() => undefined),
5555
isInteractive: vi.fn(() => false),
56+
getExperiments: () => {},
5657

5758
// --- Spread test-specific overrides ---
5859
...contextValue,

packages/cli/src/ui/hooks/useGeminiStream.test.tsx

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -223,6 +223,7 @@ describe('useGeminiStream', () => {
223223
.mockReturnValue(contentGeneratorConfig),
224224
getUseSmartEdit: () => false,
225225
isInteractive: () => false,
226+
getExperiments: () => {},
226227
} as unknown as Config;
227228
mockOnDebugMessage = vi.fn();
228229
mockHandleSlashCommand = vi.fn().mockResolvedValue(false);

packages/cli/src/ui/hooks/useToolScheduler.test.ts

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -80,6 +80,7 @@ const mockConfig = {
8080
getMessageBus: () => null,
8181
getPolicyEngine: () => null,
8282
isInteractive: () => false,
83+
getExperiments: () => {},
8384
} as unknown as Config;
8485

8586
const mockTool = new MockTool({

packages/core/src/config/config.ts

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -689,6 +689,17 @@ export class Config {
689689
this.inFallbackMode = false;
690690
}
691691

692+
async getExperimentsAsync(): Promise<Experiments | undefined> {
693+
if (this.experiments) {
694+
return this.experiments;
695+
}
696+
const codeAssistServer = getCodeAssistServer(this);
697+
if (codeAssistServer) {
698+
return getExperiments(codeAssistServer);
699+
}
700+
return undefined;
701+
}
702+
692703
getUserTier(): UserTierId | undefined {
693704
return this.contentGenerator?.userTier;
694705
}

packages/core/src/core/client.test.ts

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -241,6 +241,7 @@ describe('Gemini Client (client.ts)', () => {
241241
},
242242
},
243243
isInteractive: vi.fn().mockReturnValue(false),
244+
getExperiments: () => {},
244245
} as unknown as Config;
245246

246247
client = new GeminiClient(mockConfig);

packages/core/src/core/coreToolScheduler.test.ts

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -223,6 +223,7 @@ function createMockConfig(overrides: Partial<Config> = {}): Config {
223223
discoverTools: async () => {},
224224
getAllTools: () => [],
225225
getToolsByServer: () => [],
226+
getExperiments: () => {},
226227
} as unknown as ToolRegistry;
227228

228229
const baseConfig = {
@@ -252,6 +253,7 @@ function createMockConfig(overrides: Partial<Config> = {}): Config {
252253
getEnableMessageBusIntegration: () => false,
253254
getMessageBus: () => null,
254255
getPolicyEngine: () => null,
256+
getExperiments: () => {},
255257
} as unknown as Config;
256258

257259
return { ...baseConfig, ...overrides } as Config;

packages/core/src/core/nonInteractiveToolExecutor.test.ts

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -65,6 +65,7 @@ describe('executeToolCall', () => {
6565
getMessageBus: () => null,
6666
getPolicyEngine: () => null,
6767
isInteractive: () => false,
68+
getExperiments: () => {},
6869
} as unknown as Config;
6970

7071
abortController = new AbortController();

packages/core/src/telemetry/clearcut-logger/clearcut-logger.test.ts

Lines changed: 5 additions & 21 deletions
Original file line numberDiff line numberDiff line change
@@ -66,7 +66,6 @@ expect.extend({
6666
received: LogEventEntry[],
6767
[key, value]: [EventMetadataKey, string],
6868
) {
69-
const { isNot } = this;
7069
const event = JSON.parse(received[0].source_extension_json) as LogEvent;
7170
const metadata = event['event_metadata'][0];
7271
const data = metadata.find((m) => m.gemini_cli_key === key)?.value;
@@ -75,8 +74,7 @@ expect.extend({
7574

7675
return {
7776
pass,
78-
message: () =>
79-
`event ${received} does${isNot ? ' not' : ''} have ${value}}`,
77+
message: () => `event ${received} should have: ${value}. Found: ${data}`,
8078
};
8179
},
8280

@@ -93,21 +91,6 @@ expect.extend({
9391
`event ${received} ${isNot ? 'has' : 'does not have'} the metadata key ${key}`,
9492
};
9593
},
96-
97-
toHaveGwsExperiments(received: LogEventEntry[], expected_exps: number[]) {
98-
const { isNot } = this;
99-
const exps = received[0].gws_experiment;
100-
101-
const pass =
102-
exps.length === expected_exps.length &&
103-
exps.every((value, index) => value === expected_exps[index]);
104-
105-
return {
106-
pass,
107-
message: () =>
108-
`event ${received} ${isNot ? 'has' : 'does not have'} expected exp ids: ${expected_exps.join(',')}`,
109-
};
110-
},
11194
});
11295

11396
vi.mock('../../utils/userAccountManager.js');
@@ -618,7 +601,6 @@ describe('ClearcutLogger', () => {
618601
{
619602
event_time_ms: Date.now(),
620603
source_extension_json: JSON.stringify({ event_id: i }),
621-
gws_experiment: [],
622604
},
623605
]);
624606
}
@@ -652,7 +634,6 @@ describe('ClearcutLogger', () => {
652634
{
653635
event_time_ms: Date.now(),
654636
source_extension_json: JSON.stringify({ event_id: `failed_${i}` }),
655-
gws_experiment: [],
656637
},
657638
]);
658639
}
@@ -779,7 +760,10 @@ describe('ClearcutLogger', () => {
779760
const events = getEvents(logger!);
780761
expect(events.length).toBe(1);
781762
expect(events[0]).toHaveEventName(EventNames.AGENT_START);
782-
expect(events[0]).toHaveGwsExperiments([123, 456, 789]);
763+
expect(events[0]).toHaveMetadataValue([
764+
EventMetadataKey.GEMINI_CLI_EXPERIMENT_IDS,
765+
'123,456,789',
766+
]);
783767
});
784768
});
785769

packages/core/src/telemetry/clearcut-logger/clearcut-logger.ts

Lines changed: 65 additions & 24 deletions
Original file line numberDiff line numberDiff line change
@@ -103,7 +103,6 @@ export interface LogResponse {
103103
export interface LogEventEntry {
104104
event_time_ms: number;
105105
source_extension_json: string;
106-
gws_experiment: number[];
107106
}
108107

109108
export interface EventValue {
@@ -233,28 +232,55 @@ export class ClearcutLogger {
233232
ClearcutLogger.instance = undefined;
234233
}
235234

235+
enqueueHelper(event: LogEvent): void {
236+
// Manually handle overflow for FixedDeque, which throws when full.
237+
const wasAtCapacity = this.events.size >= MAX_EVENTS;
238+
239+
if (wasAtCapacity) {
240+
this.events.shift(); // Evict oldest element to make space.
241+
}
242+
243+
this.events.push([
244+
{
245+
event_time_ms: Date.now(),
246+
source_extension_json: safeJsonStringify(event),
247+
},
248+
]);
249+
250+
if (wasAtCapacity && this.config?.getDebugMode()) {
251+
debugLogger.debug(
252+
`ClearcutLogger: Dropped old event to prevent memory leak (queue size: ${this.events.size})`,
253+
);
254+
}
255+
}
256+
236257
enqueueLogEvent(event: LogEvent): void {
237258
try {
238-
// Manually handle overflow for FixedDeque, which throws when full.
239-
const wasAtCapacity = this.events.size >= MAX_EVENTS;
240-
241-
if (wasAtCapacity) {
242-
this.events.shift(); // Evict oldest element to make space.
259+
this.enqueueHelper(event);
260+
} catch (error) {
261+
if (this.config?.getDebugMode()) {
262+
console.error('ClearcutLogger: Failed to enqueue log event.', error);
243263
}
264+
}
265+
}
244266

245-
this.events.push([
246-
{
247-
event_time_ms: Date.now(),
248-
source_extension_json: safeJsonStringify(event),
249-
gws_experiment: this.config?.getExperiments()?.experimentIds ?? [],
250-
},
251-
]);
267+
async enqueueLogEventAfterExperimentsLoadAsync(
268+
event: LogEvent,
269+
): Promise<void> {
270+
try {
271+
this.config?.getExperimentsAsync().then((experiments) => {
272+
if (experiments) {
273+
const exp_id_data: EventValue[] = [
274+
{
275+
gemini_cli_key: EventMetadataKey.GEMINI_CLI_EXPERIMENT_IDS,
276+
value: experiments.experimentIds.toString() ?? 'NA',
277+
},
278+
];
279+
event.event_metadata = [[...event.event_metadata[0], ...exp_id_data]];
280+
}
252281

253-
if (wasAtCapacity && this.config?.getDebugMode()) {
254-
debugLogger.debug(
255-
`ClearcutLogger: Dropped old event to prevent memory leak (queue size: ${this.events.size})`,
256-
);
257-
}
282+
this.enqueueHelper(event);
283+
});
258284
} catch (error) {
259285
if (this.config?.getDebugMode()) {
260286
console.error('ClearcutLogger: Failed to enqueue log event.', error);
@@ -507,10 +533,13 @@ export class ClearcutLogger {
507533
];
508534
this.sessionData = data;
509535

510-
// Flush start event immediately
511-
this.enqueueLogEvent(this.createLogEvent(EventNames.START_SESSION, data));
512-
this.flushToClearcut().catch((error) => {
513-
debugLogger.debug('Error flushing to Clearcut:', error);
536+
// Flush after experiments finish loading from CCPA server
537+
this.enqueueLogEventAfterExperimentsLoadAsync(
538+
this.createLogEvent(EventNames.START_SESSION, data),
539+
).then(() => {
540+
this.flushToClearcut().catch((error) => {
541+
debugLogger.debug('Error flushing to Clearcut:', error);
542+
});
514543
});
515544
}
516545

@@ -847,8 +876,14 @@ export class ClearcutLogger {
847876
},
848877
];
849878

850-
this.enqueueLogEvent(this.createLogEvent(EventNames.IDE_CONNECTION, data));
851-
this.flushIfNeeded();
879+
// Flush after experiments finish loading from CCPA server
880+
this.enqueueLogEventAfterExperimentsLoadAsync(
881+
this.createLogEvent(EventNames.START_SESSION, data),
882+
).then(() => {
883+
this.flushToClearcut().catch((error) => {
884+
debugLogger.debug('Error flushing to Clearcut:', error);
885+
});
886+
});
852887
}
853888

854889
logConversationFinishedEvent(event: ConversationFinishedEvent): void {
@@ -1357,6 +1392,12 @@ export class ClearcutLogger {
13571392
value: this.config?.isInteractive().toString() ?? 'false',
13581393
},
13591394
];
1395+
if (this.config?.getExperiments()) {
1396+
defaultLogMetadata.push({
1397+
gemini_cli_key: EventMetadataKey.GEMINI_CLI_EXPERIMENT_IDS,
1398+
value: this.config?.getExperiments()?.experimentIds.toString() ?? 'NA',
1399+
});
1400+
}
13601401
return [...data, ...defaultLogMetadata];
13611402
}
13621403

packages/core/src/telemetry/clearcut-logger/event-metadata-key.ts

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -194,6 +194,9 @@ export enum EventMetadataKey {
194194
// Logs the name of the GitHub Action workflow that triggered the session.
195195
GEMINI_CLI_GH_WORKFLOW_NAME = 130,
196196

197+
// Logs the active experiment IDs for the session.
198+
GEMINI_CLI_EXPERIMENT_IDS = 131,
199+
197200
// ==========================================================================
198201
// Loop Detected Event Keys
199202
// ===========================================================================

0 commit comments

Comments
 (0)