diff options
Diffstat (limited to 'packages/core/src/telemetry/clearcut-logger/clearcut-logger.test.ts')
| -rw-r--r-- | packages/core/src/telemetry/clearcut-logger/clearcut-logger.test.ts | 181 |
1 files changed, 129 insertions, 52 deletions
diff --git a/packages/core/src/telemetry/clearcut-logger/clearcut-logger.test.ts b/packages/core/src/telemetry/clearcut-logger/clearcut-logger.test.ts index f2ce4d19..39596616 100644 --- a/packages/core/src/telemetry/clearcut-logger/clearcut-logger.test.ts +++ b/packages/core/src/telemetry/clearcut-logger/clearcut-logger.test.ts @@ -4,6 +4,7 @@ * SPDX-License-Identifier: Apache-2.0 */ +import 'vitest'; import { vi, describe, @@ -13,8 +14,13 @@ import { beforeAll, afterAll, } from 'vitest'; - -import { ClearcutLogger, LogEventEntry, TEST_ONLY } from './clearcut-logger.js'; +import { + ClearcutLogger, + LogEvent, + LogEventEntry, + EventNames, + TEST_ONLY, +} from './clearcut-logger.js'; import { ConfigParameters } from '../../config/config.js'; import * as userAccount from '../../utils/user_account.js'; import * as userId from '../../utils/user_id.js'; @@ -22,6 +28,48 @@ import { EventMetadataKey } from './event-metadata-key.js'; import { makeFakeConfig } from '../../test-utils/config.js'; import { http, HttpResponse } from 'msw'; import { server } from '../../mocks/msw.js'; +import { makeChatCompressionEvent } from '../types.js'; + +interface CustomMatchers<R = unknown> { + toHaveMetadataValue: ([key, value]: [EventMetadataKey, string]) => R; + toHaveEventName: (name: EventNames) => R; +} + +declare module 'vitest' { + // eslint-disable-next-line @typescript-eslint/no-explicit-any, @typescript-eslint/no-empty-object-type + interface Matchers<T = any> extends CustomMatchers<T> {} +} + +expect.extend({ + toHaveEventName(received: LogEventEntry[], name: EventNames) { + const { isNot } = this; + const event = JSON.parse(received[0].source_extension_json) as LogEvent; + const pass = event.event_name === (name as unknown as string); + return { + pass, + message: () => + `event name ${event.event_name} does${isNot ? ' not ' : ''} match ${name}}`, + }; + }, + + toHaveMetadataValue( + 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; + + const pass = data !== undefined && data === value; + + return { + pass, + message: () => + `event ${received} does${isNot ? ' not' : ''} have ${value}}`, + }; + }, +}); vi.mock('../../utils/user_account'); vi.mock('../../utils/user_id'); @@ -47,6 +95,7 @@ describe('ClearcutLogger', () => { const CLEARCUT_URL = 'https://play.googleapis.com/log'; const MOCK_DATE = new Date('2025-01-02T00:00:00.000Z'); const EXAMPLE_RESPONSE = `["${NEXT_WAIT_MS}",null,[[["ANDROID_BACKUP",0],["BATTERY_STATS",0],["SMART_SETUP",0],["TRON",0]],-3334737594024971225],[]]`; + // A helper to get the internal events array for testing const getEvents = (l: ClearcutLogger): LogEventEntry[][] => l['events'].toArray() as LogEventEntry[][]; @@ -130,7 +179,7 @@ describe('ClearcutLogger', () => { lifetimeGoogleAccounts: 9001, }); - const event = logger?.createLogEvent('abc', []); + const event = logger?.createLogEvent(EventNames.API_ERROR, []); expect(event?.event_metadata[0][0]).toEqual({ gemini_cli_key: EventMetadataKey.GEMINI_CLI_GOOGLE_ACCOUNTS_COUNT, @@ -138,26 +187,13 @@ describe('ClearcutLogger', () => { }); }); - it('logs the current surface from a github action', () => { - const { logger } = setup({}); - - vi.stubEnv('GITHUB_SHA', '8675309'); - - const event = logger?.createLogEvent('abc', []); - - expect(event?.event_metadata[0][1]).toEqual({ - gemini_cli_key: EventMetadataKey.GEMINI_CLI_SURFACE, - value: 'GitHub', - }); - }); - - it('honors the value from env.SURFACE over all others', () => { + it('logs the current surface', () => { const { logger } = setup({}); vi.stubEnv('TERM_PROGRAM', 'vscode'); vi.stubEnv('SURFACE', 'ide-1234'); - const event = logger?.createLogEvent('abc', []); + const event = logger?.createLogEvent(EventNames.API_ERROR, []); expect(event?.event_metadata[0][1]).toEqual({ gemini_cli_key: EventMetadataKey.GEMINI_CLI_SURFACE, @@ -209,7 +245,7 @@ describe('ClearcutLogger', () => { vi.stubEnv(key, value); } vi.stubEnv('TERM_PROGRAM', 'vscode'); - const event = logger?.createLogEvent('abc', []); + const event = logger?.createLogEvent(EventNames.API_ERROR, []); expect(event?.event_metadata[0][1]).toEqual({ gemini_cli_key: EventMetadataKey.GEMINI_CLI_SURFACE, value: expectedValue, @@ -218,10 +254,34 @@ describe('ClearcutLogger', () => { ); }); + describe('logChatCompressionEvent', () => { + it('logs an event with proper fields', () => { + const { logger } = setup(); + logger?.logChatCompressionEvent( + makeChatCompressionEvent({ + tokens_before: 9001, + tokens_after: 8000, + }), + ); + + const events = getEvents(logger!); + expect(events.length).toBe(1); + expect(events[0]).toHaveEventName(EventNames.CHAT_COMPRESSION); + expect(events[0]).toHaveMetadataValue([ + EventMetadataKey.GEMINI_CLI_COMPRESSION_TOKENS_BEFORE, + '9001', + ]); + expect(events[0]).toHaveMetadataValue([ + EventMetadataKey.GEMINI_CLI_COMPRESSION_TOKENS_AFTER, + '8000', + ]); + }); + }); + describe('enqueueLogEvent', () => { it('should add events to the queue', () => { const { logger } = setup(); - logger!.enqueueLogEvent({ test: 'event1' }); + logger!.enqueueLogEvent(logger!.createLogEvent(EventNames.API_ERROR)); expect(getEventsSize(logger!)).toBe(1); }); @@ -229,27 +289,43 @@ describe('ClearcutLogger', () => { const { logger } = setup(); for (let i = 0; i < TEST_ONLY.MAX_EVENTS; i++) { - logger!.enqueueLogEvent({ event_id: i }); + logger!.enqueueLogEvent( + logger!.createLogEvent(EventNames.API_ERROR, [ + { + gemini_cli_key: EventMetadataKey.GEMINI_CLI_AI_ADDED_LINES, + value: `${i}`, + }, + ]), + ); } - expect(getEventsSize(logger!)).toBe(TEST_ONLY.MAX_EVENTS); - const firstEvent = JSON.parse( - getEvents(logger!)[0][0].source_extension_json, - ); - expect(firstEvent.event_id).toBe(0); + let events = getEvents(logger!); + expect(events.length).toBe(TEST_ONLY.MAX_EVENTS); + expect(events[0]).toHaveMetadataValue([ + EventMetadataKey.GEMINI_CLI_AI_ADDED_LINES, + '0', + ]); // This should push out the first event - logger!.enqueueLogEvent({ event_id: TEST_ONLY.MAX_EVENTS }); - - expect(getEventsSize(logger!)).toBe(TEST_ONLY.MAX_EVENTS); - const newFirstEvent = JSON.parse( - getEvents(logger!)[0][0].source_extension_json, - ); - expect(newFirstEvent.event_id).toBe(1); - const lastEvent = JSON.parse( - getEvents(logger!)[TEST_ONLY.MAX_EVENTS - 1][0].source_extension_json, + logger!.enqueueLogEvent( + logger!.createLogEvent(EventNames.API_ERROR, [ + { + gemini_cli_key: EventMetadataKey.GEMINI_CLI_AI_ADDED_LINES, + value: `${TEST_ONLY.MAX_EVENTS}`, + }, + ]), ); - expect(lastEvent.event_id).toBe(TEST_ONLY.MAX_EVENTS); + events = getEvents(logger!); + expect(events.length).toBe(TEST_ONLY.MAX_EVENTS); + expect(events[0]).toHaveMetadataValue([ + EventMetadataKey.GEMINI_CLI_AI_ADDED_LINES, + '1', + ]); + + expect(events.at(TEST_ONLY.MAX_EVENTS - 1)).toHaveMetadataValue([ + EventMetadataKey.GEMINI_CLI_AI_ADDED_LINES, + `${TEST_ONLY.MAX_EVENTS}`, + ]); }); }); @@ -261,7 +337,7 @@ describe('ClearcutLogger', () => { }, }); - logger!.enqueueLogEvent({ event_id: 1 }); + logger!.enqueueLogEvent(logger!.createLogEvent(EventNames.API_ERROR)); const response = await logger!.flushToClearcut(); @@ -271,7 +347,7 @@ describe('ClearcutLogger', () => { it('should clear events on successful flush', async () => { const { logger } = setup(); - logger!.enqueueLogEvent({ event_id: 1 }); + logger!.enqueueLogEvent(logger!.createLogEvent(EventNames.API_ERROR)); const response = await logger!.flushToClearcut(); expect(getEvents(logger!)).toEqual([]); @@ -282,8 +358,8 @@ describe('ClearcutLogger', () => { const { logger } = setup(); server.resetHandlers(http.post(CLEARCUT_URL, () => HttpResponse.error())); - logger!.enqueueLogEvent({ event_id: 1 }); - logger!.enqueueLogEvent({ event_id: 2 }); + logger!.enqueueLogEvent(logger!.createLogEvent(EventNames.API_REQUEST)); + logger!.enqueueLogEvent(logger!.createLogEvent(EventNames.API_ERROR)); expect(getEventsSize(logger!)).toBe(2); const x = logger!.flushToClearcut(); @@ -291,7 +367,9 @@ describe('ClearcutLogger', () => { expect(getEventsSize(logger!)).toBe(2); const events = getEvents(logger!); - expect(JSON.parse(events[0][0].source_extension_json).event_id).toBe(1); + + expect(events.length).toBe(2); + expect(events[0]).toHaveEventName(EventNames.API_REQUEST); }); it('should handle an HTTP error and requeue events', async () => { @@ -310,23 +388,22 @@ describe('ClearcutLogger', () => { ), ); - logger!.enqueueLogEvent({ event_id: 1 }); - logger!.enqueueLogEvent({ event_id: 2 }); + logger!.enqueueLogEvent(logger!.createLogEvent(EventNames.API_REQUEST)); + logger!.enqueueLogEvent(logger!.createLogEvent(EventNames.API_ERROR)); expect(getEvents(logger!).length).toBe(2); await logger!.flushToClearcut(); - expect(getEvents(logger!).length).toBe(2); const events = getEvents(logger!); - expect(JSON.parse(events[0][0].source_extension_json).event_id).toBe(1); + + expect(events[0]).toHaveEventName(EventNames.API_REQUEST); }); }); describe('requeueFailedEvents logic', () => { it('should limit the number of requeued events to max_retry_events', () => { const { logger } = setup(); - const maxRetryEvents = TEST_ONLY.MAX_RETRY_EVENTS; - const eventsToLogCount = maxRetryEvents + 5; + const eventsToLogCount = TEST_ONLY.MAX_RETRY_EVENTS + 5; const eventsToSend: LogEventEntry[][] = []; for (let i = 0; i < eventsToLogCount; i++) { eventsToSend.push([ @@ -339,13 +416,13 @@ describe('ClearcutLogger', () => { requeueFailedEvents(logger!, eventsToSend); - expect(getEventsSize(logger!)).toBe(maxRetryEvents); + expect(getEventsSize(logger!)).toBe(TEST_ONLY.MAX_RETRY_EVENTS); const firstRequeuedEvent = JSON.parse( getEvents(logger!)[0][0].source_extension_json, - ); + ) as { event_id: string }; // The last `maxRetryEvents` are kept. The oldest of those is at index `eventsToLogCount - maxRetryEvents`. expect(firstRequeuedEvent.event_id).toBe( - eventsToLogCount - maxRetryEvents, + eventsToLogCount - TEST_ONLY.MAX_RETRY_EVENTS, ); }); @@ -355,7 +432,7 @@ describe('ClearcutLogger', () => { const spaceToLeave = 5; const initialEventCount = maxEvents - spaceToLeave; for (let i = 0; i < initialEventCount; i++) { - logger!.enqueueLogEvent({ event_id: `initial_${i}` }); + logger!.enqueueLogEvent(logger!.createLogEvent(EventNames.API_ERROR)); } expect(getEventsSize(logger!)).toBe(initialEventCount); @@ -382,7 +459,7 @@ describe('ClearcutLogger', () => { // The first element in the deque is the one with id 'failed_5'. const firstRequeuedEvent = JSON.parse( getEvents(logger!)[0][0].source_extension_json, - ); + ) as { event_id: string }; expect(firstRequeuedEvent.event_id).toBe('failed_5'); }); }); |