diff --git a/.vscode/launch.json b/.vscode/launch.json index 5f023be65b..8d273b2a3d 100644 --- a/.vscode/launch.json +++ b/.vscode/launch.json @@ -14,9 +14,9 @@ "sourceMaps": true, "outFiles": ["${workspaceFolder}/src/dist/**/*.js"], "preLaunchTask": "${defaultBuildTask}", + "envFile": "${workspaceFolder}/.env.local", "env": { - "NODE_ENV": "development", - "VSCODE_DEBUG_MODE": "true" + "NODE_ENV": "development" }, "resolveSourceMapLocations": ["${workspaceFolder}/**", "!**/node_modules/**"], "presentation": { diff --git a/src/api/core/logging/__tests__/api-logger.spec.ts b/src/api/core/logging/__tests__/api-logger.spec.ts new file mode 100644 index 0000000000..088dafa638 --- /dev/null +++ b/src/api/core/logging/__tests__/api-logger.spec.ts @@ -0,0 +1,381 @@ +/** + * @fileoverview Tests for the centralized API logging service + */ + +// Mock env-config to control logging in tests +vi.mock("../env-config", () => ({ + isLoggingEnabled: vi.fn(() => true), +})) + +import { ApiLogger, ApiLoggerService } from "../api-logger" +import type { ApiLogContext, ApiRequestLog, ApiResponseLog } from "../types" +import { isLoggingEnabled } from "../env-config" + +describe("ApiLoggerService", () => { + let consoleLogSpy: ReturnType + let consoleErrorSpy: ReturnType + + beforeEach(() => { + vi.clearAllMocks() + // Enable logging via mocked isLoggingEnabled + vi.mocked(isLoggingEnabled).mockReturnValue(true) + // Mock console.log and console.error + consoleLogSpy = vi.spyOn(console, "log").mockImplementation(() => {}) + consoleErrorSpy = vi.spyOn(console, "error").mockImplementation(() => {}) + // Reset to default configuration + ApiLogger.configure({ + enabled: true, + logRequests: true, + logResponses: true, + logErrors: true, + onLog: undefined, + }) + ApiLogger.clearTimestamps() + }) + + afterEach(() => { + consoleLogSpy.mockRestore() + consoleErrorSpy.mockRestore() + }) + + describe("logRequest", () => { + const baseContext: Omit = { + provider: "test-provider", + model: "test-model", + operation: "createMessage", + taskId: "task-123", + } + + const baseRequest = { + systemPromptLength: 100, + messageCount: 5, + hasTools: true, + toolCount: 3, + stream: true, + } + + it("should generate and return a unique requestId", () => { + const requestId = ApiLogger.logRequest(baseContext, baseRequest) + + expect(requestId).toMatch(/^req_\d+_[a-z0-9]+$/) + }) + + it("should generate unique requestIds for each call", () => { + const requestId1 = ApiLogger.logRequest(baseContext, baseRequest) + const requestId2 = ApiLogger.logRequest(baseContext, baseRequest) + + expect(requestId1).not.toBe(requestId2) + }) + + it("should log request details to the logger", () => { + ApiLogger.logRequest(baseContext, baseRequest) + + // First call is the request header + expect(consoleLogSpy).toHaveBeenCalledWith("[API Request] test-provider test-model createMessage") + // Second call is the metadata (since no rawBody) + expect(consoleLogSpy).toHaveBeenCalledWith( + "[API Request Metadata]", + expect.objectContaining({ + taskId: "task-123", + messageCount: 5, + hasTools: true, + toolCount: 3, + stream: true, + }), + ) + }) + + it("should log raw body when provided", () => { + const rawBody = { model: "test", messages: [{ role: "user", content: "hello" }] } + ApiLogger.logRequest(baseContext, { ...baseRequest, rawBody }) + + // First call is the request header + expect(consoleLogSpy).toHaveBeenCalledWith("[API Request] test-provider test-model createMessage") + // Second call is the raw body as JSON + expect(consoleLogSpy).toHaveBeenCalledWith("[API Request Body]", JSON.stringify(rawBody, null, 2)) + }) + + it("should track the request timestamp for duration calculation", () => { + expect(ApiLogger.getTrackedRequestCount()).toBe(0) + + ApiLogger.logRequest(baseContext, baseRequest) + + expect(ApiLogger.getTrackedRequestCount()).toBe(1) + }) + + it("should not log when logging is disabled", () => { + ApiLogger.configure({ enabled: false }) + + const requestId = ApiLogger.logRequest(baseContext, baseRequest) + + expect(requestId).toBeDefined() + expect(consoleLogSpy).not.toHaveBeenCalled() + }) + + it("should still track timestamps when logging is disabled", () => { + ApiLogger.configure({ enabled: false }) + + ApiLogger.logRequest(baseContext, baseRequest) + + expect(ApiLogger.getTrackedRequestCount()).toBe(1) + }) + + it("should not log when logRequests is false", () => { + ApiLogger.configure({ logRequests: false }) + + ApiLogger.logRequest(baseContext, baseRequest) + + expect(consoleLogSpy).not.toHaveBeenCalled() + }) + + it("should call onLog callback when configured", () => { + const onLog = vi.fn() + ApiLogger.configure({ onLog }) + + ApiLogger.logRequest(baseContext, baseRequest) + + expect(onLog).toHaveBeenCalledWith( + "request", + expect.objectContaining({ + context: expect.objectContaining({ + provider: "test-provider", + model: "test-model", + }), + request: baseRequest, + }), + ) + }) + }) + + describe("logResponse", () => { + const baseContext: Omit = { + provider: "test-provider", + model: "test-model", + operation: "createMessage", + taskId: "task-123", + } + + const baseResponse = { + textLength: 1000, + reasoningLength: 500, + toolCallCount: 2, + usage: { + inputTokens: 100, + outputTokens: 200, + cacheReadTokens: 50, + cacheWriteTokens: 30, + totalCost: 0.005, + }, + } + + it("should log response details with duration", async () => { + const requestId = ApiLogger.logRequest(baseContext, { messageCount: 1 }) + + // Small delay to ensure duration > 0 + await new Promise((resolve) => setTimeout(resolve, 10)) + + ApiLogger.logResponse(requestId, baseContext, baseResponse) + + // Check console.log was called for the response (second call after request) + expect(consoleLogSpy).toHaveBeenCalledWith( + expect.stringContaining("[API Response] test-provider test-model createMessage"), + expect.objectContaining({ + requestId, + success: true, + textLength: 1000, + reasoningLength: 500, + toolCallCount: 2, + inputTokens: 100, + outputTokens: 200, + totalCost: 0.005, + }), + ) + }) + + it("should clean up tracked timestamps", () => { + const requestId = ApiLogger.logRequest(baseContext, { messageCount: 1 }) + expect(ApiLogger.getTrackedRequestCount()).toBe(1) + + ApiLogger.logResponse(requestId, baseContext, baseResponse) + + expect(ApiLogger.getTrackedRequestCount()).toBe(0) + }) + + it("should handle missing timestamp gracefully", () => { + ApiLogger.logResponse("unknown-request-id", baseContext, baseResponse) + + // The response should still log, but duration calculation handles missing timestamp + expect(consoleLogSpy).toHaveBeenCalledWith( + expect.stringContaining("[API Response]"), + expect.objectContaining({ + success: true, + }), + ) + }) + + it("should not log when logResponses is false", () => { + const requestId = ApiLogger.logRequest(baseContext, { messageCount: 1 }) + vi.clearAllMocks() + + ApiLogger.configure({ logResponses: false }) + ApiLogger.logResponse(requestId, baseContext, baseResponse) + + expect(consoleLogSpy).not.toHaveBeenCalled() + }) + + it("should still clean up timestamps when logging is disabled", () => { + const requestId = ApiLogger.logRequest(baseContext, { messageCount: 1 }) + expect(ApiLogger.getTrackedRequestCount()).toBe(1) + + ApiLogger.configure({ enabled: false }) + ApiLogger.logResponse(requestId, baseContext, baseResponse) + + expect(ApiLogger.getTrackedRequestCount()).toBe(0) + }) + + it("should call onLog callback with response log", () => { + const onLog = vi.fn() + ApiLogger.configure({ onLog }) + + const requestId = ApiLogger.logRequest(baseContext, { messageCount: 1 }) + ApiLogger.logResponse(requestId, baseContext, baseResponse) + + expect(onLog).toHaveBeenCalledWith( + "response", + expect.objectContaining({ + response: expect.objectContaining({ + success: true, + textLength: 1000, + }), + }), + ) + }) + }) + + describe("logError", () => { + const baseContext: Omit = { + provider: "test-provider", + model: "test-model", + operation: "createMessage", + taskId: "task-123", + } + + const baseError = { + message: "Rate limit exceeded", + code: 429, + isRetryable: true, + } + + it("should log error details", () => { + const requestId = ApiLogger.logRequest(baseContext, { messageCount: 1 }) + vi.clearAllMocks() + + ApiLogger.logError(requestId, baseContext, baseError) + + expect(consoleErrorSpy).toHaveBeenCalledWith( + expect.stringContaining("[API Error] test-provider test-model createMessage"), + expect.objectContaining({ + requestId, + errorMessage: "Rate limit exceeded", + errorCode: 429, + isRetryable: true, + }), + ) + }) + + it("should clean up tracked timestamps", () => { + const requestId = ApiLogger.logRequest(baseContext, { messageCount: 1 }) + expect(ApiLogger.getTrackedRequestCount()).toBe(1) + + ApiLogger.logError(requestId, baseContext, baseError) + + expect(ApiLogger.getTrackedRequestCount()).toBe(0) + }) + + it("should not log when logErrors is false", () => { + const requestId = ApiLogger.logRequest(baseContext, { messageCount: 1 }) + vi.clearAllMocks() + + ApiLogger.configure({ logErrors: false }) + ApiLogger.logError(requestId, baseContext, baseError) + + expect(consoleErrorSpy).not.toHaveBeenCalled() + }) + + it("should call onLog callback with error response", () => { + const onLog = vi.fn() + ApiLogger.configure({ onLog }) + + const requestId = ApiLogger.logRequest(baseContext, { messageCount: 1 }) + ApiLogger.logError(requestId, baseContext, baseError) + + expect(onLog).toHaveBeenCalledWith( + "response", + expect.objectContaining({ + response: expect.objectContaining({ + success: false, + error: baseError, + }), + }), + ) + }) + }) + + describe("configure", () => { + it("should merge partial configuration", () => { + ApiLogger.configure({ logRequests: false }) + + const config = ApiLogger.getConfig() + + expect(config.enabled).toBe(true) + expect(config.logRequests).toBe(false) + expect(config.logResponses).toBe(true) + }) + + it("should allow setting all configuration options", () => { + const onLog = vi.fn() + + ApiLogger.configure({ + enabled: false, + logRequests: false, + logResponses: false, + logErrors: false, + onLog, + }) + + const config = ApiLogger.getConfig() + + expect(config.enabled).toBe(false) + expect(config.logRequests).toBe(false) + expect(config.logResponses).toBe(false) + expect(config.logErrors).toBe(false) + expect(config.onLog).toBe(onLog) + }) + }) + + describe("clearTimestamps", () => { + it("should clear all tracked timestamps", () => { + const context = { + provider: "test", + model: "test", + operation: "createMessage" as const, + } + + ApiLogger.logRequest(context, {}) + ApiLogger.logRequest(context, {}) + ApiLogger.logRequest(context, {}) + + expect(ApiLogger.getTrackedRequestCount()).toBe(3) + + ApiLogger.clearTimestamps() + + expect(ApiLogger.getTrackedRequestCount()).toBe(0) + }) + }) + + describe("singleton behavior", () => { + it("should export a singleton instance", () => { + expect(ApiLogger).toBeInstanceOf(ApiLoggerService) + }) + }) +}) diff --git a/src/api/core/logging/__tests__/with-logging.spec.ts b/src/api/core/logging/__tests__/with-logging.spec.ts new file mode 100644 index 0000000000..77a70a6b42 --- /dev/null +++ b/src/api/core/logging/__tests__/with-logging.spec.ts @@ -0,0 +1,407 @@ +/** + * @fileoverview Tests for the withLogging generator wrapper + */ + +import { withLogging } from "../with-logging" +import { ApiLogger } from "../api-logger" +import type { ApiStream, ApiStreamChunk } from "../../../transform/stream" + +// Mock the ApiLogger +vi.mock("../api-logger", () => ({ + ApiLogger: { + logRequest: vi.fn(() => "mock-request-id"), + logResponse: vi.fn(), + logError: vi.fn(), + }, +})) + +describe("withLogging", () => { + beforeEach(() => { + vi.clearAllMocks() + }) + + const baseContext = { + provider: "test-provider", + model: "test-model", + operation: "createMessage" as const, + taskId: "task-123", + } + + const baseRequest = { + messageCount: 5, + hasTools: true, + stream: true, + } + + async function* createMockStream(chunks: ApiStreamChunk[]): ApiStream { + for (const chunk of chunks) { + yield chunk + } + } + + async function collectStream(stream: ApiStream): Promise { + const chunks: ApiStreamChunk[] = [] + for await (const chunk of stream) { + chunks.push(chunk) + } + return chunks + } + + describe("basic functionality", () => { + it("should yield all chunks from the wrapped generator", async () => { + const inputChunks: ApiStreamChunk[] = [ + { type: "text", text: "Hello " }, + { type: "text", text: "World" }, + ] + + const stream = withLogging({ context: baseContext, request: baseRequest }, () => + createMockStream(inputChunks), + ) + + const outputChunks = await collectStream(stream) + + expect(outputChunks).toEqual(inputChunks) + }) + + it("should log request before iterating", async () => { + const stream = withLogging({ context: baseContext, request: baseRequest }, () => + createMockStream([{ type: "text", text: "Test" }]), + ) + + // Request should be logged when generator starts + const iterator = stream[Symbol.asyncIterator]() + await iterator.next() + + expect(ApiLogger.logRequest).toHaveBeenCalledWith(baseContext, baseRequest) + }) + + it("should log response after stream completes", async () => { + const chunks: ApiStreamChunk[] = [ + { type: "text", text: "Hello" }, + { type: "usage", inputTokens: 100, outputTokens: 50 }, + ] + + const stream = withLogging({ context: baseContext, request: baseRequest }, () => createMockStream(chunks)) + + await collectStream(stream) + + expect(ApiLogger.logResponse).toHaveBeenCalledWith("mock-request-id", baseContext, { + textLength: 5, + reasoningLength: undefined, + toolCallCount: undefined, + usage: { + inputTokens: 100, + outputTokens: 50, + cacheReadTokens: undefined, + cacheWriteTokens: undefined, + reasoningTokens: undefined, + totalCost: undefined, + }, + }) + }) + }) + + describe("metrics tracking", () => { + it("should track text length across multiple chunks", async () => { + const chunks: ApiStreamChunk[] = [ + { type: "text", text: "Hello " }, + { type: "text", text: "World" }, + { type: "text", text: "!" }, + ] + + const stream = withLogging({ context: baseContext, request: baseRequest }, () => createMockStream(chunks)) + + await collectStream(stream) + + expect(ApiLogger.logResponse).toHaveBeenCalledWith( + "mock-request-id", + baseContext, + expect.objectContaining({ textLength: 12 }), // "Hello World!" + ) + }) + + it("should track reasoning length from reasoning chunks", async () => { + const chunks: ApiStreamChunk[] = [ + { type: "reasoning", text: "Let me think..." }, + { type: "reasoning", text: " More thinking." }, + { type: "text", text: "Here's my answer" }, + ] + + const stream = withLogging({ context: baseContext, request: baseRequest }, () => createMockStream(chunks)) + + await collectStream(stream) + + expect(ApiLogger.logResponse).toHaveBeenCalledWith( + "mock-request-id", + baseContext, + expect.objectContaining({ + textLength: 16, + reasoningLength: 30, // "Let me think... More thinking." + }), + ) + }) + + it("should count tool_call chunks", async () => { + const chunks: ApiStreamChunk[] = [ + { type: "tool_call", id: "call1", name: "read_file", arguments: "{}" }, + { type: "tool_call", id: "call2", name: "write_file", arguments: "{}" }, + ] + + const stream = withLogging({ context: baseContext, request: baseRequest }, () => createMockStream(chunks)) + + await collectStream(stream) + + expect(ApiLogger.logResponse).toHaveBeenCalledWith( + "mock-request-id", + baseContext, + expect.objectContaining({ toolCallCount: 2 }), + ) + }) + + it("should count tool_call_start chunks", async () => { + const chunks: ApiStreamChunk[] = [ + { type: "tool_call_start", id: "call1", name: "read_file" }, + { type: "tool_call_delta", id: "call1", delta: '{"path":' }, + { type: "tool_call_end", id: "call1" }, + { type: "tool_call_start", id: "call2", name: "write_file" }, + { type: "tool_call_end", id: "call2" }, + ] + + const stream = withLogging({ context: baseContext, request: baseRequest }, () => createMockStream(chunks)) + + await collectStream(stream) + + // Only tool_call_start chunks should be counted + expect(ApiLogger.logResponse).toHaveBeenCalledWith( + "mock-request-id", + baseContext, + expect.objectContaining({ toolCallCount: 2 }), + ) + }) + + it("should capture usage metrics from usage chunk", async () => { + const chunks: ApiStreamChunk[] = [ + { type: "text", text: "Response" }, + { + type: "usage", + inputTokens: 500, + outputTokens: 200, + cacheReadTokens: 100, + cacheWriteTokens: 50, + reasoningTokens: 30, + totalCost: 0.01, + }, + ] + + const stream = withLogging({ context: baseContext, request: baseRequest }, () => createMockStream(chunks)) + + await collectStream(stream) + + expect(ApiLogger.logResponse).toHaveBeenCalledWith( + "mock-request-id", + baseContext, + expect.objectContaining({ + usage: { + inputTokens: 500, + outputTokens: 200, + cacheReadTokens: 100, + cacheWriteTokens: 50, + reasoningTokens: 30, + totalCost: 0.01, + }, + }), + ) + }) + + it("should handle stream with no usage chunk", async () => { + const chunks: ApiStreamChunk[] = [{ type: "text", text: "Response without usage" }] + + const stream = withLogging({ context: baseContext, request: baseRequest }, () => createMockStream(chunks)) + + await collectStream(stream) + + expect(ApiLogger.logResponse).toHaveBeenCalledWith( + "mock-request-id", + baseContext, + expect.objectContaining({ usage: undefined }), + ) + }) + }) + + describe("error handling", () => { + it("should log error when generator throws", async () => { + const testError = new Error("API rate limit exceeded") + ;(testError as Error & { status?: number }).status = 429 + + async function* failingGenerator(): ApiStream { + yield { type: "text", text: "Starting..." } + throw testError + } + + const stream = withLogging({ context: baseContext, request: baseRequest }, failingGenerator) + + await expect(collectStream(stream)).rejects.toThrow("API rate limit exceeded") + + expect(ApiLogger.logError).toHaveBeenCalledWith("mock-request-id", baseContext, { + message: "API rate limit exceeded", + code: 429, + }) + }) + + it("should extract error code from status property", async () => { + const testError = new Error("Server error") + ;(testError as Error & { status?: number }).status = 500 + + // eslint-disable-next-line require-yield + async function* failingGenerator(): ApiStream { + throw testError + } + + const stream = withLogging({ context: baseContext, request: baseRequest }, failingGenerator) + + await expect(collectStream(stream)).rejects.toThrow() + + expect(ApiLogger.logError).toHaveBeenCalledWith( + "mock-request-id", + baseContext, + expect.objectContaining({ code: 500 }), + ) + }) + + it("should extract error code from code property", async () => { + const testError = new Error("Connection error") + ;(testError as Error & { code?: string }).code = "ECONNREFUSED" + + // eslint-disable-next-line require-yield + async function* failingGenerator(): ApiStream { + throw testError + } + + const stream = withLogging({ context: baseContext, request: baseRequest }, failingGenerator) + + await expect(collectStream(stream)).rejects.toThrow() + + expect(ApiLogger.logError).toHaveBeenCalledWith( + "mock-request-id", + baseContext, + expect.objectContaining({ code: "ECONNREFUSED" }), + ) + }) + + it("should handle non-Error throws", async () => { + // eslint-disable-next-line require-yield + async function* failingGenerator(): ApiStream { + throw "string error" + } + + const stream = withLogging({ context: baseContext, request: baseRequest }, failingGenerator) + + await expect(collectStream(stream)).rejects.toBe("string error") + + expect(ApiLogger.logError).toHaveBeenCalledWith( + "mock-request-id", + baseContext, + expect.objectContaining({ message: "string error" }), + ) + }) + + it("should re-throw the original error", async () => { + const originalError = new Error("Original error") + + // eslint-disable-next-line require-yield + async function* failingGenerator(): ApiStream { + throw originalError + } + + const stream = withLogging({ context: baseContext, request: baseRequest }, failingGenerator) + + try { + await collectStream(stream) + expect.fail("Should have thrown") + } catch (error) { + expect(error).toBe(originalError) + } + }) + + it("should not log response when error occurs", async () => { + // eslint-disable-next-line require-yield + async function* failingGenerator(): ApiStream { + throw new Error("Failed") + } + + const stream = withLogging({ context: baseContext, request: baseRequest }, failingGenerator) + + await expect(collectStream(stream)).rejects.toThrow() + + expect(ApiLogger.logResponse).not.toHaveBeenCalled() + }) + }) + + describe("edge cases", () => { + it("should handle empty stream", async () => { + const stream = withLogging({ context: baseContext, request: baseRequest }, () => createMockStream([])) + + const chunks = await collectStream(stream) + + expect(chunks).toEqual([]) + expect(ApiLogger.logResponse).toHaveBeenCalledWith( + "mock-request-id", + baseContext, + expect.objectContaining({ + textLength: 0, + reasoningLength: undefined, + toolCallCount: undefined, + }), + ) + }) + + it("should handle stream with only usage chunk", async () => { + const chunks: ApiStreamChunk[] = [{ type: "usage", inputTokens: 10, outputTokens: 5 }] + + const stream = withLogging({ context: baseContext, request: baseRequest }, () => createMockStream(chunks)) + + await collectStream(stream) + + expect(ApiLogger.logResponse).toHaveBeenCalledWith( + "mock-request-id", + baseContext, + expect.objectContaining({ + usage: expect.objectContaining({ + inputTokens: 10, + outputTokens: 5, + }), + }), + ) + }) + + it("should handle grounding chunks without tracking them", async () => { + const chunks: ApiStreamChunk[] = [ + { type: "text", text: "Answer with source" }, + { type: "grounding", sources: [{ title: "Source", url: "https://example.com" }] }, + ] + + const stream = withLogging({ context: baseContext, request: baseRequest }, () => createMockStream(chunks)) + + const outputChunks = await collectStream(stream) + + expect(outputChunks).toEqual(chunks) + expect(ApiLogger.logResponse).toHaveBeenCalled() + }) + + it("should handle error chunks without stopping the stream", async () => { + const chunks: ApiStreamChunk[] = [ + { type: "text", text: "Partial response" }, + { type: "error", error: "PARTIAL_ERROR", message: "Something went wrong" }, + ] + + const stream = withLogging({ context: baseContext, request: baseRequest }, () => createMockStream(chunks)) + + const outputChunks = await collectStream(stream) + + expect(outputChunks).toEqual(chunks) + // Should still log as response (not as error), since stream completed normally + expect(ApiLogger.logResponse).toHaveBeenCalled() + expect(ApiLogger.logError).not.toHaveBeenCalled() + }) + }) +}) diff --git a/src/api/core/logging/api-logger.ts b/src/api/core/logging/api-logger.ts new file mode 100644 index 0000000000..09adaebe9e --- /dev/null +++ b/src/api/core/logging/api-logger.ts @@ -0,0 +1,237 @@ +/** + * @fileoverview Centralized API logging service + * Provides consistent logging for all API requests and responses across providers + * + * Enable logging by: + * 1. Setting ROO_CODE_LOGGING=true in workspace .env.local file + * 2. Setting ROO_CODE_LOGGING=true in process environment + * 3. Setting VSCODE_DEBUG_MODE=true in process environment + * + * Logs will appear in the Output/Debug console as simple console.log statements. + */ + +import type { + ApiLogContext, + ApiLoggerConfig, + ApiRequestLog, + ApiRequestMetadata, + ApiResponseLog, + ApiResponseMetrics, + ApiErrorDetails, +} from "./types" +import { isLoggingEnabled } from "./env-config" + +/** + * Centralized API logging service + * Singleton instance that all providers route through for consistent logging + * + * When ROO_CODE_LOGGING=true, logs are output via console.log/console.error + * for visibility in VS Code's Output panel and Debug Console. + */ +class ApiLoggerService { + private config: ApiLoggerConfig = { + enabled: true, + logRequests: true, + logResponses: true, + logErrors: true, + } + + /** Maps request IDs to their start timestamps for duration calculation */ + private requestTimestamps = new Map() + + /** + * Configure the logger behavior + * @param config Partial configuration to merge with current settings + */ + configure(config: Partial): void { + this.config = { ...this.config, ...config } + } + + /** + * Get the current configuration + */ + getConfig(): Readonly { + return { ...this.config } + } + + /** + * Check if logging should actually output + * Requires both: config.enabled AND ROO_CODE_LOGGING=true + */ + private shouldLog(): boolean { + return this.config.enabled && isLoggingEnabled() + } + + /** + * Log an outbound API request + * Call this BEFORE making the API call + * + * @param context The API call context (provider, model, operation, etc.) + * @param request Sanitized request metadata (no actual content or keys) + * @returns A unique requestId to correlate with the response + */ + logRequest(context: Omit, request: ApiRequestMetadata): string { + const requestId = this.generateRequestId() + const timestamp = Date.now() + + // Always track timestamp for duration calculation + this.requestTimestamps.set(requestId, timestamp) + + if (!this.shouldLog() || !this.config.logRequests) { + return requestId + } + + const log: ApiRequestLog = { + context: { ...context, requestId }, + timestamp, + request, + } + + // Emit to custom callback if configured + if (this.config.onLog) { + this.config.onLog("request", log) + } + + // Log using console.log for visibility in VS Code Output/Debug + console.log(`[API Request] ${context.provider} ${context.model} ${context.operation}`) + + // If raw body is provided, output it for debugging + if (request.rawBody) { + console.log("[API Request Body]", JSON.stringify(request.rawBody, null, 2)) + } else { + // Fallback to metadata if no raw body + console.log("[API Request Metadata]", { + requestId, + taskId: context.taskId, + messageCount: request.messageCount, + hasTools: request.hasTools, + toolCount: request.toolCount, + stream: request.stream, + }) + } + + return requestId + } + + /** + * Log a successful API response + * Call this AFTER receiving and processing the response + * + * @param requestId The requestId returned from logRequest + * @param context The API call context + * @param response Response metrics (token usage, content length, etc.) + */ + logResponse( + requestId: string, + context: Omit, + response: Omit & { success?: true }, + ): void { + const startTime = this.requestTimestamps.get(requestId) + const timestamp = Date.now() + const durationMs = startTime ? timestamp - startTime : 0 + + // Clean up the timestamp tracking + this.requestTimestamps.delete(requestId) + + if (!this.shouldLog() || !this.config.logResponses) { + return + } + + const log: ApiResponseLog = { + context: { ...context, requestId }, + timestamp, + durationMs, + response: { ...response, success: true }, + } + + // Emit to custom callback if configured + if (this.config.onLog) { + this.config.onLog("response", log) + } + + // Log using console.log for visibility in VS Code Output/Debug + console.log(`[API Response] ${context.provider} ${context.model} ${context.operation} (${durationMs}ms)`, { + requestId, + success: true, + textLength: response.textLength, + reasoningLength: response.reasoningLength, + toolCallCount: response.toolCallCount, + inputTokens: response.usage?.inputTokens, + outputTokens: response.usage?.outputTokens, + totalCost: response.usage?.totalCost, + }) + } + + /** + * Log an API error + * Call this when an error occurs during the API call + * + * @param requestId The requestId returned from logRequest + * @param context The API call context + * @param error Error details + */ + logError(requestId: string, context: Omit, error: ApiErrorDetails): void { + const startTime = this.requestTimestamps.get(requestId) + const timestamp = Date.now() + const durationMs = startTime ? timestamp - startTime : 0 + + // Clean up the timestamp tracking + this.requestTimestamps.delete(requestId) + + if (!this.shouldLog() || !this.config.logErrors) { + return + } + + const log: ApiResponseLog = { + context: { ...context, requestId }, + timestamp, + durationMs, + response: { + success: false, + error, + }, + } + + // Emit to custom callback if configured + if (this.config.onLog) { + this.config.onLog("response", log) + } + + // Log using console.error for visibility in VS Code Output/Debug + console.error(`[API Error] ${context.provider} ${context.model} ${context.operation} (${durationMs}ms)`, { + requestId, + errorMessage: error.message, + errorCode: error.code, + isRetryable: error.isRetryable, + }) + } + + /** + * Generate a unique request ID + */ + private generateRequestId(): string { + return `req_${Date.now()}_${Math.random().toString(36).substring(2, 11)}` + } + + /** + * Clear all tracked request timestamps + * Useful for testing or cleanup + */ + clearTimestamps(): void { + this.requestTimestamps.clear() + } + + /** + * Get the number of currently tracked requests + * Useful for debugging/monitoring + */ + getTrackedRequestCount(): number { + return this.requestTimestamps.size + } +} + +// Singleton instance +export const ApiLogger = new ApiLoggerService() + +// Export the class for testing purposes +export { ApiLoggerService } diff --git a/src/api/core/logging/env-config.ts b/src/api/core/logging/env-config.ts new file mode 100644 index 0000000000..1815cc8b5b --- /dev/null +++ b/src/api/core/logging/env-config.ts @@ -0,0 +1,120 @@ +/** + * @fileoverview Environment configuration reader for API logging + * + * Reads logging settings from workspace .env.local file + */ + +import * as fs from "fs" +import * as path from "path" +import * as vscode from "vscode" + +// Cache for parsed .env.local values +let envCache: Record | null = null +let lastCacheTime = 0 +const CACHE_TTL_MS = 5000 // Re-read file every 5 seconds + +/** + * Parse a .env file content into key-value pairs + */ +function parseEnvFile(content: string): Record { + const result: Record = {} + const lines = content.split("\n") + + for (const line of lines) { + const trimmed = line.trim() + // Skip empty lines and comments + if (!trimmed || trimmed.startsWith("#")) { + continue + } + + const equalsIndex = trimmed.indexOf("=") + if (equalsIndex > 0) { + const key = trimmed.substring(0, equalsIndex).trim() + let value = trimmed.substring(equalsIndex + 1).trim() + + // Remove surrounding quotes if present + if ((value.startsWith('"') && value.endsWith('"')) || (value.startsWith("'") && value.endsWith("'"))) { + value = value.slice(1, -1) + } + + result[key] = value + } + } + + return result +} + +/** + * Get the workspace .env.local file path + */ +function getEnvLocalPath(): string | undefined { + const workspaceFolder = vscode.workspace.workspaceFolders?.[0] + if (!workspaceFolder) { + return undefined + } + return path.join(workspaceFolder.uri.fsPath, ".env.local") +} + +/** + * Read and parse the workspace .env.local file (cached) + */ +function getEnvLocalValues(): Record { + const now = Date.now() + + // Return cached values if still valid + if (envCache && now - lastCacheTime < CACHE_TTL_MS) { + return envCache + } + + const envPath = getEnvLocalPath() + if (!envPath) { + envCache = {} + lastCacheTime = now + return envCache + } + + try { + const content = fs.readFileSync(envPath, "utf-8") + envCache = parseEnvFile(content) + } catch { + // File doesn't exist or can't be read + envCache = {} + } + + lastCacheTime = now + return envCache +} + +/** + * Check if API logging is enabled + * + * Checks in order: + * 1. Workspace .env.local: ROO_CODE_LOGGING=true (for user's workspace) + * 2. Process env (loaded from extension's .env.local via envFile in launch.json) + */ +export function isLoggingEnabled(): boolean { + // Check workspace .env.local first (user's current workspace) + const envLocal = getEnvLocalValues() + if (envLocal["ROO_CODE_LOGGING"] === "true") { + return true + } + + // Fallback to process.env (populated from extension's .env.local via launch.json envFile) + return process.env.ROO_CODE_LOGGING === "true" +} + +/** + * Clear the env cache (useful for testing or when .env.local changes) + */ +export function clearEnvCache(): void { + envCache = null + lastCacheTime = 0 +} + +/** + * Get a specific value from workspace .env.local + */ +export function getEnvLocalValue(key: string): string | undefined { + const values = getEnvLocalValues() + return values[key] +} diff --git a/src/api/core/logging/http-interceptor.ts b/src/api/core/logging/http-interceptor.ts new file mode 100644 index 0000000000..10df9e90af --- /dev/null +++ b/src/api/core/logging/http-interceptor.ts @@ -0,0 +1,137 @@ +/** + * @fileoverview HTTP request interceptor for logging raw API requests + * + * This module provides a custom fetch function that logs the full raw request + * including URL, headers, and body before sending it to the API. + */ + +import { isLoggingEnabled } from "./env-config" + +/** + * Sanitize headers by removing sensitive data like API keys + */ +function sanitizeHeaders(headers: Record): Record { + const sensitiveKeys = ["authorization", "x-api-key", "api-key", "openai-api-key", "anthropic-api-key"] + + const sanitized: Record = {} + for (const [key, value] of Object.entries(headers)) { + const lowerKey = key.toLowerCase() + if (sensitiveKeys.some((sk) => lowerKey.includes(sk))) { + // Mask the value, showing only first/last few chars + if (value.length > 8) { + sanitized[key] = `${value.substring(0, 4)}...${value.substring(value.length - 4)}` + } else { + sanitized[key] = "****" + } + } else { + sanitized[key] = value + } + } + return sanitized +} + +/** + * Parse body as JSON if possible, otherwise return as-is + */ +function parseBodyIfJson(body: BodyInit | string): unknown { + try { + const bodyStr = typeof body === "string" ? body : body.toString() + return JSON.parse(bodyStr) + } catch { + return body + } +} + +/** + * Extract headers from a Headers object to a plain object + */ +function headersToObject(headers: Headers): Record { + const result: Record = {} + headers.forEach((value, key) => { + result[key] = value + }) + return result +} + +/** + * Creates a fetch wrapper that logs raw HTTP requests and responses + * + * @param providerName - Name of the provider for logging context + * @returns A fetch function that logs requests and responses + */ +export function createLoggingFetch(providerName: string): typeof fetch { + return async (input: RequestInfo | URL, init?: RequestInit): Promise => { + const loggingEnabled = isLoggingEnabled() + const url = typeof input === "string" ? input : input instanceof URL ? input.toString() : input.url + const method = init?.method || "GET" + + if (loggingEnabled) { + // Extract request headers + let headers: Record = {} + if (init?.headers) { + if (init.headers instanceof Headers) { + init.headers.forEach((value, key) => { + headers[key] = value + }) + } else if (Array.isArray(init.headers)) { + for (const [key, value] of init.headers) { + headers[key] = value + } + } else { + headers = init.headers as Record + } + } + + // Log the raw request as objects for native expandability in dev tools + console.log(`[${providerName}] RAW HTTP REQUEST`, { + method, + url, + headers: sanitizeHeaders(headers), + body: init?.body ? parseBodyIfJson(init.body) : undefined, + }) + } + + // Execute the actual fetch + const response = await fetch(input, init) + + if (loggingEnabled) { + const contentType = response.headers.get("content-type") || "" + const isStreaming = contentType.includes("text/event-stream") || contentType.includes("stream") + + // Log response info + const responseLog: { + status: number + statusText: string + headers: Record + body?: unknown + streaming?: boolean + } = { + status: response.status, + statusText: response.statusText, + headers: sanitizeHeaders(headersToObject(response.headers)), + } + + if (isStreaming) { + responseLog.streaming = true + console.log(`[${providerName}] RAW HTTP RESPONSE`, responseLog) + } else { + // For non-streaming responses, clone and read the body + try { + const cloned = response.clone() + const bodyText = await cloned.text() + responseLog.body = parseBodyIfJson(bodyText) + } catch { + responseLog.body = "[unable to read body]" + } + console.log(`[${providerName}] RAW HTTP RESPONSE`, responseLog) + } + } + + return response + } +} + +/** + * Export a default logging fetch for convenience + */ +export const loggingFetch = createLoggingFetch("API") diff --git a/src/api/core/logging/index.ts b/src/api/core/logging/index.ts new file mode 100644 index 0000000000..906f41b055 --- /dev/null +++ b/src/api/core/logging/index.ts @@ -0,0 +1,35 @@ +/** + * @fileoverview Centralized API logging component exports + * + * This module provides: + * - ApiLogger: Singleton service for logging API requests/responses + * - withLogging: Generator wrapper for automatic request logging + * - createLoggingFetch: HTTP fetch wrapper for raw request logging + * - isLoggingEnabled: Check if logging is enabled (via .env.local or process.env) + */ + +// Main logger service +export { ApiLogger, ApiLoggerService } from "./api-logger" + +// Generator wrapper helper +export { withLogging } from "./with-logging" +export type { WithLoggingOptions } from "./with-logging" + +// HTTP interceptor for raw request logging +export { createLoggingFetch, loggingFetch } from "./http-interceptor" + +// Environment configuration +export { isLoggingEnabled, clearEnvCache, getEnvLocalValue } from "./env-config" + +// Type definitions +export type { + ApiLogContext, + ApiRequestMetadata, + ApiRequestLog, + ApiUsageMetrics, + ApiErrorDetails, + ApiResponseMetrics, + ApiResponseLog, + ApiLogCallback, + ApiLoggerConfig, +} from "./types" diff --git a/src/api/core/logging/types.ts b/src/api/core/logging/types.ts new file mode 100644 index 0000000000..b8000fa21e --- /dev/null +++ b/src/api/core/logging/types.ts @@ -0,0 +1,139 @@ +/** + * @fileoverview Type definitions for the centralized API logging component + */ + +/** + * Context information for an API call + */ +export interface ApiLogContext { + /** The provider name (e.g., "anthropic", "openai", "gemini") */ + provider: string + /** The model identifier being used */ + model: string + /** The type of API operation */ + operation: "createMessage" | "completePrompt" | "countTokens" | "fetchModels" + /** Optional task ID for correlation */ + taskId?: string + /** Unique request ID for correlating request/response logs */ + requestId?: string +} + +/** + * Sanitized request metadata for logging + * Does NOT include actual message content or API keys + */ +export interface ApiRequestMetadata { + /** Length of the system prompt in characters */ + systemPromptLength?: number + /** Number of messages in the conversation */ + messageCount?: number + /** Whether tools are being used */ + hasTools?: boolean + /** Number of tools available */ + toolCount?: number + /** Whether this is a streaming request */ + stream?: boolean + /** Additional sanitized parameters */ + params?: Record + /** + * Raw API request body for debugging + * Contains the full request object sent to the provider API + * WARNING: May contain sensitive data - only use in development/debug mode + */ + rawBody?: unknown +} + +/** + * Log entry for an outbound API request + */ +export interface ApiRequestLog { + /** Context information */ + context: ApiLogContext + /** Timestamp when request was made */ + timestamp: number + /** Sanitized request metadata */ + request: ApiRequestMetadata +} + +/** + * Usage metrics from an API response + */ +export interface ApiUsageMetrics { + /** Number of input tokens */ + inputTokens: number + /** Number of output tokens */ + outputTokens: number + /** Tokens read from cache */ + cacheReadTokens?: number + /** Tokens written to cache */ + cacheWriteTokens?: number + /** Reasoning/thinking tokens */ + reasoningTokens?: number + /** Total cost in dollars */ + totalCost?: number +} + +/** + * Error details for logging + */ +export interface ApiErrorDetails { + /** Error message */ + message: string + /** Error code (HTTP status or provider-specific) */ + code?: string | number + /** Whether this error can be retried */ + isRetryable?: boolean +} + +/** + * Response metrics for logging + */ +export interface ApiResponseMetrics { + /** Whether the request was successful */ + success: boolean + /** Length of text content in characters */ + textLength?: number + /** Length of reasoning content in characters */ + reasoningLength?: number + /** Number of tool calls made */ + toolCallCount?: number + /** Token usage metrics */ + usage?: ApiUsageMetrics + /** Error details if request failed */ + error?: ApiErrorDetails +} + +/** + * Log entry for an inbound API response + */ +export interface ApiResponseLog { + /** Context information */ + context: ApiLogContext + /** Timestamp when response was received */ + timestamp: number + /** Duration of the request in milliseconds */ + durationMs: number + /** Response metrics */ + response: ApiResponseMetrics +} + +/** + * Callback type for custom log handling + */ +export type ApiLogCallback = (type: "request" | "response", log: ApiRequestLog | ApiResponseLog) => void + +/** + * Configuration options for the API logger + */ +export interface ApiLoggerConfig { + /** Whether logging is enabled */ + enabled: boolean + /** Whether to log outbound requests */ + logRequests: boolean + /** Whether to log successful responses */ + logResponses: boolean + /** Whether to log errors */ + logErrors: boolean + /** Optional callback for custom log destinations */ + onLog?: ApiLogCallback +} diff --git a/src/api/core/logging/with-logging.ts b/src/api/core/logging/with-logging.ts new file mode 100644 index 0000000000..408cd344b8 --- /dev/null +++ b/src/api/core/logging/with-logging.ts @@ -0,0 +1,104 @@ +/** + * @fileoverview Generator wrapper that automatically logs API requests and responses + */ + +import { ApiLogger } from "./api-logger" +import type { ApiLogContext, ApiRequestMetadata, ApiUsageMetrics } from "./types" +import type { ApiStream, ApiStreamUsageChunk } from "../../transform/stream" + +/** + * Options for the withLogging wrapper + */ +export interface WithLoggingOptions { + /** API call context (provider, model, operation) */ + context: Omit + /** Sanitized request metadata */ + request: ApiRequestMetadata +} + +/** + * Wraps an ApiStream generator with automatic logging + * + * This function: + * 1. Logs the request before iteration starts + * 2. Tracks metrics during streaming (text length, tool calls, usage) + * 3. Logs the response after streaming completes (or error if thrown) + * + * @param options Logging options including context and request metadata + * @param generator Factory function that creates the ApiStream to wrap + * @returns A new ApiStream that yields the same chunks with logging + * + * @example + * ```typescript + * yield* withLogging( + * { + * context: { provider: "openai", model: "gpt-4", operation: "createMessage" }, + * request: { messageCount: 3, hasTools: true, stream: true }, + * }, + * () => this.createStreamInternal(systemPrompt, messages, metadata) + * ) + * ``` + */ +export async function* withLogging(options: WithLoggingOptions, generator: () => ApiStream): ApiStream { + const requestId = ApiLogger.logRequest(options.context, options.request) + + // Track metrics during streaming + let textLength = 0 + let reasoningLength = 0 + let toolCallCount = 0 + let usage: ApiStreamUsageChunk | undefined + + try { + for await (const chunk of generator()) { + // Track metrics based on chunk type + switch (chunk.type) { + case "text": + textLength += chunk.text.length + break + case "reasoning": + reasoningLength += chunk.text.length + break + case "tool_call": + case "tool_call_start": + toolCallCount++ + break + case "usage": + usage = chunk + break + } + + yield chunk + } + + // Build usage metrics if we have them + const usageMetrics: ApiUsageMetrics | undefined = usage + ? { + inputTokens: usage.inputTokens, + outputTokens: usage.outputTokens, + cacheReadTokens: usage.cacheReadTokens, + cacheWriteTokens: usage.cacheWriteTokens, + reasoningTokens: usage.reasoningTokens, + totalCost: usage.totalCost, + } + : undefined + + // Log successful completion + ApiLogger.logResponse(requestId, options.context, { + textLength, + reasoningLength: reasoningLength || undefined, + toolCallCount: toolCallCount || undefined, + usage: usageMetrics, + }) + } catch (error) { + // Log the error + ApiLogger.logError(requestId, options.context, { + message: error instanceof Error ? error.message : String(error), + code: + (error as { status?: string | number; code?: string | number })?.status || + (error as { status?: string | number; code?: string | number })?.code, + }) + + // Re-throw to preserve error handling behavior + throw error + } +} diff --git a/src/api/providers/__tests__/openrouter.spec.ts b/src/api/providers/__tests__/openrouter.spec.ts index 1ebdd68494..c3f48dfa61 100644 --- a/src/api/providers/__tests__/openrouter.spec.ts +++ b/src/api/providers/__tests__/openrouter.spec.ts @@ -1,6 +1,10 @@ // pnpm --filter roo-cline test api/providers/__tests__/openrouter.spec.ts -vitest.mock("vscode", () => ({})) +vitest.mock("vscode", () => ({ + workspace: { + workspaceFolders: undefined, + }, +})) import { Anthropic } from "@anthropic-ai/sdk" import OpenAI from "openai" @@ -99,15 +103,19 @@ describe("OpenRouterHandler", () => { const handler = new OpenRouterHandler(mockOptions) expect(handler).toBeInstanceOf(OpenRouterHandler) - expect(OpenAI).toHaveBeenCalledWith({ - baseURL: "https://openrouter.ai/api/v1", - apiKey: mockOptions.openRouterApiKey, - defaultHeaders: { - "HTTP-Referer": "https://github.com/RooVetGit/Roo-Cline", - "X-Title": "Roo Code", - "User-Agent": `RooCode/${Package.version}`, - }, - }) + expect(OpenAI).toHaveBeenCalledWith( + expect.objectContaining({ + baseURL: "https://openrouter.ai/api/v1", + apiKey: mockOptions.openRouterApiKey, + defaultHeaders: { + "HTTP-Referer": "https://github.com/RooVetGit/Roo-Cline", + "X-Title": "Roo Code", + "User-Agent": `RooCode/${Package.version}`, + }, + // Also includes fetch function for logging + fetch: expect.any(Function), + }), + ) }) describe("fetchModel", () => { diff --git a/src/api/providers/anthropic-vertex.ts b/src/api/providers/anthropic-vertex.ts index cbfae08f41..df54ce8c4c 100644 --- a/src/api/providers/anthropic-vertex.ts +++ b/src/api/providers/anthropic-vertex.ts @@ -24,6 +24,7 @@ import { convertOpenAIToolsToAnthropic, convertOpenAIToolChoiceToAnthropic, } from "../../core/prompts/tools/native-tools/converters" +import { withLogging, ApiLogger } from "../core/logging" import { BaseProvider } from "./base-provider" import type { SingleCompletionHandler, ApiHandlerCreateMessageMetadata } from "../index" @@ -33,6 +34,10 @@ export class AnthropicVertexHandler extends BaseProvider implements SingleComple protected options: ApiHandlerOptions private client: AnthropicVertex + protected override get providerName(): string { + return "Anthropic Vertex" + } + constructor(options: ApiHandlerOptions) { super() @@ -69,6 +74,26 @@ export class AnthropicVertexHandler extends BaseProvider implements SingleComple systemPrompt: string, messages: Anthropic.Messages.MessageParam[], metadata?: ApiHandlerCreateMessageMetadata, + ): ApiStream { + yield* withLogging( + { + context: this.getLogContext("createMessage", metadata), + request: { + systemPromptLength: systemPrompt.length, + messageCount: messages.length, + hasTools: Boolean(metadata?.tools?.length), + toolCount: metadata?.tools?.length, + stream: true, + }, + }, + () => this.createMessageInternal(systemPrompt, messages, metadata), + ) + } + + private async *createMessageInternal( + systemPrompt: string, + messages: Anthropic.Messages.MessageParam[], + metadata?: ApiHandlerCreateMessageMetadata, ): ApiStream { let { id, info, temperature, maxTokens, reasoning: thinking, betas } = this.getModel() @@ -268,6 +293,12 @@ export class AnthropicVertexHandler extends BaseProvider implements SingleComple } async completePrompt(prompt: string) { + const context = this.getLogContext("completePrompt") + const requestId = ApiLogger.logRequest(context, { + messageCount: 1, + stream: false, + }) + try { let { id, @@ -296,12 +327,24 @@ export class AnthropicVertexHandler extends BaseProvider implements SingleComple const response = await this.client.messages.create(params) const content = response.content[0] - if (content.type === "text") { - return content.text - } + const result = content.type === "text" ? content.text : "" - return "" + ApiLogger.logResponse(requestId, context, { + textLength: result.length, + usage: response.usage + ? { + inputTokens: response.usage.input_tokens, + outputTokens: response.usage.output_tokens, + } + : undefined, + }) + + return result } catch (error) { + ApiLogger.logError(requestId, context, { + message: error instanceof Error ? error.message : String(error), + }) + if (error instanceof Error) { throw new Error(`Vertex completion error: ${error.message}`) } diff --git a/src/api/providers/anthropic.ts b/src/api/providers/anthropic.ts index 4faf341d28..4c39fed883 100644 --- a/src/api/providers/anthropic.ts +++ b/src/api/providers/anthropic.ts @@ -23,6 +23,7 @@ import { resolveToolProtocol } from "../../utils/resolveToolProtocol" import { handleProviderError } from "./utils/error-handler" import { BaseProvider } from "./base-provider" +import { withLogging, ApiLogger } from "../core/logging" import type { SingleCompletionHandler, ApiHandlerCreateMessageMetadata } from "../index" import { calculateApiCostAnthropic } from "../../shared/cost" import { @@ -33,7 +34,10 @@ import { export class AnthropicHandler extends BaseProvider implements SingleCompletionHandler { private options: ApiHandlerOptions private client: Anthropic - private readonly providerName = "Anthropic" + + protected override get providerName(): string { + return "Anthropic" + } constructor(options: ApiHandlerOptions) { super() @@ -52,6 +56,76 @@ export class AnthropicHandler extends BaseProvider implements SingleCompletionHa systemPrompt: string, messages: Anthropic.Messages.MessageParam[], metadata?: ApiHandlerCreateMessageMetadata, + ): ApiStream { + // Build the request body first so we can log it + const requestBody = this.buildRequestBody(systemPrompt, messages, metadata) + + yield* withLogging( + { + context: this.getLogContext("createMessage", metadata), + request: { + systemPromptLength: systemPrompt.length, + messageCount: messages.length, + hasTools: Boolean(metadata?.tools?.length), + toolCount: metadata?.tools?.length, + stream: true, + rawBody: requestBody, + }, + }, + () => this.createMessageInternal(systemPrompt, messages, metadata), + ) + } + + /** + * Build the request body for logging purposes. + * This creates the request object that will be sent to the API. + */ + private buildRequestBody( + systemPrompt: string, + messages: Anthropic.Messages.MessageParam[], + metadata?: ApiHandlerCreateMessageMetadata, + ): Record { + const { id: modelId, maxTokens, temperature, reasoning: thinking } = this.getModel() + + // Filter out non-Anthropic blocks + const sanitizedMessages = filterNonAnthropicBlocks(messages) + + // Check for native tools + const model = this.getModel() + const toolProtocol = resolveToolProtocol(this.options, model.info) + const shouldIncludeNativeTools = + metadata?.tools && + metadata.tools.length > 0 && + toolProtocol === TOOL_PROTOCOL.NATIVE && + metadata?.tool_choice !== "none" + + const nativeToolParams = shouldIncludeNativeTools + ? { + tools: convertOpenAIToolsToAnthropic(metadata.tools!), + tool_choice: this.convertOpenAIToolChoice(metadata.tool_choice, metadata.parallelToolCalls), + } + : {} + + return { + model: modelId, + max_tokens: maxTokens ?? ANTHROPIC_DEFAULT_MAX_TOKENS, + temperature, + thinking, + system: [{ text: systemPrompt, type: "text" }], + messages: sanitizedMessages, + stream: true, + ...nativeToolParams, + } + } + + /** + * Internal implementation of createMessage without logging wrapper. + * This is wrapped by createMessage with logging. + */ + private async *createMessageInternal( + systemPrompt: string, + messages: Anthropic.Messages.MessageParam[], + metadata?: ApiHandlerCreateMessageMetadata, ): ApiStream { let stream: AnthropicStream const cacheControl: CacheControlEphemeral = { type: "ephemeral" } @@ -382,7 +456,9 @@ export class AnthropicHandler extends BaseProvider implements SingleCompletionHa } async completePrompt(prompt: string) { - let { id: model, temperature } = this.getModel() + const { id: model, temperature } = this.getModel() + const context = this.getLogContext("completePrompt") + const requestId = ApiLogger.logRequest(context, { messageCount: 1, stream: false }) let message try { @@ -395,6 +471,12 @@ export class AnthropicHandler extends BaseProvider implements SingleCompletionHa stream: false, }) } catch (error) { + // Check if Anthropic.APIError exists before using instanceof (may not exist in test mocks) + const isAnthropicAPIError = typeof Anthropic.APIError === "function" && error instanceof Anthropic.APIError + ApiLogger.logError(requestId, context, { + message: error instanceof Error ? error.message : String(error), + code: isAnthropicAPIError ? (error as { status?: number }).status : undefined, + }) TelemetryService.instance.captureException( new ApiProviderError( error instanceof Error ? error.message : String(error), @@ -407,6 +489,16 @@ export class AnthropicHandler extends BaseProvider implements SingleCompletionHa } const content = message.content.find(({ type }) => type === "text") - return content?.type === "text" ? content.text : "" + const result = content?.type === "text" ? content.text : "" + + ApiLogger.logResponse(requestId, context, { + textLength: result.length, + usage: { + inputTokens: message.usage?.input_tokens, + outputTokens: message.usage?.output_tokens, + }, + }) + + return result } } diff --git a/src/api/providers/base-openai-compatible-provider.ts b/src/api/providers/base-openai-compatible-provider.ts index 92b9558c45..ee5dbfd004 100644 --- a/src/api/providers/base-openai-compatible-provider.ts +++ b/src/api/providers/base-openai-compatible-provider.ts @@ -14,6 +14,7 @@ import { BaseProvider } from "./base-provider" import { handleOpenAIError } from "./utils/openai-error-handler" import { calculateApiCostOpenAI } from "../../shared/cost" import { getApiRequestTimeout } from "./utils/timeout-config" +import { withLogging, ApiLogger } from "../core/logging" type BaseOpenAiCompatibleProviderOptions = ApiHandlerOptions & { providerName: string @@ -27,7 +28,7 @@ export abstract class BaseOpenAiCompatibleProvider extends BaseProvider implements SingleCompletionHandler { - protected readonly providerName: string + protected readonly _providerName: string protected readonly baseURL: string protected readonly defaultTemperature: number protected readonly defaultProviderModelId: ModelName @@ -47,7 +48,7 @@ export abstract class BaseOpenAiCompatibleProvider }: BaseOpenAiCompatibleProviderOptions) { super() - this.providerName = providerName + this._providerName = providerName this.baseURL = baseURL this.defaultProviderModelId = defaultProviderModelId this.providerModels = providerModels @@ -67,6 +68,13 @@ export abstract class BaseOpenAiCompatibleProvider }) } + /** + * Get the provider name for logging + */ + protected override get providerName(): string { + return this._providerName + } + protected createStream( systemPrompt: string, messages: Anthropic.Messages.MessageParam[], @@ -116,6 +124,30 @@ export abstract class BaseOpenAiCompatibleProvider systemPrompt: string, messages: Anthropic.Messages.MessageParam[], metadata?: ApiHandlerCreateMessageMetadata, + ): ApiStream { + yield* withLogging( + { + context: this.getLogContext("createMessage", metadata), + request: { + systemPromptLength: systemPrompt.length, + messageCount: messages.length, + hasTools: Boolean(metadata?.tools?.length), + toolCount: metadata?.tools?.length, + stream: true, + }, + }, + () => this.createMessageInternal(systemPrompt, messages, metadata), + ) + } + + /** + * Internal implementation of createMessage without logging wrapper. + * This is wrapped by createMessage with logging. + */ + private async *createMessageInternal( + systemPrompt: string, + messages: Anthropic.Messages.MessageParam[], + metadata?: ApiHandlerCreateMessageMetadata, ): ApiStream { const stream = await this.createStream(systemPrompt, messages, metadata) @@ -209,6 +241,12 @@ export abstract class BaseOpenAiCompatibleProvider async completePrompt(prompt: string): Promise { const { id: modelId, info: modelInfo } = this.getModel() + const context = this.getLogContext("completePrompt") + + const requestId = ApiLogger.logRequest(context, { + messageCount: 1, + stream: false, + }) const params: OpenAI.Chat.Completions.ChatCompletionCreateParams = { model: modelId, @@ -231,8 +269,28 @@ export abstract class BaseOpenAiCompatibleProvider ) } - return response.choices?.[0]?.message.content || "" + const content = response.choices?.[0]?.message.content || "" + + // Log successful response + ApiLogger.logResponse(requestId, context, { + textLength: content.length, + usage: response.usage + ? { + inputTokens: response.usage.prompt_tokens, + outputTokens: response.usage.completion_tokens, + } + : undefined, + }) + + return content } catch (error) { + // Log error + ApiLogger.logError(requestId, context, { + message: error instanceof Error ? error.message : String(error), + code: + (error as { status?: string | number; code?: string | number })?.status || + (error as { status?: string | number; code?: string | number })?.code, + }) throw handleOpenAIError(error, this.providerName) } } diff --git a/src/api/providers/base-provider.ts b/src/api/providers/base-provider.ts index 84c8cf6fe9..7e60341226 100644 --- a/src/api/providers/base-provider.ts +++ b/src/api/providers/base-provider.ts @@ -5,11 +5,21 @@ import type { ModelInfo } from "@roo-code/types" import type { ApiHandler, ApiHandlerCreateMessageMetadata } from "../index" import { ApiStream } from "../transform/stream" import { countTokens } from "../../utils/countTokens" +import type { ApiLogContext } from "../core/logging" /** * Base class for API providers that implements common functionality. */ export abstract class BaseProvider implements ApiHandler { + /** + * The name of the provider for logging purposes. + * Override this in subclasses to provide a meaningful name. + * Defaults to class name. + */ + protected get providerName(): string { + return this.constructor.name + } + abstract createMessage( systemPrompt: string, messages: Anthropic.Messages.MessageParam[], @@ -18,6 +28,24 @@ export abstract class BaseProvider implements ApiHandler { abstract getModel(): { id: string; info: ModelInfo } + /** + * Helper to build log context for API calls + * @param operation The operation type + * @param metadata Optional metadata containing taskId + */ + protected getLogContext( + operation: ApiLogContext["operation"], + metadata?: { taskId?: string }, + ): Omit { + const { id: model } = this.getModel() + return { + provider: this.providerName, + model, + operation, + taskId: metadata?.taskId, + } + } + /** * Converts an array of tools to be compatible with OpenAI's strict mode. * Filters for function tools, applies schema conversion to their parameters, diff --git a/src/api/providers/bedrock.ts b/src/api/providers/bedrock.ts index 761500750d..e091263cfa 100644 --- a/src/api/providers/bedrock.ts +++ b/src/api/providers/bedrock.ts @@ -45,6 +45,7 @@ import { getModelParams } from "../transform/model-params" import { shouldUseReasoningBudget } from "../../shared/api" import { normalizeToolSchema } from "../../utils/json-schema" import type { SingleCompletionHandler, ApiHandlerCreateMessageMetadata } from "../index" +import { withLogging, ApiLogger } from "../core/logging" /************************************************************************************ * @@ -200,7 +201,10 @@ export class AwsBedrockHandler extends BaseProvider implements SingleCompletionH protected options: ProviderSettings private client: BedrockRuntimeClient private arnInfo: any - private readonly providerName = "Bedrock" + + protected override get providerName(): string { + return "Bedrock" + } constructor(options: ProviderSettings) { super() @@ -355,6 +359,36 @@ export class AwsBedrockHandler extends BaseProvider implements SingleCompletionH maxThinkingTokens?: number } }, + ): ApiStream { + yield* withLogging( + { + context: this.getLogContext("createMessage", metadata), + request: { + systemPromptLength: systemPrompt.length, + messageCount: messages.length, + hasTools: Boolean(metadata?.tools?.length), + toolCount: metadata?.tools?.length, + stream: true, + }, + }, + () => this.createMessageInternal(systemPrompt, messages, metadata), + ) + } + + /** + * Internal implementation of createMessage without logging wrapper. + * This is wrapped by createMessage with logging. + */ + private async *createMessageInternal( + systemPrompt: string, + messages: Anthropic.Messages.MessageParam[], + metadata?: ApiHandlerCreateMessageMetadata & { + thinking?: { + enabled: boolean + maxTokens?: number + maxThinkingTokens?: number + } + }, ): ApiStream { const modelConfig = this.getModel() const usePromptCache = Boolean(this.options.awsUsePromptCache && this.supportsAwsPromptCache(modelConfig)) @@ -747,6 +781,9 @@ export class AwsBedrockHandler extends BaseProvider implements SingleCompletionH } async completePrompt(prompt: string): Promise { + const context = this.getLogContext("completePrompt") + const requestId = ApiLogger.logRequest(context, { messageCount: 1, stream: false }) + try { const modelConfig = this.getModel() @@ -792,7 +829,11 @@ export class AwsBedrockHandler extends BaseProvider implements SingleCompletionH response.output.message.content[0].text.trim().length > 0 ) { try { - return response.output.message.content[0].text + const result = response.output.message.content[0].text + ApiLogger.logResponse(requestId, context, { + textLength: result.length, + }) + return result } catch (parseError) { logger.error("Failed to parse Bedrock response", { ctx: "bedrock", @@ -800,8 +841,17 @@ export class AwsBedrockHandler extends BaseProvider implements SingleCompletionH }) } } + + ApiLogger.logResponse(requestId, context, { textLength: 0 }) return "" } catch (error) { + // Log error + const errorMessage = error instanceof Error ? error.message : String(error) + ApiLogger.logError(requestId, context, { + message: errorMessage, + code: (error as any)?.$metadata?.httpStatusCode, + }) + // Capture error in telemetry const model = this.getModel() const telemetryErrorMessage = error instanceof Error ? error.message : String(error) @@ -811,10 +861,10 @@ export class AwsBedrockHandler extends BaseProvider implements SingleCompletionH // Use the extracted error handling method for all errors const errorResult = this.handleBedrockError(error, false) // false for non-streaming context // Since we're in a non-streaming context, we know the result is a string - const errorMessage = errorResult as string + const bedrockErrorMessage = errorResult as string // Create enhanced error for retry system - const enhancedError = new Error(errorMessage) + const enhancedError = new Error(bedrockErrorMessage) if (error instanceof Error) { // Preserve important properties from the original error enhancedError.name = error.name diff --git a/src/api/providers/claude-code.ts b/src/api/providers/claude-code.ts index cdd1cb3beb..293bcf2bee 100644 --- a/src/api/providers/claude-code.ts +++ b/src/api/providers/claude-code.ts @@ -10,6 +10,7 @@ import { } from "@roo-code/types" import { type ApiHandler, ApiHandlerCreateMessageMetadata, type SingleCompletionHandler } from ".." import { ApiStreamUsageChunk, type ApiStream } from "../transform/stream" +import { withLogging, ApiLogger, type ApiLogContext } from "../core/logging" import { claudeCodeOAuthManager, generateUserId } from "../../integrations/claude-code/oauth" import { createStreamingMessage, @@ -73,11 +74,28 @@ export class ClaudeCodeHandler implements ApiHandler, SingleCompletionHandler { * Similar to Gemini's thoughtSignature pattern. */ private lastThinkingSignature?: string + private readonly providerName = "Claude Code" constructor(options: ApiHandlerOptions) { this.options = options } + /** + * Helper to build log context for API calls + */ + private getLogContext( + operation: ApiLogContext["operation"], + metadata?: { taskId?: string }, + ): Omit { + const { id: model } = this.getModel() + return { + provider: this.providerName, + model, + operation, + taskId: metadata?.taskId, + } + } + /** * Get the thinking signature from the last response. * Used by Task.addToApiConversationHistory to persist the signature @@ -118,6 +136,26 @@ export class ClaudeCodeHandler implements ApiHandler, SingleCompletionHandler { systemPrompt: string, messages: Anthropic.Messages.MessageParam[], metadata?: ApiHandlerCreateMessageMetadata, + ): ApiStream { + yield* withLogging( + { + context: this.getLogContext("createMessage", metadata), + request: { + systemPromptLength: systemPrompt.length, + messageCount: messages.length, + hasTools: Boolean(metadata?.tools?.length), + toolCount: metadata?.tools?.length, + stream: true, + }, + }, + () => this.createMessageInternal(systemPrompt, messages, metadata), + ) + } + + private async *createMessageInternal( + systemPrompt: string, + messages: Anthropic.Messages.MessageParam[], + metadata?: ApiHandlerCreateMessageMetadata, ): ApiStream { // Reset per-request state that we persist into apiConversationHistory this.lastThinkingSignature = undefined @@ -297,6 +335,12 @@ export class ClaudeCodeHandler implements ApiHandler, SingleCompletionHandler { * The Claude Code branding is automatically prepended by createStreamingMessage. */ async completePrompt(prompt: string): Promise { + const context = this.getLogContext("completePrompt") + const requestId = ApiLogger.logRequest(context, { + messageCount: 1, + stream: false, + }) + // Get access token from OAuth manager const accessToken = await claudeCodeOAuthManager.getAccessToken() @@ -343,16 +387,32 @@ export class ClaudeCodeHandler implements ApiHandler, SingleCompletionHandler { // Collect all text chunks into a single response let result = "" - for await (const chunk of stream) { - switch (chunk.type) { - case "text": - result += chunk.text - break - case "error": - throw new Error(chunk.error) + try { + for await (const chunk of stream) { + switch (chunk.type) { + case "text": + result += chunk.text + break + case "error": + ApiLogger.logError(requestId, context, { + message: chunk.error, + }) + throw new Error(chunk.error) + } } - } - return result + ApiLogger.logResponse(requestId, context, { + textLength: result.length, + }) + + return result + } catch (error) { + if (!(error instanceof Error && error.message)) { + ApiLogger.logError(requestId, context, { + message: error instanceof Error ? error.message : String(error), + }) + } + throw error + } } } diff --git a/src/api/providers/deepseek.ts b/src/api/providers/deepseek.ts index 4e5aef23a5..19f86ae018 100644 --- a/src/api/providers/deepseek.ts +++ b/src/api/providers/deepseek.ts @@ -13,6 +13,7 @@ import type { ApiHandlerOptions } from "../../shared/api" import { ApiStream, ApiStreamUsageChunk } from "../transform/stream" import { getModelParams } from "../transform/model-params" import { convertToR1Format } from "../transform/r1-format" +import { withLogging } from "../core/logging" import { OpenAiHandler } from "./openai" import type { ApiHandlerCreateMessageMetadata } from "../index" @@ -23,6 +24,10 @@ type DeepSeekChatCompletionParams = OpenAI.Chat.ChatCompletionCreateParamsStream } export class DeepSeekHandler extends OpenAiHandler { + protected override get providerName(): string { + return "DeepSeek" + } + constructor(options: ApiHandlerOptions) { super({ ...options, @@ -45,6 +50,26 @@ export class DeepSeekHandler extends OpenAiHandler { systemPrompt: string, messages: Anthropic.Messages.MessageParam[], metadata?: ApiHandlerCreateMessageMetadata, + ): ApiStream { + yield* withLogging( + { + context: this.getLogContext("createMessage", metadata), + request: { + systemPromptLength: systemPrompt.length, + messageCount: messages.length, + hasTools: Boolean(metadata?.tools?.length), + toolCount: metadata?.tools?.length, + stream: true, + }, + }, + () => this.createMessageDeepSeek(systemPrompt, messages, metadata), + ) + } + + private async *createMessageDeepSeek( + systemPrompt: string, + messages: Anthropic.Messages.MessageParam[], + metadata?: ApiHandlerCreateMessageMetadata, ): ApiStream { const modelId = this.options.apiModelId ?? deepSeekDefaultModelId const { info: modelInfo } = this.getModel() diff --git a/src/api/providers/gemini.ts b/src/api/providers/gemini.ts index 4402e3e017..e672584f8f 100644 --- a/src/api/providers/gemini.ts +++ b/src/api/providers/gemini.ts @@ -29,6 +29,7 @@ import { handleProviderError } from "./utils/error-handler" import type { SingleCompletionHandler, ApiHandlerCreateMessageMetadata } from "../index" import { BaseProvider } from "./base-provider" +import { withLogging, ApiLogger } from "../core/logging" type GeminiHandlerOptions = ApiHandlerOptions & { isVertex?: boolean @@ -40,7 +41,10 @@ export class GeminiHandler extends BaseProvider implements SingleCompletionHandl private client: GoogleGenAI private lastThoughtSignature?: string private lastResponseId?: string - private readonly providerName = "Gemini" + + protected override get providerName(): string { + return "Gemini" + } constructor({ isVertex, ...options }: GeminiHandlerOptions) { super() @@ -76,6 +80,30 @@ export class GeminiHandler extends BaseProvider implements SingleCompletionHandl systemInstruction: string, messages: Anthropic.Messages.MessageParam[], metadata?: ApiHandlerCreateMessageMetadata, + ): ApiStream { + yield* withLogging( + { + context: this.getLogContext("createMessage", metadata), + request: { + systemPromptLength: systemInstruction.length, + messageCount: messages.length, + hasTools: Boolean(metadata?.tools?.length), + toolCount: metadata?.tools?.length, + stream: true, + }, + }, + () => this.createMessageInternal(systemInstruction, messages, metadata), + ) + } + + /** + * Internal implementation of createMessage without logging wrapper. + * This is wrapped by createMessage with logging. + */ + private async *createMessageInternal( + systemInstruction: string, + messages: Anthropic.Messages.MessageParam[], + metadata?: ApiHandlerCreateMessageMetadata, ): ApiStream { const { id: model, info, reasoning: thinkingConfig, maxTokens } = this.getModel() // Reset per-request metadata that we persist into apiConversationHistory. @@ -400,6 +428,8 @@ export class GeminiHandler extends BaseProvider implements SingleCompletionHandl async completePrompt(prompt: string): Promise { const { id: model, info } = this.getModel() + const context = this.getLogContext("completePrompt") + const requestId = ApiLogger.logRequest(context, { messageCount: 1, stream: false }) try { const tools: GenerateContentConfig["tools"] = [] @@ -441,9 +471,17 @@ export class GeminiHandler extends BaseProvider implements SingleCompletionHandl } } + ApiLogger.logResponse(requestId, context, { + textLength: text.length, + }) + return text } catch (error) { const errorMessage = error instanceof Error ? error.message : String(error) + ApiLogger.logError(requestId, context, { + message: errorMessage, + }) + const apiError = new ApiProviderError(errorMessage, this.providerName, model, "completePrompt") TelemetryService.instance.captureException(apiError) diff --git a/src/api/providers/huggingface.ts b/src/api/providers/huggingface.ts index 7b62046b99..9704ead86f 100644 --- a/src/api/providers/huggingface.ts +++ b/src/api/providers/huggingface.ts @@ -14,7 +14,10 @@ export class HuggingFaceHandler extends BaseProvider implements SingleCompletion private client: OpenAI private options: ApiHandlerOptions private modelCache: ModelRecord | null = null - private readonly providerName = "HuggingFace" + + protected override get providerName(): string { + return "HuggingFace" + } constructor(options: ApiHandlerOptions) { super() diff --git a/src/api/providers/human-relay.ts b/src/api/providers/human-relay.ts index 54446bd362..499b5668b5 100644 --- a/src/api/providers/human-relay.ts +++ b/src/api/providers/human-relay.ts @@ -5,6 +5,7 @@ import type { ModelInfo } from "@roo-code/types" import { getCommand } from "../../utils/commands" import { ApiStream } from "../transform/stream" +import { withLogging, ApiLogger, type ApiLogContext } from "../core/logging" import type { ApiHandler, SingleCompletionHandler, ApiHandlerCreateMessageMetadata } from "../index" @@ -13,10 +14,28 @@ import type { ApiHandler, SingleCompletionHandler, ApiHandlerCreateMessageMetada * This processor does not directly call the API, but interacts with the model through human operations copy and paste. */ export class HumanRelayHandler implements ApiHandler, SingleCompletionHandler { + private readonly providerName = "Human Relay" + countTokens(_content: Array): Promise { return Promise.resolve(0) } + /** + * Helper to build log context for API calls + */ + private getLogContext( + operation: ApiLogContext["operation"], + metadata?: { taskId?: string }, + ): Omit { + const { id: model } = this.getModel() + return { + provider: this.providerName, + model, + operation, + taskId: metadata?.taskId, + } + } + /** * Create a message processing flow, display a dialog box to request human assistance * @param systemPrompt System prompt words @@ -27,6 +46,25 @@ export class HumanRelayHandler implements ApiHandler, SingleCompletionHandler { systemPrompt: string, messages: Anthropic.Messages.MessageParam[], metadata?: ApiHandlerCreateMessageMetadata, + ): ApiStream { + yield* withLogging( + { + context: this.getLogContext("createMessage", metadata), + request: { + systemPromptLength: systemPrompt.length, + messageCount: messages.length, + hasTools: false, + stream: false, // Human relay is not really streaming + }, + }, + () => this.createMessageInternal(systemPrompt, messages, metadata), + ) + } + + private async *createMessageInternal( + systemPrompt: string, + messages: Anthropic.Messages.MessageParam[], + _metadata?: ApiHandlerCreateMessageMetadata, ): ApiStream { // Get the most recent user message const latestMessage = messages[messages.length - 1] @@ -82,17 +120,39 @@ export class HumanRelayHandler implements ApiHandler, SingleCompletionHandler { * @param prompt Prompt content */ async completePrompt(prompt: string): Promise { - // Copy to clipboard - await vscode.env.clipboard.writeText(prompt) + const context = this.getLogContext("completePrompt") + const requestId = ApiLogger.logRequest(context, { + messageCount: 1, + stream: false, + }) - // A dialog box pops up to request user action - const response = await showHumanRelayDialog(prompt) + try { + // Copy to clipboard + await vscode.env.clipboard.writeText(prompt) - if (!response) { - throw new Error("Human relay operation cancelled") + // A dialog box pops up to request user action + const response = await showHumanRelayDialog(prompt) + + if (!response) { + ApiLogger.logError(requestId, context, { + message: "Human relay operation cancelled", + }) + throw new Error("Human relay operation cancelled") + } + + ApiLogger.logResponse(requestId, context, { + textLength: response.length, + }) + + return response + } catch (error) { + if (!(error instanceof Error && error.message === "Human relay operation cancelled")) { + ApiLogger.logError(requestId, context, { + message: error instanceof Error ? error.message : String(error), + }) + } + throw error } - - return response } } diff --git a/src/api/providers/lm-studio.ts b/src/api/providers/lm-studio.ts index 102c108dce..c0121ac253 100644 --- a/src/api/providers/lm-studio.ts +++ b/src/api/providers/lm-studio.ts @@ -21,7 +21,10 @@ import { handleOpenAIError } from "./utils/openai-error-handler" export class LmStudioHandler extends BaseProvider implements SingleCompletionHandler { protected options: ApiHandlerOptions private client: OpenAI - private readonly providerName = "LM Studio" + + protected override get providerName(): string { + return "LM Studio" + } constructor(options: ApiHandlerOptions) { super() diff --git a/src/api/providers/mistral.ts b/src/api/providers/mistral.ts index 95739cdcf7..2fa6647cf4 100644 --- a/src/api/providers/mistral.ts +++ b/src/api/providers/mistral.ts @@ -51,7 +51,10 @@ type MistralTool = { export class MistralHandler extends BaseProvider implements SingleCompletionHandler { protected options: ApiHandlerOptions private client: Mistral - private readonly providerName = "Mistral" + + protected override get providerName(): string { + return "Mistral" + } constructor(options: ApiHandlerOptions) { super() diff --git a/src/api/providers/native-ollama.ts b/src/api/providers/native-ollama.ts index 712b70445c..8293234ab5 100644 --- a/src/api/providers/native-ollama.ts +++ b/src/api/providers/native-ollama.ts @@ -3,6 +3,7 @@ import OpenAI from "openai" import { Message, Ollama, Tool as OllamaTool, type Config as OllamaOptions } from "ollama" import { ModelInfo, openAiModelInfoSaneDefaults, DEEP_SEEK_DEFAULT_TEMPERATURE } from "@roo-code/types" import { ApiStream } from "../transform/stream" +import { withLogging, ApiLogger } from "../core/logging" import { BaseProvider } from "./base-provider" import type { ApiHandlerOptions } from "../../shared/api" import { getOllamaModels } from "./fetchers/ollama" @@ -150,6 +151,10 @@ export class NativeOllamaHandler extends BaseProvider implements SingleCompletio private client: Ollama | undefined protected models: Record = {} + protected override get providerName(): string { + return "Ollama" + } + constructor(options: ApiHandlerOptions) { super() this.options = options @@ -204,6 +209,26 @@ export class NativeOllamaHandler extends BaseProvider implements SingleCompletio systemPrompt: string, messages: Anthropic.Messages.MessageParam[], metadata?: ApiHandlerCreateMessageMetadata, + ): ApiStream { + yield* withLogging( + { + context: this.getLogContext("createMessage", metadata), + request: { + systemPromptLength: systemPrompt.length, + messageCount: messages.length, + hasTools: Boolean(metadata?.tools?.length), + toolCount: metadata?.tools?.length, + stream: true, + }, + }, + () => this.createMessageInternal(systemPrompt, messages, metadata), + ) + } + + private async *createMessageInternal( + systemPrompt: string, + messages: Anthropic.Messages.MessageParam[], + metadata?: ApiHandlerCreateMessageMetadata, ): ApiStream { const client = this.ensureClient() const { id: modelId, info: modelInfo } = await this.fetchModel() @@ -341,6 +366,12 @@ export class NativeOllamaHandler extends BaseProvider implements SingleCompletio } async completePrompt(prompt: string): Promise { + const context = this.getLogContext("completePrompt") + const requestId = ApiLogger.logRequest(context, { + messageCount: 1, + stream: false, + }) + try { const client = this.ensureClient() const { id: modelId } = await this.fetchModel() @@ -363,8 +394,25 @@ export class NativeOllamaHandler extends BaseProvider implements SingleCompletio options: chatOptions, }) - return response.message?.content || "" + const result = response.message?.content || "" + + ApiLogger.logResponse(requestId, context, { + textLength: result.length, + usage: + response.eval_count || response.prompt_eval_count + ? { + inputTokens: response.prompt_eval_count || 0, + outputTokens: response.eval_count || 0, + } + : undefined, + }) + + return result } catch (error) { + ApiLogger.logError(requestId, context, { + message: error instanceof Error ? error.message : String(error), + }) + if (error instanceof Error) { throw new Error(`Ollama completion error: ${error.message}`) } diff --git a/src/api/providers/openai-native.ts b/src/api/providers/openai-native.ts index 762b81fc83..1bc17f0607 100644 --- a/src/api/providers/openai-native.ts +++ b/src/api/providers/openai-native.ts @@ -23,6 +23,7 @@ import { ApiStream, ApiStreamUsageChunk } from "../transform/stream" import { getModelParams } from "../transform/model-params" import { BaseProvider } from "./base-provider" +import { withLogging, ApiLogger } from "../core/logging" import type { SingleCompletionHandler, ApiHandlerCreateMessageMetadata } from "../index" export type OpenAiNativeModel = ReturnType @@ -30,7 +31,10 @@ export type OpenAiNativeModel = ReturnType export class OpenAiNativeHandler extends BaseProvider implements SingleCompletionHandler { protected options: ApiHandlerOptions private client: OpenAI - private readonly providerName = "OpenAI Native" + + protected override get providerName(): string { + return "OpenAI Native" + } // Resolved service tier from Responses API (actual tier used by OpenAI) private lastServiceTier: ServiceTier | undefined // Complete response output array (includes reasoning items with encrypted_content) @@ -135,6 +139,30 @@ export class OpenAiNativeHandler extends BaseProvider implements SingleCompletio systemPrompt: string, messages: Anthropic.Messages.MessageParam[], metadata?: ApiHandlerCreateMessageMetadata, + ): ApiStream { + yield* withLogging( + { + context: this.getLogContext("createMessage", metadata), + request: { + systemPromptLength: systemPrompt.length, + messageCount: messages.length, + hasTools: Boolean(metadata?.tools?.length), + toolCount: metadata?.tools?.length, + stream: true, + }, + }, + () => this.createMessageInternal(systemPrompt, messages, metadata), + ) + } + + /** + * Internal implementation of createMessage without logging wrapper. + * This is wrapped by createMessage with logging. + */ + private async *createMessageInternal( + systemPrompt: string, + messages: Anthropic.Messages.MessageParam[], + metadata?: ApiHandlerCreateMessageMetadata, ): ApiStream { const model = this.getModel() @@ -1265,6 +1293,9 @@ export class OpenAiNativeHandler extends BaseProvider implements SingleCompletio } async completePrompt(prompt: string): Promise { + const context = this.getLogContext("completePrompt") + const requestId = ApiLogger.logRequest(context, { messageCount: 1, stream: false }) + // Create AbortController for cancellation this.abortController = new AbortController() @@ -1337,6 +1368,9 @@ export class OpenAiNativeHandler extends BaseProvider implements SingleCompletio if (outputItem.type === "message" && outputItem.content) { for (const content of outputItem.content) { if (content.type === "output_text" && content.text) { + ApiLogger.logResponse(requestId, context, { + textLength: content.text.length, + }) return content.text } } @@ -1346,13 +1380,21 @@ export class OpenAiNativeHandler extends BaseProvider implements SingleCompletio // Fallback: check for direct text in response if (response?.text) { + ApiLogger.logResponse(requestId, context, { + textLength: response.text.length, + }) return response.text } + ApiLogger.logResponse(requestId, context, { textLength: 0 }) return "" } catch (error) { const errorModel = this.getModel() const errorMessage = error instanceof Error ? error.message : String(error) + ApiLogger.logError(requestId, context, { + message: errorMessage, + }) + const apiError = new ApiProviderError(errorMessage, this.providerName, errorModel.id, "completePrompt") TelemetryService.instance.captureException(apiError) diff --git a/src/api/providers/openai.ts b/src/api/providers/openai.ts index b198fe11d3..cd0bc798d7 100644 --- a/src/api/providers/openai.ts +++ b/src/api/providers/openai.ts @@ -22,6 +22,7 @@ import { getModelParams } from "../transform/model-params" import { DEFAULT_HEADERS } from "./constants" import { BaseProvider } from "./base-provider" +import { withLogging, ApiLogger } from "../core/logging" import type { SingleCompletionHandler, ApiHandlerCreateMessageMetadata } from "../index" import { getApiRequestTimeout } from "./utils/timeout-config" import { handleOpenAIError } from "./utils/openai-error-handler" @@ -32,7 +33,10 @@ import { handleOpenAIError } from "./utils/openai-error-handler" export class OpenAiHandler extends BaseProvider implements SingleCompletionHandler { protected options: ApiHandlerOptions protected client: OpenAI - private readonly providerName = "OpenAI" + + protected override get providerName(): string { + return "OpenAI" + } constructor(options: ApiHandlerOptions) { super() @@ -84,6 +88,30 @@ export class OpenAiHandler extends BaseProvider implements SingleCompletionHandl systemPrompt: string, messages: Anthropic.Messages.MessageParam[], metadata?: ApiHandlerCreateMessageMetadata, + ): ApiStream { + yield* withLogging( + { + context: this.getLogContext("createMessage", metadata), + request: { + systemPromptLength: systemPrompt.length, + messageCount: messages.length, + hasTools: Boolean(metadata?.tools?.length), + toolCount: metadata?.tools?.length, + stream: true, + }, + }, + () => this.createMessageInternal(systemPrompt, messages, metadata), + ) + } + + /** + * Internal implementation of createMessage without logging wrapper. + * This is wrapped by createMessage with logging. + */ + private async *createMessageInternal( + systemPrompt: string, + messages: Anthropic.Messages.MessageParam[], + metadata?: ApiHandlerCreateMessageMetadata, ): ApiStream { const { info: modelInfo, reasoning } = this.getModel() const modelUrl = this.options.openAiBaseUrl ?? "" @@ -305,6 +333,9 @@ export class OpenAiHandler extends BaseProvider implements SingleCompletionHandl } async completePrompt(prompt: string): Promise { + const context = this.getLogContext("completePrompt") + const requestId = ApiLogger.logRequest(context, { messageCount: 1, stream: false }) + try { const isAzureAiInference = this._isAzureAiInference(this.options.openAiBaseUrl) const model = this.getModel() @@ -328,8 +359,24 @@ export class OpenAiHandler extends BaseProvider implements SingleCompletionHandl throw handleOpenAIError(error, this.providerName) } - return response.choices?.[0]?.message.content || "" + const result = response.choices?.[0]?.message.content || "" + ApiLogger.logResponse(requestId, context, { + textLength: result.length, + usage: response.usage + ? { + inputTokens: response.usage.prompt_tokens || 0, + outputTokens: response.usage.completion_tokens || 0, + } + : undefined, + }) + + return result } catch (error) { + const errorMessage = error instanceof Error ? error.message : String(error) + ApiLogger.logError(requestId, context, { + message: errorMessage, + }) + if (error instanceof Error) { throw new Error(`${this.providerName} completion error: ${error.message}`) } diff --git a/src/api/providers/openrouter.ts b/src/api/providers/openrouter.ts index 5b8c29c337..075bae4ff4 100644 --- a/src/api/providers/openrouter.ts +++ b/src/api/providers/openrouter.ts @@ -16,6 +16,7 @@ import { NativeToolCallParser } from "../../core/assistant-message/NativeToolCal import type { ApiHandlerOptions, ModelRecord } from "../../shared/api" +import { withLogging, ApiLogger, createLoggingFetch } from "../core/logging" import { convertToOpenAiMessages } from "../transform/openai-format" import { normalizeMistralToolCallId } from "../transform/mistral-format" import { resolveToolProtocol } from "../../utils/resolveToolProtocol" @@ -140,9 +141,12 @@ export class OpenRouterHandler extends BaseProvider implements SingleCompletionH private client: OpenAI protected models: ModelRecord = {} protected endpoints: ModelRecord = {} - private readonly providerName = "OpenRouter" private currentReasoningDetails: any[] = [] + protected override get providerName(): string { + return "OpenRouter" + } + constructor(options: ApiHandlerOptions) { super() this.options = options @@ -150,7 +154,13 @@ export class OpenRouterHandler extends BaseProvider implements SingleCompletionH const baseURL = this.options.openRouterBaseUrl || "https://openrouter.ai/api/v1" const apiKey = this.options.openRouterApiKey ?? "not-provided" - this.client = new OpenAI({ baseURL, apiKey, defaultHeaders: DEFAULT_HEADERS }) + // Use logging fetch for raw HTTP request logging when enabled + this.client = new OpenAI({ + baseURL, + apiKey, + defaultHeaders: DEFAULT_HEADERS, + fetch: createLoggingFetch(this.providerName), + }) // Load models asynchronously to populate cache before getModel() is called this.loadDynamicModels().catch((error) => { @@ -207,6 +217,26 @@ export class OpenRouterHandler extends BaseProvider implements SingleCompletionH systemPrompt: string, messages: Anthropic.Messages.MessageParam[], metadata?: ApiHandlerCreateMessageMetadata, + ): AsyncGenerator { + yield* withLogging( + { + context: this.getLogContext("createMessage", metadata), + request: { + systemPromptLength: systemPrompt.length, + messageCount: messages.length, + hasTools: Boolean(metadata?.tools?.length), + toolCount: metadata?.tools?.length, + stream: true, + }, + }, + () => this.createMessageInternal(systemPrompt, messages, metadata), + ) + } + + private async *createMessageInternal( + systemPrompt: string, + messages: Anthropic.Messages.MessageParam[], + metadata?: ApiHandlerCreateMessageMetadata, ): AsyncGenerator { const model = await this.fetchModel() @@ -547,7 +577,14 @@ export class OpenRouterHandler extends BaseProvider implements SingleCompletionH } async completePrompt(prompt: string) { - let { id: modelId, maxTokens, temperature, reasoning } = await this.fetchModel() + const model = await this.fetchModel() + let { id: modelId, maxTokens, temperature, reasoning } = model + + const context = this.getLogContext("completePrompt") + const requestId = ApiLogger.logRequest(context, { + messageCount: 1, + stream: false, + }) const completionParams: OpenRouterChatCompletionParams = { model: modelId, @@ -612,11 +649,27 @@ export class OpenRouterHandler extends BaseProvider implements SingleCompletionH } if ("error" in response) { + ApiLogger.logError(requestId, context, { + message: `OpenRouter error: ${(response.error as OpenRouterError)?.message || "Unknown error"}`, + code: (response.error as OpenRouterError)?.code, + }) this.handleStreamingError(response.error as OpenRouterError, modelId, "completePrompt") } const completion = response as OpenAI.Chat.ChatCompletion - return completion.choices[0]?.message?.content || "" + const content = completion.choices[0]?.message?.content || "" + + ApiLogger.logResponse(requestId, context, { + textLength: content.length, + usage: completion.usage + ? { + inputTokens: completion.usage.prompt_tokens, + outputTokens: completion.usage.completion_tokens, + } + : undefined, + }) + + return content } /** diff --git a/src/api/providers/requesty.ts b/src/api/providers/requesty.ts index 85efeb800f..280be83a67 100644 --- a/src/api/providers/requesty.ts +++ b/src/api/providers/requesty.ts @@ -61,7 +61,10 @@ export class RequestyHandler extends BaseProvider implements SingleCompletionHan protected models: ModelRecord = {} private client: OpenAI private baseURL: string - private readonly providerName = "Requesty" + + protected override get providerName(): string { + return "Requesty" + } constructor(options: ApiHandlerOptions) { super() diff --git a/src/api/providers/roo.ts b/src/api/providers/roo.ts index 83eab87ef7..4e0e0e6e98 100644 --- a/src/api/providers/roo.ts +++ b/src/api/providers/roo.ts @@ -14,6 +14,7 @@ import type { RooReasoningParams } from "../transform/reasoning" import { getRooReasoning } from "../transform/reasoning" import type { ApiHandlerCreateMessageMetadata } from "../index" +import { withLogging } from "../core/logging" import { BaseOpenAiCompatibleProvider } from "./base-openai-compatible-provider" import { getModels, getModelsFromCache } from "../providers/fetchers/modelCache" import { handleOpenAIError } from "./utils/openai-error-handler" @@ -124,6 +125,26 @@ export class RooHandler extends BaseOpenAiCompatibleProvider { systemPrompt: string, messages: Anthropic.Messages.MessageParam[], metadata?: ApiHandlerCreateMessageMetadata, + ): ApiStream { + yield* withLogging( + { + context: this.getLogContext("createMessage", metadata), + request: { + systemPromptLength: systemPrompt.length, + messageCount: messages.length, + hasTools: Boolean(metadata?.tools?.length), + toolCount: metadata?.tools?.length, + stream: true, + }, + }, + () => this.createMessageRoo(systemPrompt, messages, metadata), + ) + } + + private async *createMessageRoo( + systemPrompt: string, + messages: Anthropic.Messages.MessageParam[], + metadata?: ApiHandlerCreateMessageMetadata, ): ApiStream { try { // Reset reasoning_details accumulator for this request diff --git a/src/api/providers/vscode-lm.ts b/src/api/providers/vscode-lm.ts index ed244ba97d..ec4e0cd1a6 100644 --- a/src/api/providers/vscode-lm.ts +++ b/src/api/providers/vscode-lm.ts @@ -9,6 +9,7 @@ import { SELECTOR_SEPARATOR, stringifyVsCodeLmModelSelector } from "../../shared import { ApiStream } from "../transform/stream" import { convertToVsCodeLmMessages, extractTextCountFromMessage } from "../transform/vscode-lm-format" +import { withLogging, ApiLogger } from "../core/logging" import { BaseProvider } from "./base-provider" import type { SingleCompletionHandler, ApiHandlerCreateMessageMetadata } from "../index" @@ -61,6 +62,10 @@ export class VsCodeLmHandler extends BaseProvider implements SingleCompletionHan private disposable: vscode.Disposable | null private currentRequestCancellation: vscode.CancellationTokenSource | null + protected override get providerName(): string { + return "VSCode LM" + } + constructor(options: ApiHandlerOptions) { super() this.options = options @@ -350,6 +355,26 @@ export class VsCodeLmHandler extends BaseProvider implements SingleCompletionHan systemPrompt: string, messages: Anthropic.Messages.MessageParam[], metadata?: ApiHandlerCreateMessageMetadata, + ): ApiStream { + yield* withLogging( + { + context: this.getLogContext("createMessage", metadata), + request: { + systemPromptLength: systemPrompt.length, + messageCount: messages.length, + hasTools: Boolean(metadata?.tools?.length), + toolCount: metadata?.tools?.length, + stream: true, + }, + }, + () => this.createMessageInternal(systemPrompt, messages, metadata), + ) + } + + private async *createMessageInternal( + systemPrompt: string, + messages: Anthropic.Messages.MessageParam[], + metadata?: ApiHandlerCreateMessageMetadata, ): ApiStream { // Ensure clean state before starting a new request this.ensureCleanState() @@ -574,6 +599,12 @@ export class VsCodeLmHandler extends BaseProvider implements SingleCompletionHan } async completePrompt(prompt: string): Promise { + const context = this.getLogContext("completePrompt") + const requestId = ApiLogger.logRequest(context, { + messageCount: 1, + stream: false, + }) + try { const client = await this.getClient() const response = await client.sendRequest( @@ -587,8 +618,17 @@ export class VsCodeLmHandler extends BaseProvider implements SingleCompletionHan result += chunk.value } } + + ApiLogger.logResponse(requestId, context, { + textLength: result.length, + }) + return result } catch (error) { + ApiLogger.logError(requestId, context, { + message: error instanceof Error ? error.message : String(error), + }) + if (error instanceof Error) { throw new Error(`VSCode LM completion error: ${error.message}`) } diff --git a/src/api/providers/xai.ts b/src/api/providers/xai.ts index a1377a1317..61238d9db7 100644 --- a/src/api/providers/xai.ts +++ b/src/api/providers/xai.ts @@ -21,7 +21,10 @@ const XAI_DEFAULT_TEMPERATURE = 0 export class XAIHandler extends BaseProvider implements SingleCompletionHandler { protected options: ApiHandlerOptions private client: OpenAI - private readonly providerName = "xAI" + + protected override get providerName(): string { + return "xAI" + } constructor(options: ApiHandlerOptions) { super() diff --git a/src/utils/logging/index.ts b/src/utils/logging/index.ts index 76a4629d24..3843835a7e 100644 --- a/src/utils/logging/index.ts +++ b/src/utils/logging/index.ts @@ -20,6 +20,9 @@ const noopLogger = { /** * Default logger instance - * Uses CompactLogger for normal operation, switches to noop logger in Jest test environment + * Uses CompactLogger for test environment, switches to noop logger in production + * + * Note: For API logging, use the ApiLogger from src/api/core/logging which + * outputs to console.log when ROO_CODE_LOGGING=true */ export const logger = process.env.NODE_ENV === "test" ? new CompactLogger() : noopLogger