From 1918f4466be886e080481ebac7b47ac83bbae30d Mon Sep 17 00:00:00 2001 From: Shardul Natu <43422294+kiranani@users.noreply.github.com> Date: Sun, 24 Aug 2025 19:11:41 -0700 Subject: [PATCH] add(OTel): Add OTel logging for MalformedJsonEvent (#6912) Co-authored-by: Shnatu Co-authored-by: cornmander --- docs/telemetry.md | 4 +++ packages/core/src/core/client.ts | 5 ++-- packages/core/src/telemetry/constants.ts | 2 ++ packages/core/src/telemetry/loggers.test.ts | 30 +++++++++++++++++++++ packages/core/src/telemetry/loggers.ts | 23 ++++++++++++++++ 5 files changed, 62 insertions(+), 2 deletions(-) diff --git a/docs/telemetry.md b/docs/telemetry.md index 55dc8fb8..794975b7 100644 --- a/docs/telemetry.md +++ b/docs/telemetry.md @@ -220,6 +220,10 @@ Logs are timestamped records of specific events. The following events are logged - `response_text` (if applicable) - `auth_type` +- `gemini_cli.malformed_json_response`: This event occurs when a `generateJson` response from Gemini API cannot be parsed as a json. + - **Attributes**: + - `model` + - `gemini_cli.flash_fallback`: This event occurs when Gemini CLI switches to flash as fallback. - **Attributes**: - `auth_type` diff --git a/packages/core/src/core/client.ts b/packages/core/src/core/client.ts index d521ab18..64b6511d 100644 --- a/packages/core/src/core/client.ts +++ b/packages/core/src/core/client.ts @@ -46,13 +46,13 @@ import { ideContext } from '../ide/ideContext.js'; import { logChatCompression, logNextSpeakerCheck, + logMalformedJsonResponse, } from '../telemetry/loggers.js'; import { makeChatCompressionEvent, MalformedJsonResponseEvent, NextSpeakerCheckEvent, } from '../telemetry/types.js'; -import { ClearcutLogger } from '../telemetry/clearcut-logger/clearcut-logger.js'; import { IdeContext, File } from '../ide/ideContext.js'; function isThinkingSupported(model: string) { @@ -617,7 +617,8 @@ export class GeminiClient { const prefix = '```json'; const suffix = '```'; if (text.startsWith(prefix) && text.endsWith(suffix)) { - ClearcutLogger.getInstance(this.config)?.logMalformedJsonResponseEvent( + logMalformedJsonResponse( + this.config, new MalformedJsonResponseEvent(modelToUse), ); text = text diff --git a/packages/core/src/telemetry/constants.ts b/packages/core/src/telemetry/constants.ts index a058734b..5decd771 100644 --- a/packages/core/src/telemetry/constants.ts +++ b/packages/core/src/telemetry/constants.ts @@ -17,6 +17,8 @@ export const EVENT_NEXT_SPEAKER_CHECK = 'gemini_cli.next_speaker_check'; export const EVENT_SLASH_COMMAND = 'gemini_cli.slash_command'; export const EVENT_IDE_CONNECTION = 'gemini_cli.ide_connection'; export const EVENT_CHAT_COMPRESSION = 'gemini_cli.chat_compression'; +export const EVENT_MALFORMED_JSON_RESPONSE = + 'gemini_cli.malformed_json_response'; export const METRIC_TOOL_CALL_COUNT = 'gemini_cli.tool.call.count'; export const METRIC_TOOL_CALL_LATENCY = 'gemini_cli.tool.call.latency'; export const METRIC_API_REQUEST_COUNT = 'gemini_cli.api.request.count'; diff --git a/packages/core/src/telemetry/loggers.test.ts b/packages/core/src/telemetry/loggers.test.ts index e8706f3d..1221ac27 100644 --- a/packages/core/src/telemetry/loggers.test.ts +++ b/packages/core/src/telemetry/loggers.test.ts @@ -26,6 +26,7 @@ import { EVENT_TOOL_CALL, EVENT_USER_PROMPT, EVENT_FLASH_FALLBACK, + EVENT_MALFORMED_JSON_RESPONSE, } from './constants.js'; import { logApiRequest, @@ -35,6 +36,7 @@ import { logToolCall, logFlashFallback, logChatCompression, + logMalformedJsonResponse, } from './loggers.js'; import { ToolCallDecision } from './tool-call-decision.js'; import { @@ -44,6 +46,7 @@ import { ToolCallEvent, UserPromptEvent, FlashFallbackEvent, + MalformedJsonResponseEvent, makeChatCompressionEvent, } from './types.js'; import * as metrics from './metrics.js'; @@ -818,4 +821,31 @@ describe('loggers', () => { }); }); }); + + describe('logMalformedJsonResponse', () => { + beforeEach(() => { + vi.spyOn(ClearcutLogger.prototype, 'logMalformedJsonResponseEvent'); + }); + + it('logs the event to Clearcut and OTEL', () => { + const mockConfig = makeFakeConfig(); + const event = new MalformedJsonResponseEvent('test-model'); + + logMalformedJsonResponse(mockConfig, event); + + expect( + ClearcutLogger.prototype.logMalformedJsonResponseEvent, + ).toHaveBeenCalledWith(event); + + expect(mockLogger.emit).toHaveBeenCalledWith({ + body: 'Malformed JSON response from test-model.', + attributes: { + 'session.id': 'test-session-id', + 'event.name': EVENT_MALFORMED_JSON_RESPONSE, + 'event.timestamp': '2025-01-01T00:00:00.000Z', + model: 'test-model', + }, + }); + }); + }); }); diff --git a/packages/core/src/telemetry/loggers.ts b/packages/core/src/telemetry/loggers.ts index 29ccc226..dcf29f8f 100644 --- a/packages/core/src/telemetry/loggers.ts +++ b/packages/core/src/telemetry/loggers.ts @@ -20,6 +20,7 @@ import { SERVICE_NAME, EVENT_SLASH_COMMAND, EVENT_CHAT_COMPRESSION, + EVENT_MALFORMED_JSON_RESPONSE, } from './constants.js'; import { ApiErrorEvent, @@ -36,6 +37,7 @@ import { SlashCommandEvent, KittySequenceOverflowEvent, ChatCompressionEvent, + MalformedJsonResponseEvent, } from './types.js'; import { recordApiErrorMetrics, @@ -449,3 +451,24 @@ export function logKittySequenceOverflow( }; logger.emit(logRecord); } + +export function logMalformedJsonResponse( + config: Config, + event: MalformedJsonResponseEvent, +): void { + ClearcutLogger.getInstance(config)?.logMalformedJsonResponseEvent(event); + if (!isTelemetrySdkInitialized()) return; + + const attributes: LogAttributes = { + ...getCommonAttributes(config), + ...event, + 'event.name': EVENT_MALFORMED_JSON_RESPONSE, + }; + + const logger = logs.getLogger(SERVICE_NAME); + const logRecord: LogRecord = { + body: `Malformed JSON response from ${event.model}.`, + attributes, + }; + logger.emit(logRecord); +}