From 886faa2990b191a0dbd01dc58a88e09e342886b5 Mon Sep 17 00:00:00 2001 From: Sandy Tao Date: Mon, 14 Jul 2025 21:44:07 -0700 Subject: [PATCH] Log the 2 types of loop detection (#4193) --- packages/core/src/core/client.ts | 3 ++- .../src/services/loopDetectionService.test.ts | 21 +++++++++++++++++-- .../core/src/services/loopDetectionService.ts | 21 ++++++++++++++++++- .../clearcut-logger/clearcut-logger.ts | 14 +++++++++++++ .../clearcut-logger/event-metadata-key.ts | 7 +++++++ packages/core/src/telemetry/loggers.ts | 21 +++++++++++++++++++ packages/core/src/telemetry/types.ts | 20 +++++++++++++++++- 7 files changed, 102 insertions(+), 5 deletions(-) diff --git a/packages/core/src/core/client.ts b/packages/core/src/core/client.ts index b26856f0..80979812 100644 --- a/packages/core/src/core/client.ts +++ b/packages/core/src/core/client.ts @@ -101,7 +101,7 @@ export class GeminiClient { */ private readonly COMPRESSION_PRESERVE_THRESHOLD = 0.3; - private readonly loopDetector = new LoopDetectionService(); + private readonly loopDetector: LoopDetectionService; private lastPromptId?: string; constructor(private config: Config) { @@ -110,6 +110,7 @@ export class GeminiClient { } this.embeddingModel = config.getEmbeddingModel(); + this.loopDetector = new LoopDetectionService(config); } async initialize(contentGeneratorConfig: ContentGeneratorConfig) { diff --git a/packages/core/src/services/loopDetectionService.test.ts b/packages/core/src/services/loopDetectionService.test.ts index 915bedc0..f0d76166 100644 --- a/packages/core/src/services/loopDetectionService.test.ts +++ b/packages/core/src/services/loopDetectionService.test.ts @@ -4,7 +4,7 @@ * SPDX-License-Identifier: Apache-2.0 */ -import { describe, it, expect, beforeEach } from 'vitest'; +import { describe, it, expect, beforeEach, vi } from 'vitest'; import { LoopDetectionService } from './loopDetectionService.js'; import { GeminiEventType, @@ -12,15 +12,26 @@ import { ServerGeminiToolCallRequestEvent, } from '../core/turn.js'; import { ServerGeminiStreamEvent } from '../core/turn.js'; +import { Config } from '../config/config.js'; +import * as loggers from '../telemetry/loggers.js'; + +vi.mock('../telemetry/loggers.js', () => ({ + logLoopDetected: vi.fn(), +})); const TOOL_CALL_LOOP_THRESHOLD = 5; const CONTENT_LOOP_THRESHOLD = 10; describe('LoopDetectionService', () => { let service: LoopDetectionService; + let mockConfig: Config; beforeEach(() => { - service = new LoopDetectionService(); + mockConfig = { + getTelemetryEnabled: () => true, + } as unknown as Config; + service = new LoopDetectionService(mockConfig); + vi.clearAllMocks(); }); const createToolCallRequestEvent = ( @@ -48,6 +59,7 @@ describe('LoopDetectionService', () => { for (let i = 0; i < TOOL_CALL_LOOP_THRESHOLD - 1; i++) { expect(service.addAndCheck(event)).toBe(false); } + expect(loggers.logLoopDetected).not.toHaveBeenCalled(); }); it(`should detect a loop on the TOOL_CALL_LOOP_THRESHOLD-th identical call`, () => { @@ -56,6 +68,7 @@ describe('LoopDetectionService', () => { service.addAndCheck(event); } expect(service.addAndCheck(event)).toBe(true); + expect(loggers.logLoopDetected).toHaveBeenCalledTimes(1); }); it('should detect a loop on subsequent identical calls', () => { @@ -64,6 +77,7 @@ describe('LoopDetectionService', () => { service.addAndCheck(event); } expect(service.addAndCheck(event)).toBe(true); + expect(loggers.logLoopDetected).toHaveBeenCalledTimes(2); }); it('should not detect a loop for different tool calls', () => { @@ -91,6 +105,7 @@ describe('LoopDetectionService', () => { for (let i = 0; i < CONTENT_LOOP_THRESHOLD - 1; i++) { expect(service.addAndCheck(event)).toBe(false); } + expect(loggers.logLoopDetected).not.toHaveBeenCalled(); }); it(`should detect a loop on the CONTENT_LOOP_THRESHOLD-th identical content string`, () => { @@ -99,6 +114,7 @@ describe('LoopDetectionService', () => { service.addAndCheck(event); } expect(service.addAndCheck(event)).toBe(true); + expect(loggers.logLoopDetected).toHaveBeenCalledTimes(1); }); it('should not detect a loop for different content strings', () => { @@ -108,6 +124,7 @@ describe('LoopDetectionService', () => { expect(service.addAndCheck(event1)).toBe(false); expect(service.addAndCheck(event2)).toBe(false); } + expect(loggers.logLoopDetected).not.toHaveBeenCalled(); }); }); diff --git a/packages/core/src/services/loopDetectionService.ts b/packages/core/src/services/loopDetectionService.ts index 57e0980c..c1078f69 100644 --- a/packages/core/src/services/loopDetectionService.ts +++ b/packages/core/src/services/loopDetectionService.ts @@ -6,6 +6,9 @@ import { createHash } from 'crypto'; import { GeminiEventType, ServerGeminiStreamEvent } from '../core/turn.js'; +import { logLoopDetected } from '../telemetry/loggers.js'; +import { LoopDetectedEvent, LoopType } from '../telemetry/types.js'; +import { Config } from '../config/config.js'; const TOOL_CALL_LOOP_THRESHOLD = 5; const CONTENT_LOOP_THRESHOLD = 10; @@ -24,6 +27,11 @@ export class LoopDetectionService { private lastRepeatedSentence: string = ''; private sentenceRepetitionCount: number = 0; private partialContent: string = ''; + private config: Config; + + constructor(config: Config) { + this.config = config; + } private getToolCallKey(toolCall: { name: string; args: object }): string { const argsString = JSON.stringify(toolCall.args); @@ -59,7 +67,14 @@ export class LoopDetectionService { this.lastToolCallKey = key; this.toolCallRepetitionCount = 1; } - return this.toolCallRepetitionCount >= TOOL_CALL_LOOP_THRESHOLD; + if (this.toolCallRepetitionCount >= TOOL_CALL_LOOP_THRESHOLD) { + logLoopDetected( + this.config, + new LoopDetectedEvent(LoopType.CONSECUTIVE_IDENTICAL_TOOL_CALLS), + ); + return true; + } + return false; } private checkContentLoop(content: string): boolean { @@ -94,6 +109,10 @@ export class LoopDetectionService { } if (this.sentenceRepetitionCount >= CONTENT_LOOP_THRESHOLD) { + logLoopDetected( + this.config, + new LoopDetectedEvent(LoopType.CHANTING_IDENTICAL_SENTENCES), + ); return true; } } diff --git a/packages/core/src/telemetry/clearcut-logger/clearcut-logger.ts b/packages/core/src/telemetry/clearcut-logger/clearcut-logger.ts index 07c40c86..7beacb9b 100644 --- a/packages/core/src/telemetry/clearcut-logger/clearcut-logger.ts +++ b/packages/core/src/telemetry/clearcut-logger/clearcut-logger.ts @@ -15,6 +15,7 @@ import { ApiResponseEvent, ApiErrorEvent, FlashFallbackEvent, + LoopDetectedEvent, } from '../types.js'; import { EventMetadataKey } from './event-metadata-key.js'; import { Config } from '../../config/config.js'; @@ -33,6 +34,7 @@ const api_response_event_name = 'api_response'; const api_error_event_name = 'api_error'; const end_session_event_name = 'end_session'; const flash_fallback_event_name = 'flash_fallback'; +const loop_detected_event_name = 'loop_detected'; export interface LogResponse { nextRequestWaitMs?: number; @@ -448,6 +450,18 @@ export class ClearcutLogger { }); } + logLoopDetectedEvent(event: LoopDetectedEvent): void { + const data = [ + { + gemini_cli_key: EventMetadataKey.GEMINI_CLI_LOOP_DETECTED_TYPE, + value: JSON.stringify(event.loop_type), + }, + ]; + + this.enqueueLogEvent(this.createLogEvent(loop_detected_event_name, data)); + this.flushIfNeeded(); + } + logEndSessionEvent(event: EndSessionEvent): void { const data = [ { diff --git a/packages/core/src/telemetry/clearcut-logger/event-metadata-key.ts b/packages/core/src/telemetry/clearcut-logger/event-metadata-key.ts index 8e9d53f5..4a47488a 100644 --- a/packages/core/src/telemetry/clearcut-logger/event-metadata-key.ts +++ b/packages/core/src/telemetry/clearcut-logger/event-metadata-key.ts @@ -150,6 +150,13 @@ export enum EventMetadataKey { // Logs the total number of Google accounts ever used. GEMINI_CLI_GOOGLE_ACCOUNTS_COUNT = 37, + + // ========================================================================== + // Loop Detected Event Keys + // =========================================================================== + + // Logs the type of loop detected. + GEMINI_CLI_LOOP_DETECTED_TYPE = 38, } export function getEventMetadataKey( diff --git a/packages/core/src/telemetry/loggers.ts b/packages/core/src/telemetry/loggers.ts index 3cf3794b..25a35b5d 100644 --- a/packages/core/src/telemetry/loggers.ts +++ b/packages/core/src/telemetry/loggers.ts @@ -25,6 +25,7 @@ import { ToolCallEvent, UserPromptEvent, FlashFallbackEvent, + LoopDetectedEvent, } from './types.js'; import { recordApiErrorMetrics, @@ -288,3 +289,23 @@ export function logApiResponse(config: Config, event: ApiResponseEvent): void { ); recordTokenUsageMetrics(config, event.model, event.tool_token_count, 'tool'); } + +export function logLoopDetected( + config: Config, + event: LoopDetectedEvent, +): void { + ClearcutLogger.getInstance(config)?.logLoopDetectedEvent(event); + if (!isTelemetrySdkInitialized()) return; + + const attributes: LogAttributes = { + ...getCommonAttributes(config), + ...event, + }; + + const logger = logs.getLogger(SERVICE_NAME); + const logRecord: LogRecord = { + body: `Loop detected. Type: ${event.loop_type}.`, + attributes, + }; + logger.emit(logRecord); +} diff --git a/packages/core/src/telemetry/types.ts b/packages/core/src/telemetry/types.ts index d04756e2..54da0214 100644 --- a/packages/core/src/telemetry/types.ts +++ b/packages/core/src/telemetry/types.ts @@ -246,6 +246,23 @@ export class FlashFallbackEvent { } } +export enum LoopType { + CONSECUTIVE_IDENTICAL_TOOL_CALLS = 'consecutive_identical_tool_calls', + CHANTING_IDENTICAL_SENTENCES = 'chanting_identical_sentences', +} + +export class LoopDetectedEvent { + 'event.name': 'loop_detected'; + 'event.timestamp': string; // ISO 8601 + loop_type: LoopType; + + constructor(loop_type: LoopType) { + this['event.name'] = 'loop_detected'; + this['event.timestamp'] = new Date().toISOString(); + this.loop_type = loop_type; + } +} + export type TelemetryEvent = | StartSessionEvent | EndSessionEvent @@ -254,4 +271,5 @@ export type TelemetryEvent = | ApiRequestEvent | ApiErrorEvent | ApiResponseEvent - | FlashFallbackEvent; + | FlashFallbackEvent + | LoopDetectedEvent;