MediaMetz/gemini-cli
1
0
Fork 0
mirror of https://github.com/google-gemini/gemini-cli.git synced 2026-03-22 20:14:58 -07:00
Code Issues Packages Projects Releases Wiki Activity

feat(telemetry): Add content length to tool calls and log tool output truncation event (#8014)

Browse Source
This commit is contained in:
Sandy Tao
2025-09-11 08:40:46 -07:00
committed by GitHub
parent 8f4321b1ca
commit 095351bf39
10 changed files with 275 additions and 10 deletions
Download Patch File Download Diff File Expand all files Collapse all files

10
docs/telemetry.md
View File

@@ -194,6 +194,7 @@ Logs are timestamped records of specific events. The following events are logged
- `decision` (string: "accept", "reject", "auto_accept", or "modify", if applicable)
- `error` (if applicable)
- `error_type` (if applicable)
- `content_length` (int, if applicable)
- `metadata` (if applicable, dictionary of string -> any)
- `gemini_cli.file_operation`: This event occurs for each file operation.
@@ -238,6 +239,15 @@ Logs are timestamped records of specific events. The following events are logged
- `response_text` (if applicable)
- `auth_type`
- `gemini_cli.tool_output_truncated`: This event occurs when the output of a tool call is too large and gets truncated.
- **Attributes**:
- `tool_name` (string)
- `original_content_length` (int)
- `truncated_content_length` (int)
- `threshold` (int)
- `lines` (int)
- `prompt_id` (string)
- `gemini_cli.malformed_json_response`: This event occurs when a `generateJson` response from Gemini API cannot be parsed as a json.
- **Attributes**:
- `model`

39
packages/core/src/core/coreToolScheduler.ts
View File

@@ -25,6 +25,8 @@ import {
ToolErrorType,
ToolCallEvent,
ShellTool,
logToolOutputTruncated,
ToolOutputTruncatedEvent,
} from '../index.js';
import type { Part, PartListUnion } from '@google/genai';
import { getResponseTextFromParts } from '../utils/generateContentResponseUtilities.js';
@@ -245,6 +247,7 @@ const createErrorResponse = (
],
resultDisplay: error.message,
errorType,
contentLength: error.message.length,
});
export async function truncateAndSaveToFile(
@@ -461,6 +464,7 @@ export class CoreToolScheduler {
}
}
const errorMessage = `[Operation Cancelled] Reason: ${auxiliaryData}`;
return {
request: currentCall.request,
tool: toolInstance,
@@ -474,7 +478,7 @@ export class CoreToolScheduler {
id: currentCall.request.callId,
name: currentCall.request.name,
response: {
error: `[Operation Cancelled] Reason: ${auxiliaryData}`,
error: errorMessage,
},
},
},
@@ -482,6 +486,7 @@ export class CoreToolScheduler {
resultDisplay,
error: undefined,
errorType: undefined,
contentLength: errorMessage.length,
},
durationMs,
outcome,
@@ -975,6 +980,8 @@ export class CoreToolScheduler {
if (toolResult.error === undefined) {
let content = toolResult.llmContent;
let outputFile: string | undefined = undefined;
const contentLength =
typeof content === 'string' ? content.length : undefined;
if (
typeof content === 'string' &&
toolName === ShellTool.Name &&
@@ -982,13 +989,34 @@ export class CoreToolScheduler {
this.config.getTruncateToolOutputThreshold() > 0 &&
this.config.getTruncateToolOutputLines() > 0
) {
({ content, outputFile } = await truncateAndSaveToFile(
const originalContentLength = content.length;
const threshold = this.config.getTruncateToolOutputThreshold();
const lines = this.config.getTruncateToolOutputLines();
const truncatedResult = await truncateAndSaveToFile(
content,
callId,
this.config.storage.getProjectTempDir(),
this.config.getTruncateToolOutputThreshold(),
this.config.getTruncateToolOutputLines(),
));
threshold,
lines,
);
content = truncatedResult.content;
outputFile = truncatedResult.outputFile;
if (outputFile) {
logToolOutputTruncated(
this.config,
new ToolOutputTruncatedEvent(
scheduledCall.request.prompt_id,
{
toolName,
originalContentLength,
truncatedContentLength: content.length,
threshold,
lines,
},
),
);
}
}
const response = convertToFunctionResponse(
@@ -1003,6 +1031,7 @@ export class CoreToolScheduler {
error: undefined,
errorType: undefined,
outputFile,
contentLength,
};
this.setStatusInternal(callId, 'success', successResponse);
} else {

61
packages/core/src/core/nonInteractiveToolExecutor.test.ts
View File

@@ -88,6 +88,10 @@ describe('executeToolCall', () => {
errorType: undefined,
outputFile: undefined,
resultDisplay: 'Success!',
contentLength:
typeof toolResult.llmContent === 'string'
? toolResult.llmContent.length
: undefined,
responseParts: [
{
functionResponse: {
@@ -127,6 +131,7 @@ describe('executeToolCall', () => {
error: new Error(expectedErrorMessage),
errorType: ToolErrorType.TOOL_NOT_REGISTERED,
resultDisplay: expectedErrorMessage,
contentLength: expectedErrorMessage.length,
responseParts: [
{
functionResponse: {
@@ -176,6 +181,7 @@ describe('executeToolCall', () => {
},
],
resultDisplay: 'Invalid parameters',
contentLength: 'Invalid parameters'.length,
});
});
@@ -219,6 +225,7 @@ describe('executeToolCall', () => {
},
],
resultDisplay: 'Execution failed',
contentLength: 'Execution failed'.length,
});
});
@@ -246,6 +253,7 @@ describe('executeToolCall', () => {
error: new Error('Something went very wrong'),
errorType: ToolErrorType.UNHANDLED_EXCEPTION,
resultDisplay: 'Something went very wrong',
contentLength: 'Something went very wrong'.length,
responseParts: [
{
functionResponse: {
@@ -288,6 +296,7 @@ describe('executeToolCall', () => {
errorType: undefined,
outputFile: undefined,
resultDisplay: 'Image processed',
contentLength: undefined,
responseParts: [
{
functionResponse: {
@@ -302,4 +311,56 @@ describe('executeToolCall', () => {
],
});
});
it('should calculate contentLength for a string llmContent', async () => {
const request: ToolCallRequestInfo = {
callId: 'call7',
name: 'testTool',
args: {},
isClientInitiated: false,
prompt_id: 'prompt-id-7',
};
const toolResult: ToolResult = {
llmContent: 'This is a test string.',
returnDisplay: 'String returned',
};
vi.mocked(mockToolRegistry.getTool).mockReturnValue(mockTool);
mockTool.executeFn.mockReturnValue(toolResult);
const response = await executeToolCall(
mockConfig,
request,
abortController.signal,
);
expect(response.contentLength).toBe(
typeof toolResult.llmContent === 'string'
? toolResult.llmContent.length
: undefined,
);
});
it('should have undefined contentLength for array llmContent with no string parts', async () => {
const request: ToolCallRequestInfo = {
callId: 'call8',
name: 'testTool',
args: {},
isClientInitiated: false,
prompt_id: 'prompt-id-8',
};
const toolResult: ToolResult = {
llmContent: [{ inlineData: { mimeType: 'image/png', data: 'fakedata' } }],
returnDisplay: 'Image data returned',
};
vi.mocked(mockToolRegistry.getTool).mockReturnValue(mockTool);
mockTool.executeFn.mockReturnValue(toolResult);
const response = await executeToolCall(
mockConfig,
request,
abortController.signal,
);
expect(response.contentLength).toBeUndefined();
});
});

1
packages/core/src/core/turn.ts
View File

@@ -92,6 +92,7 @@ export interface ToolCallResponseInfo {
error: Error | undefined;
errorType: ToolErrorType | undefined;
outputFile?: string | undefined;
contentLength?: number;
}
export interface ServerToolCallConfirmationDetails {

39
packages/core/src/telemetry/clearcut-logger/clearcut-logger.ts
View File

@@ -25,6 +25,7 @@ import type {
ContentRetryEvent,
ContentRetryFailureEvent,
ExtensionInstallEvent,
ToolOutputTruncatedEvent,
} from '../types.js';
import { EventMetadataKey } from './event-metadata-key.js';
import type { Config } from '../../config/config.js';
@@ -58,6 +59,7 @@ export enum EventNames {
CONTENT_RETRY = 'content_retry',
CONTENT_RETRY_FAILURE = 'content_retry_failure',
EXTENSION_INSTALL = 'extension_install',
TOOL_OUTPUT_TRUNCATED = 'tool_output_truncated',
}
export interface LogResponse {
@@ -464,6 +466,10 @@ export class ClearcutLogger {
gemini_cli_key: EventMetadataKey.GEMINI_CLI_TOOL_TYPE,
value: JSON.stringify(event.tool_type),
},
{
gemini_cli_key: EventMetadataKey.GEMINI_CLI_TOOL_CALL_CONTENT_LENGTH,
value: JSON.stringify(event.content_length),
},
];
if (event.metadata) {
@@ -861,6 +867,39 @@ export class ClearcutLogger {
this.flushIfNeeded();
}
logToolOutputTruncatedEvent(event: ToolOutputTruncatedEvent): void {
const data: EventValue[] = [
{
gemini_cli_key: EventMetadataKey.GEMINI_CLI_TOOL_CALL_NAME,
value: JSON.stringify(event.tool_name),
},
{
gemini_cli_key:
EventMetadataKey.GEMINI_CLI_TOOL_OUTPUT_TRUNCATED_ORIGINAL_LENGTH,
value: JSON.stringify(event.original_content_length),
},
{
gemini_cli_key:
EventMetadataKey.GEMINI_CLI_TOOL_OUTPUT_TRUNCATED_TRUNCATED_LENGTH,
value: JSON.stringify(event.truncated_content_length),
},
{
gemini_cli_key:
EventMetadataKey.GEMINI_CLI_TOOL_OUTPUT_TRUNCATED_THRESHOLD,
value: JSON.stringify(event.threshold),
},
{
gemini_cli_key: EventMetadataKey.GEMINI_CLI_TOOL_OUTPUT_TRUNCATED_LINES,
value: JSON.stringify(event.lines),
},
];
this.enqueueLogEvent(
this.createLogEvent(EventNames.TOOL_OUTPUT_TRUNCATED, data),
);
this.flushIfNeeded();
}
/**
* Adds default fields to data, and returns a new data array. This fields
* should exist on all log events.

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

@@ -77,6 +77,9 @@ export enum EventMetadataKey {
// Logs the tool call error type, if any.
GEMINI_CLI_TOOL_CALL_ERROR_TYPE = 19,
// Logs the length of tool output
GEMINI_CLI_TOOL_CALL_CONTENT_LENGTH = 93,
// ==========================================================================
// GenAI API Request Event Keys
// ===========================================================================
@@ -347,4 +350,20 @@ export enum EventMetadataKey {
// Logs the status of the extension install.
GEMINI_CLI_EXTENSION_INSTALL_STATUS = 88,
// ==========================================================================
// Tool Output Truncated Event Keys
// ===========================================================================
// Logs the original length of the tool output.
GEMINI_CLI_TOOL_OUTPUT_TRUNCATED_ORIGINAL_LENGTH = 89,
// Logs the truncated length of the tool output.
GEMINI_CLI_TOOL_OUTPUT_TRUNCATED_TRUNCATED_LENGTH = 90,
// Logs the threshold at which the tool output was truncated.
GEMINI_CLI_TOOL_OUTPUT_TRUNCATED_THRESHOLD = 91,
// Logs the number of lines the tool output was truncated to.
GEMINI_CLI_TOOL_OUTPUT_TRUNCATED_LINES = 92,
}

2
packages/core/src/telemetry/index.ts
View File

@@ -30,6 +30,7 @@ export {
logConversationFinishedEvent,
logKittySequenceOverflow,
logChatCompression,
logToolOutputTruncated,
} from './loggers.js';
export type { SlashCommandEvent, ChatCompressionEvent } from './types.js';
export {
@@ -44,6 +45,7 @@ export {
ToolCallEvent,
ConversationFinishedEvent,
KittySequenceOverflowEvent,
ToolOutputTruncatedEvent,
} from './types.js';
export { makeSlashCommandEvent, makeChatCompressionEvent } from './types.js';
export type { TelemetryEvent } from './types.js';

55
packages/core/src/telemetry/loggers.test.ts
View File

@@ -44,6 +44,7 @@ import {
logMalformedJsonResponse,
logFileOperation,
logRipgrepFallback,
logToolOutputTruncated,
} from './loggers.js';
import { ToolCallDecision } from './tool-call-decision.js';
import {
@@ -57,6 +58,7 @@ import {
MalformedJsonResponseEvent,
makeChatCompressionEvent,
FileOperationEvent,
ToolOutputTruncatedEvent,
} from './types.js';
import * as metrics from './metrics.js';
import { FileOperation } from './metrics.js';
@@ -601,6 +603,7 @@ describe('loggers', () => {
},
error: undefined,
errorType: undefined,
contentLength: 13,
},
tool,
invocation: {} as AnyToolInvocation,
@@ -634,6 +637,7 @@ describe('loggers', () => {
tool_type: 'native',
error: undefined,
error_type: undefined,
metadata: {
model_added_lines: 1,
model_removed_lines: 2,
@@ -644,6 +648,7 @@ describe('loggers', () => {
user_added_chars: 7,
user_removed_chars: 8,
},
content_length: 13,
},
});
@@ -681,6 +686,7 @@ describe('loggers', () => {
resultDisplay: undefined,
error: undefined,
errorType: undefined,
contentLength: undefined,
},
durationMs: 100,
outcome: ToolConfirmationOutcome.Cancel,
@@ -713,6 +719,7 @@ describe('loggers', () => {
error: undefined,
error_type: undefined,
metadata: undefined,
content_length: undefined,
},
});
@@ -751,6 +758,7 @@ describe('loggers', () => {
resultDisplay: undefined,
error: undefined,
errorType: undefined,
contentLength: 13,
},
outcome: ToolConfirmationOutcome.ModifyWithEditor,
tool: new EditTool(mockConfig),
@@ -785,6 +793,7 @@ describe('loggers', () => {
error: undefined,
error_type: undefined,
metadata: undefined,
content_length: 13,
},
});
@@ -823,6 +832,7 @@ describe('loggers', () => {
resultDisplay: undefined,
error: undefined,
errorType: undefined,
contentLength: 13,
},
tool: new EditTool(mockConfig),
invocation: {} as AnyToolInvocation,
@@ -856,6 +866,7 @@ describe('loggers', () => {
error: undefined,
error_type: undefined,
metadata: undefined,
content_length: 13,
},
});
@@ -876,6 +887,7 @@ describe('loggers', () => {
});
it('should log a failed tool call with an error', () => {
const errorMessage = 'test-error';
const call: ErroredToolCall = {
status: 'error',
request: {
@@ -892,11 +904,9 @@ describe('loggers', () => {
callId: 'test-call-id',
responseParts: [{ text: 'test-response' }],
resultDisplay: undefined,
error: {
name: 'test-error-type',
message: 'test-error',
},
error: new Error(errorMessage),
errorType: ToolErrorType.UNKNOWN,
contentLength: errorMessage.length,
},
durationMs: 100,
};
@@ -930,6 +940,7 @@ describe('loggers', () => {
tool_type: 'native',
decision: undefined,
metadata: undefined,
content_length: errorMessage.length,
},
});
@@ -1035,4 +1046,40 @@ describe('loggers', () => {
);
});
});
describe('logToolOutputTruncated', () => {
const mockConfig = {
getSessionId: () => 'test-session-id',
getUsageStatisticsEnabled: () => true,
} as unknown as Config;
it('should log a tool output truncated event', () => {
const event = new ToolOutputTruncatedEvent('prompt-id-1', {
toolName: 'test-tool',
originalContentLength: 1000,
truncatedContentLength: 100,
threshold: 500,
lines: 10,
});
logToolOutputTruncated(mockConfig, event);
expect(mockLogger.emit).toHaveBeenCalledWith({
body: 'Tool output truncated for test-tool.',
attributes: {
'session.id': 'test-session-id',
'user.email': 'test-user@example.com',
'event.name': 'tool_output_truncated',
'event.timestamp': '2025-01-01T00:00:00.000Z',
eventName: 'tool_output_truncated',
prompt_id: 'prompt-id-1',
tool_name: 'test-tool',
original_content_length: 1000,
truncated_content_length: 100,
threshold: 500,
lines: 10,
},
});
});
});
});

23
packages/core/src/telemetry/loggers.ts
View File

@@ -50,6 +50,7 @@ import type {
ContentRetryEvent,
ContentRetryFailureEvent,
RipgrepFallbackEvent,
ToolOutputTruncatedEvent,
} from './types.js';
import {
recordApiErrorMetrics,
@@ -185,6 +186,28 @@ export function logToolCall(config: Config, event: ToolCallEvent): void {
);
}
export function logToolOutputTruncated(
config: Config,
event: ToolOutputTruncatedEvent,
): void {
ClearcutLogger.getInstance(config)?.logToolOutputTruncatedEvent(event);
if (!isTelemetrySdkInitialized()) return;
const attributes: LogAttributes = {
...getCommonAttributes(config),
...event,
'event.name': 'tool_output_truncated',
'event.timestamp': new Date().toISOString(),
};
const logger = logs.getLogger(SERVICE_NAME);
const logRecord: LogRecord = {
body: `Tool output truncated for ${event.tool_name}.`,
attributes,
};
logger.emit(logRecord);
}
export function logFileOperation(
config: Config,
event: FileOperationEvent,

36
packages/core/src/telemetry/types.ts
View File

@@ -136,6 +136,7 @@ export class ToolCallEvent implements BaseTelemetryEvent {
error_type?: string;
prompt_id: string;
tool_type: 'native' | 'mcp';
content_length?: number;
// eslint-disable-next-line @typescript-eslint/no-explicit-any
metadata?: { [key: string]: any };
@@ -156,6 +157,7 @@ export class ToolCallEvent implements BaseTelemetryEvent {
typeof call.tool !== 'undefined' && call.tool instanceof DiscoveredMCPTool
? 'mcp'
: 'native';
this.content_length = call.response.contentLength;
if (
call.status === 'success' &&
@@ -535,7 +537,8 @@ export type TelemetryEvent =
| InvalidChunkEvent
| ContentRetryEvent
| ContentRetryFailureEvent
| ExtensionInstallEvent;
| ExtensionInstallEvent
| ToolOutputTruncatedEvent;
export class ExtensionInstallEvent implements BaseTelemetryEvent {
'event.name': 'extension_install';
@@ -559,3 +562,34 @@ export class ExtensionInstallEvent implements BaseTelemetryEvent {
this.status = status;
}
}
export class ToolOutputTruncatedEvent implements BaseTelemetryEvent {
readonly eventName = 'tool_output_truncated';
readonly 'event.timestamp' = new Date().toISOString();
'event.name': string;
tool_name: string;
original_content_length: number;
truncated_content_length: number;
threshold: number;
lines: number;
prompt_id: string;
constructor(
prompt_id: string,
details: {
toolName: string;
originalContentLength: number;
truncatedContentLength: number;
threshold: number;
lines: number;
},
) {
this['event.name'] = this.eventName;
this.prompt_id = prompt_id;
this.tool_name = details.toolName;
this.original_content_length = details.originalContentLength;
this.truncated_content_length = details.truncatedContentLength;
this.threshold = details.threshold;
this.lines = details.lines;
}
}