Fix exp id logging (#13430)

This commit is contained in:
owenofbrien
2025-11-21 14:44:50 -06:00
committed by GitHub
parent 0713c86dec
commit 64eb14ab11
11 changed files with 92 additions and 45 deletions
@@ -53,6 +53,7 @@ const renderComponent = (
getUseSmartEdit: vi.fn(() => false),
getProxy: vi.fn(() => undefined),
isInteractive: vi.fn(() => false),
getExperiments: () => {},
// --- Spread test-specific overrides ---
...contextValue,
@@ -223,6 +223,7 @@ describe('useGeminiStream', () => {
.mockReturnValue(contentGeneratorConfig),
getUseSmartEdit: () => false,
isInteractive: () => false,
getExperiments: () => {},
} as unknown as Config;
mockOnDebugMessage = vi.fn();
mockHandleSlashCommand = vi.fn().mockResolvedValue(false);
@@ -80,6 +80,7 @@ const mockConfig = {
getMessageBus: () => null,
getPolicyEngine: () => null,
isInteractive: () => false,
getExperiments: () => {},
} as unknown as Config;
const mockTool = new MockTool({
+11
View File
@@ -689,6 +689,17 @@ export class Config {
this.inFallbackMode = false;
}
async getExperimentsAsync(): Promise<Experiments | undefined> {
if (this.experiments) {
return this.experiments;
}
const codeAssistServer = getCodeAssistServer(this);
if (codeAssistServer) {
return getExperiments(codeAssistServer);
}
return undefined;
}
getUserTier(): UserTierId | undefined {
return this.contentGenerator?.userTier;
}
+1
View File
@@ -241,6 +241,7 @@ describe('Gemini Client (client.ts)', () => {
},
},
isInteractive: vi.fn().mockReturnValue(false),
getExperiments: () => {},
} as unknown as Config;
client = new GeminiClient(mockConfig);
@@ -223,6 +223,7 @@ function createMockConfig(overrides: Partial<Config> = {}): Config {
discoverTools: async () => {},
getAllTools: () => [],
getToolsByServer: () => [],
getExperiments: () => {},
} as unknown as ToolRegistry;
const baseConfig = {
@@ -252,6 +253,7 @@ function createMockConfig(overrides: Partial<Config> = {}): Config {
getEnableMessageBusIntegration: () => false,
getMessageBus: () => null,
getPolicyEngine: () => null,
getExperiments: () => {},
} as unknown as Config;
return { ...baseConfig, ...overrides } as Config;
@@ -65,6 +65,7 @@ describe('executeToolCall', () => {
getMessageBus: () => null,
getPolicyEngine: () => null,
isInteractive: () => false,
getExperiments: () => {},
} as unknown as Config;
abortController = new AbortController();
@@ -66,7 +66,6 @@ expect.extend({
received: LogEventEntry[],
[key, value]: [EventMetadataKey, string],
) {
const { isNot } = this;
const event = JSON.parse(received[0].source_extension_json) as LogEvent;
const metadata = event['event_metadata'][0];
const data = metadata.find((m) => m.gemini_cli_key === key)?.value;
@@ -75,8 +74,7 @@ expect.extend({
return {
pass,
message: () =>
`event ${received} does${isNot ? ' not' : ''} have ${value}}`,
message: () => `event ${received} should have: ${value}. Found: ${data}`,
};
},
@@ -93,21 +91,6 @@ expect.extend({
`event ${received} ${isNot ? 'has' : 'does not have'} the metadata key ${key}`,
};
},
toHaveGwsExperiments(received: LogEventEntry[], expected_exps: number[]) {
const { isNot } = this;
const exps = received[0].gws_experiment;
const pass =
exps.length === expected_exps.length &&
exps.every((value, index) => value === expected_exps[index]);
return {
pass,
message: () =>
`event ${received} ${isNot ? 'has' : 'does not have'} expected exp ids: ${expected_exps.join(',')}`,
};
},
});
vi.mock('../../utils/userAccountManager.js');
@@ -618,7 +601,6 @@ describe('ClearcutLogger', () => {
{
event_time_ms: Date.now(),
source_extension_json: JSON.stringify({ event_id: i }),
gws_experiment: [],
},
]);
}
@@ -652,7 +634,6 @@ describe('ClearcutLogger', () => {
{
event_time_ms: Date.now(),
source_extension_json: JSON.stringify({ event_id: `failed_${i}` }),
gws_experiment: [],
},
]);
}
@@ -779,7 +760,10 @@ describe('ClearcutLogger', () => {
const events = getEvents(logger!);
expect(events.length).toBe(1);
expect(events[0]).toHaveEventName(EventNames.AGENT_START);
expect(events[0]).toHaveGwsExperiments([123, 456, 789]);
expect(events[0]).toHaveMetadataValue([
EventMetadataKey.GEMINI_CLI_EXPERIMENT_IDS,
'123,456,789',
]);
});
});
@@ -103,7 +103,6 @@ export interface LogResponse {
export interface LogEventEntry {
event_time_ms: number;
source_extension_json: string;
gws_experiment: number[];
}
export interface EventValue {
@@ -233,28 +232,55 @@ export class ClearcutLogger {
ClearcutLogger.instance = undefined;
}
enqueueHelper(event: LogEvent): void {
// Manually handle overflow for FixedDeque, which throws when full.
const wasAtCapacity = this.events.size >= MAX_EVENTS;
if (wasAtCapacity) {
this.events.shift(); // Evict oldest element to make space.
}
this.events.push([
{
event_time_ms: Date.now(),
source_extension_json: safeJsonStringify(event),
},
]);
if (wasAtCapacity && this.config?.getDebugMode()) {
debugLogger.debug(
`ClearcutLogger: Dropped old event to prevent memory leak (queue size: ${this.events.size})`,
);
}
}
enqueueLogEvent(event: LogEvent): void {
try {
// Manually handle overflow for FixedDeque, which throws when full.
const wasAtCapacity = this.events.size >= MAX_EVENTS;
if (wasAtCapacity) {
this.events.shift(); // Evict oldest element to make space.
this.enqueueHelper(event);
} catch (error) {
if (this.config?.getDebugMode()) {
console.error('ClearcutLogger: Failed to enqueue log event.', error);
}
}
}
this.events.push([
{
event_time_ms: Date.now(),
source_extension_json: safeJsonStringify(event),
gws_experiment: this.config?.getExperiments()?.experimentIds ?? [],
},
]);
async enqueueLogEventAfterExperimentsLoadAsync(
event: LogEvent,
): Promise<void> {
try {
this.config?.getExperimentsAsync().then((experiments) => {
if (experiments) {
const exp_id_data: EventValue[] = [
{
gemini_cli_key: EventMetadataKey.GEMINI_CLI_EXPERIMENT_IDS,
value: experiments.experimentIds.toString() ?? 'NA',
},
];
event.event_metadata = [[...event.event_metadata[0], ...exp_id_data]];
}
if (wasAtCapacity && this.config?.getDebugMode()) {
debugLogger.debug(
`ClearcutLogger: Dropped old event to prevent memory leak (queue size: ${this.events.size})`,
);
}
this.enqueueHelper(event);
});
} catch (error) {
if (this.config?.getDebugMode()) {
console.error('ClearcutLogger: Failed to enqueue log event.', error);
@@ -507,10 +533,13 @@ export class ClearcutLogger {
];
this.sessionData = data;
// Flush start event immediately
this.enqueueLogEvent(this.createLogEvent(EventNames.START_SESSION, data));
this.flushToClearcut().catch((error) => {
debugLogger.debug('Error flushing to Clearcut:', error);
// Flush after experiments finish loading from CCPA server
this.enqueueLogEventAfterExperimentsLoadAsync(
this.createLogEvent(EventNames.START_SESSION, data),
).then(() => {
this.flushToClearcut().catch((error) => {
debugLogger.debug('Error flushing to Clearcut:', error);
});
});
}
@@ -847,8 +876,14 @@ export class ClearcutLogger {
},
];
this.enqueueLogEvent(this.createLogEvent(EventNames.IDE_CONNECTION, data));
this.flushIfNeeded();
// Flush after experiments finish loading from CCPA server
this.enqueueLogEventAfterExperimentsLoadAsync(
this.createLogEvent(EventNames.START_SESSION, data),
).then(() => {
this.flushToClearcut().catch((error) => {
debugLogger.debug('Error flushing to Clearcut:', error);
});
});
}
logConversationFinishedEvent(event: ConversationFinishedEvent): void {
@@ -1357,6 +1392,12 @@ export class ClearcutLogger {
value: this.config?.isInteractive().toString() ?? 'false',
},
];
if (this.config?.getExperiments()) {
defaultLogMetadata.push({
gemini_cli_key: EventMetadataKey.GEMINI_CLI_EXPERIMENT_IDS,
value: this.config?.getExperiments()?.experimentIds.toString() ?? 'NA',
});
}
return [...data, ...defaultLogMetadata];
}
@@ -194,6 +194,9 @@ export enum EventMetadataKey {
// Logs the name of the GitHub Action workflow that triggered the session.
GEMINI_CLI_GH_WORKFLOW_NAME = 130,
// Logs the active experiment IDs for the session.
GEMINI_CLI_EXPERIMENT_IDS = 131,
// ==========================================================================
// Loop Detected Event Keys
// ===========================================================================
@@ -116,6 +116,7 @@ describe('SmartEditTool', () => {
setGeminiMdFileCount: vi.fn(),
getToolRegistry: () => ({}) as any,
isInteractive: () => false,
getExperiments: () => {},
} as unknown as Config;
(mockConfig.getApprovalMode as Mock).mockClear();