feat: API inference logging middleware

This commit is contained in:
Hannes Rudolph 2025-12-29 17:44:04 -07:00
parent e24cd0de81
commit 099cf851f9
35 changed files with 2928 additions and 1342 deletions

View file

@ -238,6 +238,43 @@ describe("extension.ts", () => {
authStateChangedHandler = undefined
})
test("API inference logging writes to Debug Console when ROO_CODE_API_LOGGING=true", async () => {
const previousValue = process.env.ROO_CODE_API_LOGGING
process.env.ROO_CODE_API_LOGGING = "true"
const consoleLogSpy = vi.spyOn(console, "log").mockImplementation(() => {})
try {
const { activate } = await import("../extension")
await activate(mockContext)
const { ApiInferenceLogger } = await import("../api/logging/ApiInferenceLogger")
ApiInferenceLogger.start(
{
provider: "Test Provider",
operation: "createMessage",
model: "test-model",
taskId: "test-task",
requestId: "test-request",
},
{ messageCount: 1 },
)
// New simplified format: [API][request][Provider][model] + raw payload
expect(consoleLogSpy).toHaveBeenCalledWith(
"[API][request][Test Provider][test-model]",
expect.objectContaining({ messageCount: 1 }),
)
} finally {
consoleLogSpy.mockRestore()
if (previousValue === undefined) {
delete process.env.ROO_CODE_API_LOGGING
} else {
process.env.ROO_CODE_API_LOGGING = previousValue
}
}
})
test("authStateChangedHandler calls BridgeOrchestrator.disconnect when logged-out event fires", async () => {
const { CloudService, BridgeOrchestrator } = await import("@roo-code/cloud")

View file

@ -182,6 +182,41 @@ class ApiInferenceLoggerSingleton {
private enabled = false
private sink: ((...args: unknown[]) => void) | null = null
/**
* Emit an already-formatted log entry.
* This is used by HTTP-level middleware to preserve exact label formats.
*/
logRaw(label: string, payload: unknown): void {
if (!this.isEnabled() || !this.sink) return
try {
this.sink(label, sanitizePayload(payload))
} catch {
// Silently ignore logging errors to avoid breaking the application
}
}
/**
* Emit an already-formatted error log entry.
*/
logRawError(label: string, errorPayload: unknown): void {
if (!this.isEnabled() || !this.sink) return
try {
let errorData: unknown
if (errorPayload instanceof Error) {
errorData = {
name: errorPayload.name,
message: errorPayload.message,
stack: errorPayload.stack,
}
} else {
errorData = sanitizePayload(errorPayload)
}
this.sink(label, errorData)
} catch {
// Silently ignore logging errors to avoid breaking the application
}
}
/**
* Configure the logger with enabled state and output sink.
* Should be called once during extension activation.
@ -250,7 +285,7 @@ class ApiInferenceLoggerSingleton {
}
/**
* Log a request with stable tag format.
* Log a request - outputs only the raw request payload for debugging.
*/
private logRequest(data: {
provider: string
@ -261,25 +296,11 @@ class ApiInferenceLoggerSingleton {
timestamp: string
payload: unknown
}): void {
if (!this.sink) return
try {
this.sink("[API][request]", {
provider: data.provider,
operation: data.operation,
model: data.model,
taskId: data.taskId,
requestId: data.requestId,
timestamp: data.timestamp,
payload: sanitizePayload(data.payload),
})
} catch {
// Silently ignore logging errors to avoid breaking the application
}
this.logRaw(`[API][request][${data.provider}][${data.model ?? "unknown"}]`, data.payload)
}
/**
* Log a successful response with stable tag format.
* Log a successful response - outputs only the raw response payload for debugging.
*/
private logResponse(data: {
provider: string
@ -291,26 +312,11 @@ class ApiInferenceLoggerSingleton {
durationMs: number
payload: unknown
}): void {
if (!this.sink) return
try {
this.sink("[API][response]", {
provider: data.provider,
operation: data.operation,
model: data.model,
taskId: data.taskId,
requestId: data.requestId,
timestamp: data.timestamp,
durationMs: data.durationMs,
payload: sanitizePayload(data.payload),
})
} catch {
// Silently ignore logging errors to avoid breaking the application
}
this.logRaw(`[API][response][${data.provider}][${data.model ?? "unknown"}][${data.durationMs}ms]`, data.payload)
}
/**
* Log an error response with stable tag format.
* Log an error response - outputs only the error details for debugging.
*/
private logError(data: {
provider: string
@ -322,34 +328,7 @@ class ApiInferenceLoggerSingleton {
durationMs: number
error: unknown
}): void {
if (!this.sink) return
try {
// Handle Error objects specially
let errorData: unknown
if (data.error instanceof Error) {
errorData = {
name: data.error.name,
message: data.error.message,
stack: data.error.stack,
}
} else {
errorData = sanitizePayload(data.error)
}
this.sink("[API][error]", {
provider: data.provider,
operation: data.operation,
model: data.model,
taskId: data.taskId,
requestId: data.requestId,
timestamp: data.timestamp,
durationMs: data.durationMs,
error: errorData,
})
} catch {
// Silently ignore logging errors to avoid breaking the application
}
this.logRawError(`[API][error][${data.provider}][${data.model ?? "unknown"}][${data.durationMs}ms]`, data.error)
}
}

View file

@ -36,21 +36,17 @@ describe("ApiInferenceLogger", () => {
ApiInferenceLogger.configure({ enabled: true, sink: mockSink })
})
it("should emit a request log with [API][request] tag", () => {
it("should emit a request log with simplified label format", () => {
ApiInferenceLogger.start({ provider: "OpenAI", operation: "createMessage" }, { model: "gpt-4" })
expect(mockSink).toHaveBeenCalledTimes(1)
expect(mockSink).toHaveBeenCalledWith(
"[API][request]",
expect.objectContaining({
provider: "OpenAI",
operation: "createMessage",
payload: expect.objectContaining({ model: "gpt-4" }),
}),
"[API][request][OpenAI][unknown]",
expect.objectContaining({ model: "gpt-4" }),
)
})
it("should include context fields in the log", () => {
it("should use context.model in the request label", () => {
ApiInferenceLogger.start(
{
provider: "Anthropic",
@ -63,25 +59,8 @@ describe("ApiInferenceLogger", () => {
)
expect(mockSink).toHaveBeenCalledWith(
"[API][request]",
expect.objectContaining({
provider: "Anthropic",
operation: "createMessage",
model: "claude-3",
taskId: "task-123",
requestId: "req-456",
}),
)
})
it("should generate a requestId if not provided", () => {
ApiInferenceLogger.start({ provider: "test", operation: "test" }, {})
expect(mockSink).toHaveBeenCalledWith(
"[API][request]",
expect.objectContaining({
requestId: expect.stringMatching(/^req_\d+_[a-z0-9]+$/),
}),
"[API][request][Anthropic][claude-3]",
expect.objectContaining({ test: "data" }),
)
})
})
@ -91,7 +70,7 @@ describe("ApiInferenceLogger", () => {
ApiInferenceLogger.configure({ enabled: true, sink: mockSink })
})
it("should emit a response log with [API][response] tag", () => {
it("should emit a response log with simplified label format", () => {
const handle = ApiInferenceLogger.start({ provider: "OpenAI", operation: "createMessage" }, {})
mockSink.mockClear()
@ -99,29 +78,10 @@ describe("ApiInferenceLogger", () => {
expect(mockSink).toHaveBeenCalledTimes(1)
expect(mockSink).toHaveBeenCalledWith(
"[API][response]",
expect.stringMatching(/^\[API\]\[response\]\[OpenAI\]\[unknown\]\[\d+ms\]$/),
expect.objectContaining({
provider: "OpenAI",
operation: "createMessage",
payload: expect.objectContaining({
text: "Hello world",
usage: { inputTokens: 10, outputTokens: 20 },
}),
}),
)
})
it("should include duration in the response log", () => {
const handle = ApiInferenceLogger.start({ provider: "test", operation: "test" }, {})
mockSink.mockClear()
// Small delay to ensure measurable duration
handle.success({ response: "data" })
expect(mockSink).toHaveBeenCalledWith(
"[API][response]",
expect.objectContaining({
durationMs: expect.any(Number),
text: "Hello world",
usage: { inputTokens: 10, outputTokens: 20 },
}),
)
})
@ -132,7 +92,7 @@ describe("ApiInferenceLogger", () => {
ApiInferenceLogger.configure({ enabled: true, sink: mockSink })
})
it("should emit an error log with [API][error] tag", () => {
it("should emit an error log with simplified label format", () => {
const handle = ApiInferenceLogger.start({ provider: "OpenAI", operation: "createMessage" }, {})
mockSink.mockClear()
@ -140,28 +100,10 @@ describe("ApiInferenceLogger", () => {
expect(mockSink).toHaveBeenCalledTimes(1)
expect(mockSink).toHaveBeenCalledWith(
"[API][error]",
expect.stringMatching(/^\[API\]\[error\]\[OpenAI\]\[unknown\]\[\d+ms\]$/),
expect.objectContaining({
provider: "OpenAI",
operation: "createMessage",
error: expect.objectContaining({
name: "Error",
message: "API request failed",
}),
}),
)
})
it("should include duration in the error log", () => {
const handle = ApiInferenceLogger.start({ provider: "test", operation: "test" }, {})
mockSink.mockClear()
handle.error({ code: 500, message: "Internal error" })
expect(mockSink).toHaveBeenCalledWith(
"[API][error]",
expect.objectContaining({
durationMs: expect.any(Number),
name: "Error",
message: "API request failed",
}),
)
})
@ -173,12 +115,10 @@ describe("ApiInferenceLogger", () => {
handle.error({ status: 401, message: "Unauthorized" })
expect(mockSink).toHaveBeenCalledWith(
"[API][error]",
expect.stringMatching(/^\[API\]\[error\]\[test\]\[unknown\]\[\d+ms\]$/),
expect.objectContaining({
error: expect.objectContaining({
status: 401,
message: "Unauthorized",
}),
status: 401,
message: "Unauthorized",
}),
)
})
@ -196,11 +136,9 @@ describe("ApiInferenceLogger", () => {
)
expect(mockSink).toHaveBeenCalledWith(
"[API][request]",
"[API][request][test][unknown]",
expect.objectContaining({
payload: expect.objectContaining({
headers: { Authorization: "[REDACTED]" },
}),
headers: { Authorization: "[REDACTED]" },
}),
)
})
@ -209,11 +147,9 @@ describe("ApiInferenceLogger", () => {
ApiInferenceLogger.start({ provider: "test", operation: "test" }, { apiKey: "sk-secret-12345" })
expect(mockSink).toHaveBeenCalledWith(
"[API][request]",
"[API][request][test][unknown]",
expect.objectContaining({
payload: expect.objectContaining({
apiKey: "[REDACTED]",
}),
apiKey: "[REDACTED]",
}),
)
})
@ -232,16 +168,14 @@ describe("ApiInferenceLogger", () => {
)
expect(mockSink).toHaveBeenCalledWith(
"[API][request]",
"[API][request][test][unknown]",
expect.objectContaining({
payload: expect.objectContaining({
config: {
auth: {
access_token: "[REDACTED]",
api_key: "[REDACTED]",
},
config: {
auth: {
access_token: "[REDACTED]",
api_key: "[REDACTED]",
},
}),
},
}),
)
})
@ -255,11 +189,9 @@ describe("ApiInferenceLogger", () => {
)
expect(mockSink).toHaveBeenCalledWith(
"[API][request]",
"[API][request][test][unknown]",
expect.objectContaining({
payload: expect.objectContaining({
items: [{ apiKey: "[REDACTED]" }, { apiKey: "[REDACTED]" }],
}),
items: [{ apiKey: "[REDACTED]" }, { apiKey: "[REDACTED]" }],
}),
)
})
@ -271,12 +203,10 @@ describe("ApiInferenceLogger", () => {
)
expect(mockSink).toHaveBeenCalledWith(
"[API][request]",
"[API][request][test][unknown]",
expect.objectContaining({
payload: expect.objectContaining({
model: "gpt-4",
messages: [{ role: "user", content: "Hello" }],
}),
model: "gpt-4",
messages: [{ role: "user", content: "Hello" }],
}),
)
})
@ -292,11 +222,9 @@ describe("ApiInferenceLogger", () => {
ApiInferenceLogger.start({ provider: "test", operation: "test" }, { content: longString })
expect(mockSink).toHaveBeenCalledWith(
"[API][request]",
"[API][request][test][unknown]",
expect.objectContaining({
payload: expect.objectContaining({
content: "[Truncated len=15000]",
}),
content: "[Truncated len=15000]",
}),
)
})
@ -306,11 +234,9 @@ describe("ApiInferenceLogger", () => {
ApiInferenceLogger.start({ provider: "test", operation: "test" }, { content: normalString })
expect(mockSink).toHaveBeenCalledWith(
"[API][request]",
"[API][request][test][unknown]",
expect.objectContaining({
payload: expect.objectContaining({
content: normalString,
}),
content: normalString,
}),
)
})
@ -321,11 +247,9 @@ describe("ApiInferenceLogger", () => {
ApiInferenceLogger.start({ provider: "test", operation: "test" }, { image: imageData })
expect(mockSink).toHaveBeenCalledWith(
"[API][request]",
"[API][request][test][unknown]",
expect.objectContaining({
payload: expect.objectContaining({
image: expect.stringMatching(/^\[ImageData len=\d+\]$/),
}),
image: expect.stringMatching(/^\[ImageData len=\d+\]$/),
}),
)
})
@ -342,14 +266,12 @@ describe("ApiInferenceLogger", () => {
)
expect(mockSink).toHaveBeenCalledWith(
"[API][request]",
"[API][request][test][unknown]",
expect.objectContaining({
payload: expect.objectContaining({
png: expect.stringMatching(/^\[ImageData len=\d+\]$/),
jpeg: expect.stringMatching(/^\[ImageData len=\d+\]$/),
gif: expect.stringMatching(/^\[ImageData len=\d+\]$/),
webp: expect.stringMatching(/^\[ImageData len=\d+\]$/),
}),
png: expect.stringMatching(/^\[ImageData len=\d+\]$/),
jpeg: expect.stringMatching(/^\[ImageData len=\d+\]$/),
gif: expect.stringMatching(/^\[ImageData len=\d+\]$/),
webp: expect.stringMatching(/^\[ImageData len=\d+\]$/),
}),
)
})
@ -359,7 +281,7 @@ describe("ApiInferenceLogger", () => {
ApiInferenceLogger.start({ provider: "test", operation: "test" }, { items: longArray })
const call = mockSink.mock.calls[0]
const payload = call[1].payload as { items: any[] }
const payload = call[1] as { items: any[] }
expect(payload.items.length).toBe(201)
expect(payload.items[200]).toBe("[...50 more items]")
@ -370,7 +292,7 @@ describe("ApiInferenceLogger", () => {
ApiInferenceLogger.start({ provider: "test", operation: "test" }, { items: normalArray })
const call = mockSink.mock.calls[0]
const payload = call[1].payload as { items: any[] }
const payload = call[1] as { items: any[] }
expect(payload.items.length).toBe(50)
})
@ -383,7 +305,7 @@ describe("ApiInferenceLogger", () => {
ApiInferenceLogger.start({ provider: "test", operation: "test" }, bigObject)
const call = mockSink.mock.calls[0]
const payload = call[1].payload as Record<string, unknown>
const payload = call[1] as Record<string, unknown>
const keys = Object.keys(payload)
expect(keys.length).toBe(201)
@ -402,14 +324,12 @@ describe("ApiInferenceLogger", () => {
ApiInferenceLogger.start({ provider: "test", operation: "test" }, nested)
expect(mockSink).toHaveBeenCalledWith(
"[API][request]",
"[API][request][test][unknown]",
expect.objectContaining({
payload: expect.objectContaining({
level1: expect.objectContaining({
longString: "[Truncated len=15000]",
level2: expect.objectContaining({
imageData: expect.stringMatching(/^\[ImageData len=\d+\]$/),
}),
level1: expect.objectContaining({
longString: "[Truncated len=15000]",
level2: expect.objectContaining({
imageData: expect.stringMatching(/^\[ImageData len=\d+\]$/),
}),
}),
}),
@ -424,20 +344,18 @@ describe("ApiInferenceLogger", () => {
ApiInferenceLogger.start({ provider: "test", operation: "test" }, { messages })
expect(mockSink).toHaveBeenCalledWith(
"[API][request]",
"[API][request][test][unknown]",
expect.objectContaining({
payload: expect.objectContaining({
messages: [
expect.objectContaining({
role: "user",
content: "[Truncated len=15000]",
}),
expect.objectContaining({
role: "assistant",
content: expect.stringMatching(/^\[ImageData len=\d+\]$/),
}),
],
}),
messages: [
expect.objectContaining({
role: "user",
content: "[Truncated len=15000]",
}),
expect.objectContaining({
role: "assistant",
content: expect.stringMatching(/^\[ImageData len=\d+\]$/),
}),
],
}),
)
})
@ -454,12 +372,10 @@ describe("ApiInferenceLogger", () => {
}).not.toThrow()
expect(mockSink).toHaveBeenCalledWith(
"[API][request]",
"[API][request][test][unknown]",
expect.objectContaining({
payload: expect.objectContaining({
value: null,
other: undefined,
}),
value: null,
other: undefined,
}),
)
})

View file

@ -0,0 +1,271 @@
import { ApiInferenceLogger } from "../ApiInferenceLogger"
import { createLoggingFetch } from "../logging-fetch"
describe("createLoggingFetch", () => {
beforeEach(() => {
ApiInferenceLogger.configure({ enabled: true, sink: vi.fn() })
})
afterEach(() => {
ApiInferenceLogger.configure({ enabled: false, sink: () => {} })
})
it("logs request and JSON response with expected labels", async () => {
const sink = vi.fn()
ApiInferenceLogger.configure({ enabled: true, sink })
const baseFetch: typeof fetch = async (_input, init) => {
expect(init?.method).toBe("POST")
return new Response(JSON.stringify({ ok: true }), {
status: 200,
headers: { "content-type": "application/json" },
})
}
const loggingFetch = createLoggingFetch({ provider: "TestProvider" }, baseFetch)
await loggingFetch("https://example.com/v1/test", {
method: "POST",
headers: { "content-type": "application/json" },
body: JSON.stringify({ model: "test-model", foo: "bar" }),
})
expect(sink).toHaveBeenCalledWith(
"[API][request][TestProvider][test-model]",
expect.objectContaining({ model: "test-model", foo: "bar" }),
)
expect(sink).toHaveBeenCalledWith(
expect.stringMatching(/^\[API\]\[response\]\[TestProvider\]\[test-model\]\[\d+ms\]$/),
expect.objectContaining({ ok: true }),
)
})
it("tees SSE responses so the consumer can still read the stream", async () => {
const sink = vi.fn()
ApiInferenceLogger.configure({ enabled: true, sink })
const encoder = new TextEncoder()
const events = [
{
id: "1",
model: "test-model",
object: "chat.completion.chunk",
choices: [{ index: 0, delta: { role: "assistant", content: "He" } }],
},
{
id: "1",
model: "test-model",
object: "chat.completion.chunk",
choices: [{ index: 0, delta: { content: "llo" } }],
},
{
id: "1",
model: "test-model",
object: "chat.completion.chunk",
choices: [
{
index: 0,
delta: {
tool_calls: [
{
index: 0,
id: "tc_1",
type: "function",
function: { name: "do", arguments: '{"a":' },
},
],
},
},
],
},
{
id: "1",
model: "test-model",
object: "chat.completion.chunk",
choices: [
{
index: 0,
delta: {
tool_calls: [{ index: 0, id: "tc_1", type: "function", function: { arguments: "1}" } }],
},
},
],
},
{
id: "1",
model: "test-model",
object: "chat.completion.chunk",
choices: [{ index: 0, delta: {}, finish_reason: "tool_calls" }],
usage: { prompt_tokens: 1, completion_tokens: 2 },
},
]
const sse =
`: OPENROUTER PROCESSING\n\n` +
events.map((e) => `data: ${JSON.stringify(e)}\n\n`).join("") +
`data: [DONE]\n\n`
const baseFetch: typeof fetch = async () => {
return new Response(
new ReadableStream<Uint8Array>({
start(controller) {
controller.enqueue(encoder.encode(sse))
controller.close()
},
}),
{
status: 200,
headers: { "content-type": "text/event-stream" },
},
)
}
const loggingFetch = createLoggingFetch({ provider: "TestProvider" }, baseFetch)
const res = await loggingFetch("https://example.com/v1/stream", {
method: "POST",
body: JSON.stringify({ model: "test-model" }),
})
// Consumer still receives the body.
const consumerText = await res.text()
expect(consumerText).toContain("data:")
// Logger gets a streaming label.
expect(sink).toHaveBeenCalledWith(
expect.stringMatching(/^\[API\]\[response\]\[TestProvider\]\[test-model\]\[\d+ms\]\[streaming\]$/),
expect.objectContaining({
object: "chat.completion",
model: "test-model",
choices: [
expect.objectContaining({
index: 0,
finish_reason: "tool_calls",
message: expect.objectContaining({
role: "assistant",
content: "Hello",
}),
}),
],
usage: expect.objectContaining({ prompt_tokens: 1, completion_tokens: 2 }),
__sse: expect.objectContaining({
format: "sse",
__rawSse: expect.anything(),
events: expect.any(Array),
}),
}),
)
})
it("logs non-OpenAI SSE in a structured preview object", async () => {
const sink = vi.fn()
ApiInferenceLogger.configure({ enabled: true, sink })
const encoder = new TextEncoder()
const sse =
`event: ping\n` +
`data: {"type":"ping","t":123}\n\n` +
`event: custom\n` +
`data: hello world\n\n` +
`data: [DONE]\n\n`
const baseFetch: typeof fetch = async () => {
return new Response(
new ReadableStream<Uint8Array>({
start(controller) {
controller.enqueue(encoder.encode(sse))
controller.close()
},
}),
{
status: 200,
headers: { "content-type": "text/event-stream" },
},
)
}
const loggingFetch = createLoggingFetch({ provider: "TestProvider" }, baseFetch)
const res = await loggingFetch("https://example.com/v1/stream", {
method: "POST",
body: JSON.stringify({ model: "test-model" }),
})
// Drain the consumer stream and allow the async logger to finish.
await res.text()
await new Promise((r) => setTimeout(r, 0))
expect(sink).toHaveBeenCalledWith(
expect.stringMatching(/^\[API\]\[response\]\[TestProvider\]\[test-model\]\[\d+ms\]\[streaming\]$/),
expect.objectContaining({
format: "sse",
__rawSse: expect.anything(),
events: expect.arrayContaining([
expect.objectContaining({ event: "ping", data: expect.objectContaining({ type: "ping" }) }),
expect.objectContaining({ event: "custom" }),
]),
}),
)
})
it("assembles Anthropic Messages SSE into a final message object", async () => {
const sink = vi.fn()
ApiInferenceLogger.configure({ enabled: true, sink })
const encoder = new TextEncoder()
const sse =
`event: message_start\n` +
`data: {"type":"message_start","message":{"id":"msg_1","type":"message","role":"assistant","model":"claude-test","content":[],"stop_reason":null,"stop_sequence":null,"usage":{"input_tokens":1,"output_tokens":0}}}\n\n` +
`event: content_block_start\n` +
`data: {"type":"content_block_start","index":0,"content_block":{"type":"thinking","thinking":"","signature":""}}\n\n` +
`event: content_block_delta\n` +
`data: {"type":"content_block_delta","index":0,"delta":{"type":"thinking_delta","thinking":"Hello"}}\n\n` +
`event: content_block_delta\n` +
`data: {"type":"content_block_delta","index":0,"delta":{"type":"signature_delta","signature":"sig_123"}}\n\n` +
`event: content_block_stop\n` +
`data: {"type":"content_block_stop","index":0}\n\n` +
`event: message_delta\n` +
`data: {"type":"message_delta","delta":{"stop_reason":"end_turn"},"usage":{"output_tokens":2}}\n\n` +
`event: message_stop\n` +
`data: {"type":"message_stop"}\n\n`
const baseFetch: typeof fetch = async () => {
return new Response(
new ReadableStream<Uint8Array>({
start(controller) {
controller.enqueue(encoder.encode(sse))
controller.close()
},
}),
{
status: 200,
headers: { "content-type": "text/event-stream" },
},
)
}
const loggingFetch = createLoggingFetch({ provider: "Anthropic" }, baseFetch)
const res = await loggingFetch("https://example.com/v1/messages", {
method: "POST",
body: JSON.stringify({ model: "claude-test" }),
})
await res.text()
await new Promise((r) => setTimeout(r, 0))
expect(sink).toHaveBeenCalledWith(
expect.stringMatching(/^\[API\]\[response\]\[Anthropic\]\[claude-test\]\[\d+ms\]\[streaming\]$/),
expect.objectContaining({
type: "message",
id: "msg_1",
model: "claude-test",
role: "assistant",
stop_reason: "end_turn",
usage: expect.objectContaining({ input_tokens: 1, output_tokens: 2 }),
content: [expect.objectContaining({ type: "thinking", thinking: "Hello", signature: "sig_123" })],
__sse: expect.objectContaining({
format: "sse",
__rawSse: expect.anything(),
events: expect.any(Array),
}),
}),
)
})
})

View file

@ -0,0 +1,757 @@
import { ApiInferenceLogger } from "./ApiInferenceLogger"
export type LoggingFetchOptions = {
provider: string
/**
* Maximum number of bytes to buffer from request/response bodies.
* This protects against OOM when logging is enabled.
*/
maxBodySizeBytes?: number
}
const DEFAULT_MAX_BODY_SIZE_BYTES = 512 * 1024
function getMaxBodySizeBytes(maxBodySizeBytes?: number): number {
return typeof maxBodySizeBytes === "number" && maxBodySizeBytes > 0 ? maxBodySizeBytes : DEFAULT_MAX_BODY_SIZE_BYTES
}
function tryParseJson(text: string): unknown {
try {
return JSON.parse(text)
} catch {
return undefined
}
}
function extractModelId(payload: unknown): string | undefined {
if (!payload || typeof payload !== "object") return undefined
const rec = payload as Record<string, unknown>
const model = rec["model"]
return typeof model === "string" && model.trim().length > 0 ? model : undefined
}
type OpenAiToolCall = {
id: string
type: "function"
function: { name: string; arguments: string }
}
type OpenAiAssembledChoice = {
index: number
message: {
role: string
content: string
reasoning?: string
reasoning_details?: unknown
tool_calls?: OpenAiToolCall[]
}
finish_reason: string | null
}
type OpenAiAssembledResponse = {
id?: string
object: "chat.completion"
created?: number
model?: string
choices: OpenAiAssembledChoice[]
usage?: unknown
}
type ParsedSsePayload = {
model?: string
payload: unknown
}
type SseDebugInfo = {
format: "sse"
/** Total SSE blocks (event groups) in the raw stream */
blocks: number
/** Number of parsed blocks included in `events` (capped) */
loggedBlocks: number
/** Bounded raw SSE (comments/keepalives stripped) */
__rawSse: string | TruncatedStringSummary
/** Parsed events (best-effort; data may be JSON or a truncated string summary) */
events: Array<{ event?: string; data?: unknown }>
}
const DEFAULT_SSE_PREVIEW_CHARS = 1500
const DEFAULT_SSE_MAX_EVENTS = 50
type TruncatedStringSummary = {
truncated: true
length: number
head: string
tail: string
}
function summarizeLongString(
text: string,
maxChars: number = DEFAULT_SSE_PREVIEW_CHARS,
): string | TruncatedStringSummary {
if (text.length <= maxChars * 2) return text
return {
truncated: true,
length: text.length,
head: text.slice(0, maxChars),
tail: text.slice(-maxChars),
}
}
function isRecord(value: unknown): value is Record<string, unknown> {
return typeof value === "object" && value !== null
}
type AnthropicUsage = {
input_tokens?: number
output_tokens?: number
cache_creation_input_tokens?: number
cache_read_input_tokens?: number
}
type AnthropicContentBlock =
| { type: "text"; text: string; [key: string]: unknown }
| { type: "thinking"; thinking: string; [key: string]: unknown }
| { type: "tool_use"; id?: string; name?: string; input?: unknown; [key: string]: unknown }
| { type: string; [key: string]: unknown }
type AnthropicAssembledMessage = {
id?: string
type: "message"
role?: string
model?: string
content: AnthropicContentBlock[]
stop_reason?: string | null
stop_sequence?: string | null
usage?: AnthropicUsage
}
function parseAnthropicStreamingSse(text: string): AnthropicAssembledMessage | undefined {
// Assemble Anthropic Messages SSE into a final message object.
// Reference: https://docs.anthropic.com/en/api/messages-streaming
const blocks = text
.split(/\n\n+/g)
.map((b) => b.trim())
.filter(Boolean)
let message: AnthropicAssembledMessage | undefined
const contentByIndex = new Map<number, AnthropicContentBlock>()
const toolInputJsonByIndex = new Map<number, string[]>()
type AnthropicUnhandledDelta = {
sseBlockIndex: number
event?: string
delta: Record<string, unknown>
}
function pushUnhandledDelta(index: number, entry: AnthropicUnhandledDelta) {
const current = contentByIndex.get(index)
if (!current) return
const rec = current as Record<string, unknown>
const existing = rec["__unhandled_deltas"]
const next = Array.isArray(existing) ? (existing as unknown[]).slice(0, DEFAULT_SSE_MAX_EVENTS) : []
next.push(entry)
rec["__unhandled_deltas"] = next
}
let sseBlockIndex = 0
for (const block of blocks) {
let eventName: string | undefined
const dataParts: string[] = []
for (const line of block.split("\n")) {
const trimmed = line.trimEnd()
if (trimmed.startsWith(":")) continue
if (trimmed.startsWith("event:")) {
eventName = trimmed.slice("event:".length).trim() || undefined
continue
}
if (trimmed.startsWith("data:")) {
dataParts.push(trimmed.slice("data:".length).trim())
}
}
if (dataParts.length === 0) {
sseBlockIndex++
continue
}
const dataText = dataParts.join("\n")
if (dataText === "[DONE]") break
const parsed = tryParseJson(dataText)
if (!parsed || !isRecord(parsed)) {
sseBlockIndex++
continue
}
const typeFromData = typeof parsed["type"] === "string" ? (parsed["type"] as string) : undefined
const event = eventName ?? typeFromData
if (!event) {
sseBlockIndex++
continue
}
if (event === "message_start") {
const m = isRecord(parsed["message"]) ? (parsed["message"] as Record<string, unknown>) : undefined
if (!m) continue
// Preserve the raw message_start.message object as much as possible.
// We'll replace content with the assembled content blocks below.
message = {
...(m as Omit<AnthropicAssembledMessage, "content" | "type">),
type: "message",
content: [],
}
sseBlockIndex++
continue
}
if (!message) {
// Not an Anthropic message stream.
return undefined
}
if (event === "content_block_start") {
const index = typeof parsed["index"] === "number" ? (parsed["index"] as number) : 0
const cb = isRecord(parsed["content_block"])
? (parsed["content_block"] as Record<string, unknown>)
: undefined
if (!cb) continue
const cbType = typeof cb["type"] === "string" ? (cb["type"] as string) : "unknown"
const block: Record<string, unknown> = { ...cb, type: cbType }
if (cbType === "text") {
block["text"] = typeof cb["text"] === "string" ? (cb["text"] as string) : ""
}
if (cbType === "thinking") {
block["thinking"] = typeof cb["thinking"] === "string" ? (cb["thinking"] as string) : ""
}
if (cbType === "tool_use") {
toolInputJsonByIndex.set(index, [])
}
contentByIndex.set(index, block as AnthropicContentBlock)
sseBlockIndex++
continue
}
if (event === "content_block_delta") {
const index = typeof parsed["index"] === "number" ? (parsed["index"] as number) : 0
const delta = isRecord(parsed["delta"]) ? (parsed["delta"] as Record<string, unknown>) : undefined
if (!delta) continue
const deltaType = typeof delta["type"] === "string" ? (delta["type"] as string) : "unknown"
const current = contentByIndex.get(index)
if (!current) {
sseBlockIndex++
continue
}
const currentRec = current as Record<string, unknown>
if (current.type === "text" && deltaType === "text_delta" && typeof delta["text"] === "string") {
const prev = typeof currentRec["text"] === "string" ? (currentRec["text"] as string) : ""
currentRec["text"] = prev + (delta["text"] as string)
} else if (
current.type === "thinking" &&
deltaType === "thinking_delta" &&
typeof delta["thinking"] === "string"
) {
const prev = typeof currentRec["thinking"] === "string" ? (currentRec["thinking"] as string) : ""
currentRec["thinking"] = prev + (delta["thinking"] as string)
} else if (deltaType === "signature_delta" && typeof delta["signature"] === "string") {
// Interleaved thinking uses signature deltas that must be preserved alongside thinking blocks.
// Some streams initialize signature as "" in content_block_start and then send the real value via signature_delta.
const prev = typeof currentRec["signature"] === "string" ? (currentRec["signature"] as string) : ""
currentRec["signature"] = prev + (delta["signature"] as string)
} else if (
current.type === "tool_use" &&
deltaType === "input_json_delta" &&
(typeof delta["partial_json"] === "string" || typeof (delta as any)["partial_json"] === "string")
) {
const partial = (delta["partial_json"] ?? (delta as any)["partial_json"]) as string
const acc = toolInputJsonByIndex.get(index)
if (acc) acc.push(partial)
} else {
pushUnhandledDelta(index, {
sseBlockIndex,
event,
delta,
})
}
sseBlockIndex++
continue
}
if (event === "content_block_stop") {
const index = typeof parsed["index"] === "number" ? (parsed["index"] as number) : 0
const current = contentByIndex.get(index)
if (current?.type === "tool_use") {
const parts = toolInputJsonByIndex.get(index)
if (parts && parts.length > 0) {
const joined = parts.join("")
const parsedJson = tryParseJson(joined)
current.input = typeof parsedJson === "undefined" ? joined : parsedJson
}
}
sseBlockIndex++
continue
}
if (event === "message_delta") {
const delta = isRecord(parsed["delta"]) ? (parsed["delta"] as Record<string, unknown>) : undefined
if (delta) {
// Preserve all message-level delta fields (except content/type) so we don't drop
// new/unknown fields introduced by Anthropic.
for (const [k, v] of Object.entries(delta)) {
if (k === "content" || k === "type") continue
;(message as unknown as Record<string, unknown>)[k] = v
}
}
if (isRecord(parsed["usage"])) {
message.usage = { ...(message.usage ?? {}), ...(parsed["usage"] as AnthropicUsage) }
}
sseBlockIndex++
continue
}
if (event === "message_stop") {
break
}
sseBlockIndex++
}
if (!message) return undefined
// Finalize content array in index order.
message.content = Array.from(contentByIndex.entries())
.sort(([a], [b]) => a - b)
.map(([, block]) => block)
return message
}
function parseOpenAiStreamingSse(text: string): OpenAiAssembledResponse | undefined {
// Parse SSE text and attempt to assemble an OpenAI-style chat completion response.
// If the stream isn't OpenAI-like, return undefined and fall back to raw text logging.
const byChoiceIndex = new Map<
number,
{
role?: string
contentParts: string[]
reasoningParts: string[]
finishReason: string | null
toolCallsById: Map<string, { id: string; name?: string; argsParts: string[] }>
reasoningDetails: Map<
string,
{ type: string; index: number; text?: string; summary?: string; data?: string }
>
}
>()
let sawChoices = false
let id: string | undefined
let created: number | undefined
let model: string | undefined
let usage: unknown = undefined
const blocks = text.split(/\n\n+/g)
for (const block of blocks) {
if (!block.trim()) continue
const lines = block.split("\n")
const dataParts: string[] = []
for (const line of lines) {
const trimmed = line.trimEnd()
// Ignore SSE comment/keepalive lines like ": OPENROUTER PROCESSING".
if (trimmed.startsWith(":")) continue
if (trimmed.startsWith("data:")) {
dataParts.push(trimmed.slice("data:".length).trim())
}
}
if (dataParts.length === 0) continue
const data = dataParts.join("\n")
if (data === "[DONE]") break
const parsed = tryParseJson(data)
if (!parsed || !isRecord(parsed)) continue
const choices = parsed["choices"]
if (!Array.isArray(choices)) continue
sawChoices = true
if (typeof parsed["id"] === "string") id = parsed["id"] as string
if (typeof parsed["created"] === "number") created = parsed["created"] as number
if (typeof parsed["model"] === "string") model = parsed["model"] as string
if ("usage" in parsed) usage = parsed["usage"]
for (const choiceAny of choices) {
if (!isRecord(choiceAny)) continue
const index = typeof choiceAny["index"] === "number" ? (choiceAny["index"] as number) : 0
const finishReason =
choiceAny["finish_reason"] === null || typeof choiceAny["finish_reason"] === "string"
? (choiceAny["finish_reason"] as string | null)
: null
const delta = isRecord(choiceAny["delta"]) ? (choiceAny["delta"] as Record<string, unknown>) : undefined
if (!delta) continue
let state = byChoiceIndex.get(index)
if (!state) {
state = {
contentParts: [],
reasoningParts: [],
finishReason: null,
toolCallsById: new Map(),
reasoningDetails: new Map(),
}
byChoiceIndex.set(index, state)
}
if (!state.role && typeof delta["role"] === "string") state.role = delta["role"] as string
if (typeof delta["content"] === "string") {
state.contentParts.push(delta["content"] as string)
}
for (const key of ["reasoning", "reasoning_content"] as const) {
if (typeof delta[key] === "string") {
state.reasoningParts.push(delta[key] as string)
break
}
}
const toolCalls = delta["tool_calls"]
if (Array.isArray(toolCalls)) {
for (const tcAny of toolCalls) {
if (!isRecord(tcAny)) continue
const tcId = typeof tcAny["id"] === "string" ? (tcAny["id"] as string) : undefined
const tcIndex = typeof tcAny["index"] === "number" ? (tcAny["index"] as number) : undefined
const idKey = tcId ?? `index-${tcIndex ?? 0}`
const fn = isRecord(tcAny["function"]) ? (tcAny["function"] as Record<string, unknown>) : undefined
const name = typeof fn?.["name"] === "string" ? (fn?.["name"] as string) : undefined
const args = typeof fn?.["arguments"] === "string" ? (fn?.["arguments"] as string) : undefined
let existing = state.toolCallsById.get(idKey)
if (!existing) {
existing = { id: idKey, name, argsParts: [] }
state.toolCallsById.set(idKey, existing)
}
if (!existing.name && name) existing.name = name
if (args) existing.argsParts.push(args)
}
}
const reasoningDetailsAny = delta["reasoning_details"]
if (Array.isArray(reasoningDetailsAny)) {
for (const detailAny of reasoningDetailsAny) {
if (!isRecord(detailAny)) continue
const type = typeof detailAny["type"] === "string" ? (detailAny["type"] as string) : "unknown"
const rIndex = typeof detailAny["index"] === "number" ? (detailAny["index"] as number) : 0
const key = `${type}-${rIndex}`
const existing = state.reasoningDetails.get(key)
const textPart = typeof detailAny["text"] === "string" ? (detailAny["text"] as string) : undefined
const summaryPart =
typeof detailAny["summary"] === "string" ? (detailAny["summary"] as string) : undefined
const dataPart = typeof detailAny["data"] === "string" ? (detailAny["data"] as string) : undefined
if (existing) {
if (textPart) existing.text = (existing.text ?? "") + textPart
if (summaryPart) existing.summary = (existing.summary ?? "") + summaryPart
if (dataPart) existing.data = (existing.data ?? "") + dataPart
} else {
state.reasoningDetails.set(key, {
type,
index: rIndex,
...(textPart ? { text: textPart } : {}),
...(summaryPart ? { summary: summaryPart } : {}),
...(dataPart ? { data: dataPart } : {}),
})
}
}
}
if (finishReason !== null) state.finishReason = finishReason
}
}
if (!sawChoices) return undefined
const choicesOut: OpenAiAssembledChoice[] = Array.from(byChoiceIndex.entries())
.sort(([a], [b]) => a - b)
.map(([index, state]) => {
const toolCallsOut: OpenAiToolCall[] = Array.from(state.toolCallsById.values())
.filter((tc) => typeof tc.name === "string" && tc.name.length > 0)
.map((tc) => ({
id: tc.id,
type: "function",
function: { name: tc.name!, arguments: tc.argsParts.join("") },
}))
const reasoningDetailsOut =
state.reasoningDetails.size > 0
? Array.from(state.reasoningDetails.values()).sort((a, b) => a.index - b.index)
: undefined
return {
index,
message: {
role: state.role ?? "assistant",
content: state.contentParts.join(""),
...(state.reasoningParts.length > 0 ? { reasoning: state.reasoningParts.join("") } : {}),
...(reasoningDetailsOut ? { reasoning_details: reasoningDetailsOut } : {}),
...(toolCallsOut.length > 0 ? { tool_calls: toolCallsOut } : {}),
},
finish_reason: state.finishReason,
}
})
return {
id,
object: "chat.completion",
created,
model,
choices: choicesOut,
...(typeof usage === "undefined" ? {} : { usage }),
}
}
function parseSsePayload(text: string): ParsedSsePayload {
// Log SSE in a structured way so callers can see the *actual* wire format.
// We always include `events` + `__rawSse`, and optionally include an `assembled` object
// for convenience when we recognize a stream format.
const stripped = text
.split("\n")
.filter((line) => !line.trimStart().startsWith(":"))
.join("\n")
const blocks = stripped.split(/\n\n+/g)
const events: Array<{ event?: string; data?: unknown }> = []
let totalBlocks = 0
for (const block of blocks) {
if (!block.trim()) continue
totalBlocks++
if (events.length >= DEFAULT_SSE_MAX_EVENTS) continue
let eventName: string | undefined
const dataParts: string[] = []
for (const line of block.split("\n")) {
const trimmed = line.trimEnd()
if (trimmed.startsWith("event:")) {
eventName = trimmed.slice("event:".length).trim() || undefined
continue
}
if (trimmed.startsWith("data:")) {
dataParts.push(trimmed.slice("data:".length).trim())
}
}
if (dataParts.length === 0) continue
const dataText = dataParts.join("\n")
if (dataText === "[DONE]") break
const maybeJson = tryParseJson(dataText)
const dataPayload = typeof maybeJson === "undefined" ? summarizeLongString(dataText) : maybeJson
events.push({ ...(eventName ? { event: eventName } : {}), data: dataPayload })
}
const debug: SseDebugInfo = {
format: "sse",
blocks: totalBlocks,
loggedBlocks: events.length,
__rawSse: summarizeLongString(stripped),
events,
}
const openAi = parseOpenAiStreamingSse(text)
if (openAi) {
return {
model: openAi.model,
payload: {
...openAi,
__sse: debug,
},
}
}
const anthropic = parseAnthropicStreamingSse(text)
if (anthropic) {
return {
model: anthropic.model,
payload: {
...anthropic,
__sse: debug,
},
}
}
return { payload: debug }
}
async function readStreamToText(stream: ReadableStream<Uint8Array>, maxBytes: number): Promise<string> {
const reader = stream.getReader()
const decoder = new TextDecoder()
let bytesRead = 0
const parts: string[] = []
try {
while (true) {
const { done, value } = await reader.read()
if (done) break
if (!value || value.length === 0) continue
const remaining = maxBytes - bytesRead
if (remaining <= 0) break
const slice = value.length > remaining ? value.subarray(0, remaining) : value
bytesRead += slice.length
parts.push(decoder.decode(slice, { stream: true }))
if (bytesRead >= maxBytes) break
}
} finally {
reader.releaseLock()
}
parts.push(decoder.decode())
return parts.join("")
}
async function getRequestBodyForLogging(input: RequestInfo | URL, init: RequestInit | undefined, maxBytes: number) {
// Prefer init.body because that's the most common usage.
const body = init?.body
if (typeof body === "string") {
const maybeJson = tryParseJson(body)
return { payload: maybeJson ?? body, model: extractModelId(maybeJson) }
}
if (body instanceof URLSearchParams) {
return { payload: body.toString(), model: undefined }
}
// If fetch was called with a Request and no init, try to read its body.
if (!body && typeof Request !== "undefined" && input instanceof Request) {
try {
const cloned = input.clone()
if (cloned.body) {
const text = await readStreamToText(cloned.body as ReadableStream<Uint8Array>, maxBytes)
const maybeJson = tryParseJson(text)
return { payload: maybeJson ?? text, model: extractModelId(maybeJson) }
}
} catch {
// Ignore body read errors.
}
}
if (body) {
return {
payload: `[Unlogged body type=${Object.prototype.toString.call(body)}]`,
model: undefined,
}
}
return { payload: undefined, model: undefined }
}
async function logNonStreamingResponse(
response: Response,
provider: string,
model: string,
durationMs: number,
maxBytes: number,
): Promise<void> {
try {
const clone = response.clone()
const contentType = clone.headers.get("content-type") ?? ""
let payload: unknown = undefined
if (clone.body) {
const text = await readStreamToText(clone.body as ReadableStream<Uint8Array>, maxBytes)
if (contentType.includes("application/json") || contentType.includes("+json")) {
payload = tryParseJson(text) ?? text
} else {
payload = text
}
}
ApiInferenceLogger.logRaw(`[API][response][${provider}][${model}][${durationMs}ms]`, payload)
} catch (error) {
ApiInferenceLogger.logRawError(`[API][error][${provider}][${model}][${durationMs}ms]`, error)
}
}
async function logSseResponse(
stream: ReadableStream<Uint8Array>,
provider: string,
fallbackModel: string,
startedAt: number,
maxBytes: number,
): Promise<void> {
try {
const text = await readStreamToText(stream, maxBytes)
const { payload, model: modelFromStream } = parseSsePayload(text)
const durationMs = Date.now() - startedAt
const model = modelFromStream ?? fallbackModel
ApiInferenceLogger.logRaw(`[API][response][${provider}][${model}][${durationMs}ms][streaming]`, payload)
} catch (error) {
const durationMs = Date.now() - startedAt
ApiInferenceLogger.logRawError(`[API][error][${provider}][${fallbackModel}][${durationMs}ms]`, error)
}
}
export function createLoggingFetch(options: LoggingFetchOptions, baseFetch: typeof fetch = fetch): typeof fetch {
return async (input: RequestInfo | URL, init?: RequestInit): Promise<Response> => {
// Fast path: no overhead when disabled.
if (!ApiInferenceLogger.isEnabled()) {
return baseFetch(input, init)
}
const maxBytes = getMaxBodySizeBytes(options.maxBodySizeBytes)
const startedAt = Date.now()
const { payload: requestPayload, model: requestModel } = await getRequestBodyForLogging(input, init, maxBytes)
const model = requestModel ?? "unknown"
ApiInferenceLogger.logRaw(`[API][request][${options.provider}][${model}]`, requestPayload)
try {
const response = await baseFetch(input, init)
const durationMs = Date.now() - startedAt
const contentType = response.headers.get("content-type") ?? ""
const isSse = contentType.includes("text/event-stream")
if (!isSse) {
await logNonStreamingResponse(response, options.provider, model, durationMs, maxBytes)
return response
}
if (!response.body) {
ApiInferenceLogger.logRaw(
`[API][response][${options.provider}][${model}][${durationMs}ms][streaming]`,
undefined,
)
return response
}
// Tee the stream so the consumer can read one branch while we buffer the other.
const [consumerStream, logStream] = response.body.tee()
const responseForConsumer = new Response(consumerStream, {
status: response.status,
statusText: response.statusText,
headers: response.headers,
})
void logSseResponse(logStream, options.provider, model, startedAt, maxBytes)
return responseForConsumer
} catch (error) {
const durationMs = Date.now() - startedAt
ApiInferenceLogger.logRawError(`[API][error][${options.provider}][${model}][${durationMs}ms]`, error)
throw error
}
}
}

View file

@ -0,0 +1,77 @@
// npx vitest run api/providers/__tests__/anthropic-vertex-logging.spec.ts
import type { ApiHandlerOptions } from "../../../shared/api"
import { ApiInferenceLogger } from "../../logging/ApiInferenceLogger"
const mockMessagesCreate = vitest.fn()
vitest.mock("@anthropic-ai/vertex-sdk", () => {
return {
AnthropicVertex: vitest.fn().mockImplementation(() => ({
messages: {
create: mockMessagesCreate,
},
})),
}
})
describe("AnthropicVertexHandler API logging", () => {
beforeEach(() => {
vitest.clearAllMocks()
vitest.spyOn(ApiInferenceLogger, "isEnabled").mockReturnValue(true)
vitest.spyOn(ApiInferenceLogger, "logRaw").mockImplementation(() => {})
vitest.spyOn(ApiInferenceLogger, "logRawError").mockImplementation(() => {})
})
it("logs request + streaming response", async () => {
mockMessagesCreate.mockResolvedValueOnce({
async *[Symbol.asyncIterator]() {
yield {
type: "message_start",
message: {
usage: { input_tokens: 10, output_tokens: 5 },
},
}
yield {
type: "content_block_start",
index: 0,
content_block: { type: "text", text: "Hello" },
}
yield {
type: "content_block_delta",
index: 0,
delta: { type: "text_delta", text: " world" },
}
},
})
const { AnthropicVertexHandler } = await import("../anthropic-vertex")
const options: ApiHandlerOptions = {
apiModelId: "claude-3-5-sonnet-v2@20241022",
vertexProjectId: "test-project",
vertexRegion: "us-central1",
}
const handler = new AnthropicVertexHandler(options)
for await (const _ of handler.createMessage("system", [{ role: "user", content: "hi" }])) {
// drain
}
expect(ApiInferenceLogger.logRaw).toHaveBeenCalledWith(
expect.stringMatching(/^\[API\]\[request\]\[Anthropic Vertex\]\[.+\]$/),
expect.objectContaining({
model: expect.any(String),
stream: true,
}),
)
expect(ApiInferenceLogger.logRaw).toHaveBeenCalledWith(
expect.stringMatching(/^\[API\]\[response\]\[Anthropic Vertex\]\[.+\]\[\d+ms\]\[streaming\]$/),
expect.objectContaining({
type: "message",
model: expect.any(String),
content: expect.any(Array),
}),
)
})
})

View file

@ -0,0 +1,121 @@
// npx vitest run api/providers/__tests__/bedrock-logging.spec.ts
import { AwsBedrockHandler } from "../bedrock"
import type { ApiHandlerOptions } from "../../../shared/api"
import { ApiInferenceLogger } from "../../logging/ApiInferenceLogger"
const mockSend = vitest.fn()
vitest.mock("@aws-sdk/client-bedrock-runtime", () => {
return {
BedrockRuntimeClient: vitest.fn().mockImplementation(() => ({
send: mockSend,
config: { region: "us-east-1" },
middlewareStack: {
clone: () => ({ resolve: () => {} }),
use: () => {},
},
})),
ConverseStreamCommand: vitest.fn((params) => ({
...params,
input: params,
middlewareStack: {
clone: () => ({ resolve: () => {} }),
use: () => {},
},
})),
ConverseCommand: vitest.fn((params) => ({
...params,
input: params,
middlewareStack: {
clone: () => ({ resolve: () => {} }),
use: () => {},
},
})),
}
})
vitest.mock("@aws-sdk/credential-providers", () => ({
fromIni: vitest.fn().mockReturnValue({
accessKeyId: "profile-access-key",
secretAccessKey: "profile-secret-key",
}),
}))
vitest.mock("@smithy/smithy-client", () => ({
throwDefaultError: vitest.fn(),
}))
describe("AwsBedrockHandler API logging", () => {
beforeEach(() => {
vitest.clearAllMocks()
vitest.spyOn(ApiInferenceLogger, "isEnabled").mockReturnValue(true)
vitest.spyOn(ApiInferenceLogger, "logRaw").mockImplementation(() => {})
vitest.spyOn(ApiInferenceLogger, "logRawError").mockImplementation(() => {})
})
it("logs request + streaming response", async () => {
mockSend.mockResolvedValueOnce({
stream: {
[Symbol.asyncIterator]: async function* () {
yield {
contentBlockStart: {
start: { text: "Hello" },
contentBlockIndex: 0,
},
}
yield {
contentBlockDelta: {
delta: { text: " world" },
contentBlockIndex: 0,
},
}
yield {
metadata: {
usage: {
inputTokens: 10,
outputTokens: 2,
},
},
}
},
},
})
const options: ApiHandlerOptions = {
apiModelId: "anthropic.claude-3-5-sonnet-20241022-v2:0",
awsAccessKey: "test-access-key",
awsSecretKey: "test-secret-key",
awsRegion: "us-east-1",
}
const handler = new AwsBedrockHandler(options)
const stream = handler.createMessage("system", [{ role: "user", content: "hi" }])
for await (const _ of stream) {
// consume
}
expect(ApiInferenceLogger.logRaw).toHaveBeenCalledWith(
expect.stringMatching(/^\[API\]\[request\]\[Bedrock\]\[anthropic\.claude-3-5-sonnet-20241022-v2:0\]$/),
expect.objectContaining({
modelId: "anthropic.claude-3-5-sonnet-20241022-v2:0",
messages: expect.any(Array),
}),
)
expect(ApiInferenceLogger.logRaw).toHaveBeenCalledWith(
expect.stringMatching(
/^\[API\]\[response\]\[Bedrock\]\[anthropic\.claude-3-5-sonnet-20241022-v2:0\]\[\d+ms\]\[streaming\]$/,
),
expect.objectContaining({
model: "anthropic.claude-3-5-sonnet-20241022-v2:0",
message: expect.objectContaining({
role: "assistant",
content: "Hello world",
}),
usage: expect.objectContaining({ inputTokens: 10, outputTokens: 2 }),
__stream: expect.objectContaining({ format: "bedrock" }),
}),
)
})
})

View file

@ -2,8 +2,13 @@ import { t } from "i18next"
import { GeminiHandler } from "../gemini"
import type { ApiHandlerOptions } from "../../../shared/api"
import { ApiInferenceLogger } from "../../logging/ApiInferenceLogger"
describe("GeminiHandler backend support", () => {
afterEach(() => {
ApiInferenceLogger.configure({ enabled: false, sink: () => {} })
})
it("passes tools for URL context and grounding in config", async () => {
const options = {
apiProvider: "gemini",
@ -19,6 +24,46 @@ describe("GeminiHandler backend support", () => {
expect(config.tools).toEqual([{ urlContext: {} }, { googleSearch: {} }])
})
it("logs request/response via ApiInferenceLogger when enabled", async () => {
const sink = vi.fn()
ApiInferenceLogger.configure({ enabled: true, sink })
const options = {
apiProvider: "gemini",
apiModelId: "gemini-1.5-flash", // just needs to exist for getModel
} as ApiHandlerOptions
const handler = new GeminiHandler(options)
const mockStream = (async function* () {
yield {
candidates: [{ content: { parts: [{ text: "hi" }] }, finishReason: "STOP" }],
usageMetadata: { promptTokenCount: 1, candidatesTokenCount: 2 },
responseId: "r_1",
}
})()
// @ts-ignore access private client
handler["client"].models.generateContentStream = vi.fn().mockResolvedValue(mockStream)
// Drain
for await (const _ of handler.createMessage("sys", [] as any)) {
// noop
}
expect(sink).toHaveBeenCalledWith(
expect.stringMatching(/^\[API\]\[request\]\[Gemini\]\[.+\]$/),
expect.objectContaining({
model: expect.any(String),
contents: expect.any(Array),
config: expect.any(Object),
}),
)
expect(sink).toHaveBeenCalledWith(
expect.stringMatching(/^\[API\]\[response\]\[Gemini\]\[.+\]\[\d+ms\]\[streaming\]$/),
expect.objectContaining({ candidates: expect.any(Array) }),
)
})
it("completePrompt passes config overrides without tools when URL context and grounding disabled", async () => {
const options = {
apiProvider: "gemini",

View file

@ -0,0 +1,78 @@
// npx vitest run api/providers/__tests__/native-ollama-logging.spec.ts
import { NativeOllamaHandler } from "../native-ollama"
import type { ApiHandlerOptions } from "../../../shared/api"
import { ApiInferenceLogger } from "../../logging/ApiInferenceLogger"
import { getOllamaModels } from "../fetchers/ollama"
const mockChat = vitest.fn()
vitest.mock("ollama", () => {
return {
Ollama: vitest.fn().mockImplementation(() => ({
chat: mockChat,
})),
Message: vitest.fn(),
}
})
vitest.mock("../fetchers/ollama", () => ({
getOllamaModels: vitest.fn(),
}))
describe("NativeOllamaHandler API logging", () => {
beforeEach(() => {
vitest.clearAllMocks()
vitest.spyOn(ApiInferenceLogger, "isEnabled").mockReturnValue(true)
vitest.spyOn(ApiInferenceLogger, "logRaw").mockImplementation(() => {})
vitest.spyOn(ApiInferenceLogger, "logRawError").mockImplementation(() => {})
vitest.mocked(getOllamaModels).mockResolvedValue({
llama2: {
contextWindow: 4096,
maxTokens: 4096,
supportsImages: false,
supportsPromptCache: false,
},
})
})
it("logs request + streaming response", async () => {
mockChat.mockImplementation(async function* () {
yield { message: { content: "Hello" } }
yield { message: { content: " world" }, eval_count: 2, prompt_eval_count: 10 }
})
const options: ApiHandlerOptions = {
apiModelId: "llama2",
ollamaModelId: "llama2",
ollamaBaseUrl: "http://localhost:11434",
}
const handler = new NativeOllamaHandler(options)
const stream = handler.createMessage("system", [{ role: "user", content: "hi" }])
for await (const _ of stream) {
// consume
}
expect(ApiInferenceLogger.logRaw).toHaveBeenCalledWith(
expect.stringMatching(/^\[API\]\[request\]\[Ollama\]\[llama2\]$/),
expect.objectContaining({
model: "llama2",
stream: true,
messages: expect.any(Array),
}),
)
expect(ApiInferenceLogger.logRaw).toHaveBeenCalledWith(
expect.stringMatching(/^\[API\]\[response\]\[Ollama\]\[llama2\]\[\d+ms\]\[streaming\]$/),
expect.objectContaining({
model: "llama2",
message: expect.objectContaining({
role: "assistant",
content: "Hello world",
}),
usage: expect.objectContaining({ inputTokens: 10, outputTokens: 2 }),
}),
)
})
})

View file

@ -8,6 +8,10 @@ vi.mock("node:fs", () => ({
},
}))
vi.mock("../../../utils/safeWriteJson", () => ({
safeWriteJson: vi.fn().mockResolvedValue(undefined),
}))
const mockCreate = vi.fn()
vi.mock("openai", () => {
return {
@ -28,6 +32,7 @@ import { promises as fs } from "node:fs"
import { QwenCodeHandler } from "../qwen-code"
import { NativeToolCallParser } from "../../../core/assistant-message/NativeToolCallParser"
import type { ApiHandlerOptions } from "../../../shared/api"
import { safeWriteJson } from "../../../utils/safeWriteJson"
describe("QwenCodeHandler Native Tools", () => {
let handler: QwenCodeHandler
@ -52,6 +57,7 @@ describe("QwenCodeHandler Native Tools", () => {
beforeEach(() => {
vi.clearAllMocks()
vi.mocked(safeWriteJson).mockResolvedValue(undefined)
// Mock credentials file
const mockCredentials = {

View file

@ -58,6 +58,7 @@ import * as vscode from "vscode"
import { VsCodeLmHandler } from "../vscode-lm"
import type { ApiHandlerOptions } from "../../../shared/api"
import type { Anthropic } from "@anthropic-ai/sdk"
import { ApiInferenceLogger } from "../../logging/ApiInferenceLogger"
const mockLanguageModelChat = {
id: "test-model",
@ -141,6 +142,48 @@ describe("VsCodeLmHandler", () => {
handler["client"] = mockLanguageModelChat
})
it("should log request/response when ApiInferenceLogger is enabled", async () => {
const sink = vi.fn()
ApiInferenceLogger.configure({ enabled: true, sink })
const systemPrompt = "You are a helpful assistant"
const messages: Anthropic.Messages.MessageParam[] = [
{
role: "user" as const,
content: "Hello",
},
]
const responseText = "Hello!"
mockLanguageModelChat.sendRequest.mockResolvedValueOnce({
stream: (async function* () {
yield new vscode.LanguageModelTextPart(responseText)
return
})(),
text: (async function* () {
yield responseText
return
})(),
})
for await (const _ of handler.createMessage(systemPrompt, messages)) {
// drain
}
expect(sink).toHaveBeenCalledWith(
expect.stringMatching(/^\[API\]\[request\]\[VS Code LM\]\[.+\]$/),
expect.objectContaining({
model: expect.any(String),
system: systemPrompt,
messages: expect.any(Array),
}),
)
expect(sink).toHaveBeenCalledWith(
expect.stringMatching(/^\[API\]\[response\]\[VS Code LM\]\[.+\]\[\d+ms\]\[streaming\]$/),
expect.objectContaining({ text: expect.any(String), usage: expect.any(Object) }),
)
})
it("should stream text responses", async () => {
const systemPrompt = "You are a helpful assistant"
const messages: Anthropic.Messages.MessageParam[] = [

View file

@ -25,6 +25,8 @@ import {
convertOpenAIToolChoiceToAnthropic,
} from "../../core/prompts/tools/native-tools/converters"
import { ApiInferenceLogger } from "../logging/ApiInferenceLogger"
import { BaseProvider } from "./base-provider"
import type { SingleCompletionHandler, ApiHandlerCreateMessageMetadata } from "../index"
@ -71,6 +73,9 @@ export class AnthropicVertexHandler extends BaseProvider implements SingleComple
messages: Anthropic.Messages.MessageParam[],
metadata?: ApiHandlerCreateMessageMetadata,
): ApiStream {
const startedAt = Date.now()
const shouldLog = ApiInferenceLogger.isEnabled()
let { id, info, temperature, maxTokens, reasoning: thinking, betas } = this.getModel()
const { supportsPromptCache } = info
@ -95,6 +100,44 @@ export class AnthropicVertexHandler extends BaseProvider implements SingleComple
}
: {}
const textParts: string[] = []
const reasoningParts: string[] = []
const toolCallsByIndex = new Map<
number,
{
index: number
id?: string
name?: string
argsParts: string[]
}
>()
let usageSnapshot:
| {
inputTokens: number
outputTokens: number
cacheWriteTokens?: number
cacheReadTokens?: number
}
| undefined
function tryParseJsonString(input: string): unknown {
try {
return JSON.parse(input)
} catch {
return input
}
}
function getOrCreateToolCall(index: number) {
let current = toolCallsByIndex.get(index)
if (!current) {
current = { index, argsParts: [] }
toolCallsByIndex.set(index, current)
}
return current
}
/**
* Vertex API has specific limitations for prompt caching:
* 1. Maximum of 4 blocks can have cache_control
@ -125,98 +168,183 @@ export class AnthropicVertexHandler extends BaseProvider implements SingleComple
// and prompt caching
const requestOptions = betas?.length ? { headers: { "anthropic-beta": betas.join(",") } } : undefined
const stream = await this.client.messages.create(params, requestOptions)
if (shouldLog) {
ApiInferenceLogger.logRaw(`[API][request][${this.providerName}][${id}]`, {
...params,
...(requestOptions ? { __requestOptions: requestOptions } : {}),
})
}
for await (const chunk of stream) {
switch (chunk.type) {
case "message_start": {
const usage = chunk.message!.usage
let stream: Awaited<ReturnType<typeof this.client.messages.create>>
try {
stream = await this.client.messages.create(params, requestOptions)
} catch (error) {
if (shouldLog) {
const durationMs = Date.now() - startedAt
ApiInferenceLogger.logRawError(`[API][error][${this.providerName}][${id}][${durationMs}ms]`, error)
}
throw error
}
yield {
type: "usage",
inputTokens: usage.input_tokens || 0,
outputTokens: usage.output_tokens || 0,
cacheWriteTokens: usage.cache_creation_input_tokens || undefined,
cacheReadTokens: usage.cache_read_input_tokens || undefined,
try {
for await (const chunk of stream) {
switch (chunk.type) {
case "message_start": {
const usage = chunk.message!.usage
usageSnapshot = {
inputTokens: usage.input_tokens || 0,
outputTokens: usage.output_tokens || 0,
cacheWriteTokens: usage.cache_creation_input_tokens || undefined,
cacheReadTokens: usage.cache_read_input_tokens || undefined,
}
yield {
type: "usage",
inputTokens: usageSnapshot.inputTokens,
outputTokens: usageSnapshot.outputTokens,
cacheWriteTokens: usageSnapshot.cacheWriteTokens,
cacheReadTokens: usageSnapshot.cacheReadTokens,
}
break
}
case "message_delta": {
const outputTokens = chunk.usage!.output_tokens || 0
if (usageSnapshot) usageSnapshot.outputTokens = outputTokens
yield {
type: "usage",
inputTokens: 0,
outputTokens,
}
break
}
case "message_delta": {
yield {
type: "usage",
inputTokens: 0,
outputTokens: chunk.usage!.output_tokens || 0,
break
}
case "content_block_start": {
switch (chunk.content_block!.type) {
case "text": {
if (chunk.index! > 0) {
textParts.push("\n")
yield { type: "text", text: "\n" }
}
break
}
case "content_block_start": {
switch (chunk.content_block!.type) {
case "text": {
if (chunk.index! > 0) {
yield { type: "text", text: "\n" }
textParts.push(chunk.content_block!.text)
yield { type: "text", text: chunk.content_block!.text }
break
}
case "thinking": {
if (chunk.index! > 0) {
reasoningParts.push("\n")
yield { type: "reasoning", text: "\n" }
}
yield { type: "text", text: chunk.content_block!.text }
break
}
case "thinking": {
if (chunk.index! > 0) {
yield { type: "reasoning", text: "\n" }
const thinkingText = (chunk.content_block as any).thinking as string
reasoningParts.push(thinkingText)
yield { type: "reasoning", text: thinkingText }
break
}
case "tool_use": {
const tc = getOrCreateToolCall(chunk.index ?? 0)
tc.id = chunk.content_block!.id
tc.name = chunk.content_block!.name
yield { type: "reasoning", text: (chunk.content_block as any).thinking }
break
}
case "tool_use": {
// Emit initial tool call partial with id and name
yield {
type: "tool_call_partial",
index: chunk.index,
id: chunk.content_block!.id,
name: chunk.content_block!.name,
arguments: undefined,
// Emit initial tool call partial with id and name
yield {
type: "tool_call_partial",
index: chunk.index,
id: chunk.content_block!.id,
name: chunk.content_block!.name,
arguments: undefined,
}
break
}
break
}
break
}
break
}
case "content_block_delta": {
switch (chunk.delta!.type) {
case "text_delta": {
yield { type: "text", text: chunk.delta!.text }
break
}
case "thinking_delta": {
yield { type: "reasoning", text: (chunk.delta as any).thinking }
break
}
case "input_json_delta": {
// Emit tool call partial chunks as arguments stream in
yield {
type: "tool_call_partial",
index: chunk.index,
id: undefined,
name: undefined,
arguments: (chunk.delta as any).partial_json,
case "content_block_delta": {
switch (chunk.delta!.type) {
case "text_delta": {
textParts.push(chunk.delta!.text)
yield { type: "text", text: chunk.delta!.text }
break
}
case "thinking_delta": {
const thinkingText = (chunk.delta as any).thinking as string
reasoningParts.push(thinkingText)
yield { type: "reasoning", text: thinkingText }
break
}
case "input_json_delta": {
const partial = (chunk.delta as any).partial_json as string
const tc = getOrCreateToolCall(chunk.index ?? 0)
if (typeof partial === "string" && partial.length > 0) tc.argsParts.push(partial)
// Emit tool call partial chunks as arguments stream in
yield {
type: "tool_call_partial",
index: chunk.index,
id: undefined,
name: undefined,
arguments: partial,
}
break
}
break
}
}
break
}
case "content_block_stop": {
// Block complete - no action needed for now.
// NativeToolCallParser handles tool call completion
// Note: Signature for multi-turn thinking would require using stream.finalMessage()
// after iteration completes, which requires restructuring the streaming approach.
break
break
}
case "content_block_stop": {
// Block complete - no action needed for now.
// NativeToolCallParser handles tool call completion
// Note: Signature for multi-turn thinking would require using stream.finalMessage()
// after iteration completes, which requires restructuring the streaming approach.
break
}
}
}
} catch (error) {
if (shouldLog) {
const durationMs = Date.now() - startedAt
ApiInferenceLogger.logRawError(`[API][error][${this.providerName}][${id}][${durationMs}ms]`, error)
}
throw error
} finally {
if (shouldLog) {
const durationMs = Date.now() - startedAt
const toolUseBlocks = Array.from(toolCallsByIndex.values())
.sort((a, b) => a.index - b.index)
.map((tc) => {
const joined = tc.argsParts.join("")
return {
type: "tool_use" as const,
...(tc.id ? { id: tc.id } : {}),
...(tc.name ? { name: tc.name } : {}),
...(joined.length > 0 ? { input: tryParseJsonString(joined) } : {}),
}
})
ApiInferenceLogger.logRaw(`[API][response][${this.providerName}][${id}][${durationMs}ms][streaming]`, {
type: "message",
role: "assistant",
model: id,
content: [
...(textParts.length > 0 ? ([{ type: "text", text: textParts.join("") }] as const) : []),
...(reasoningParts.length > 0
? ([{ type: "thinking", thinking: reasoningParts.join("") }] as const)
: []),
...toolUseBlocks,
],
...(usageSnapshot
? {
usage: {
input_tokens: usageSnapshot.inputTokens,
output_tokens: usageSnapshot.outputTokens,
cache_creation_input_tokens: usageSnapshot.cacheWriteTokens,
cache_read_input_tokens: usageSnapshot.cacheReadTokens,
},
}
: {}),
})
}
}
}
@ -270,6 +398,7 @@ export class AnthropicVertexHandler extends BaseProvider implements SingleComple
async completePrompt(prompt: string) {
try {
const startedAt = Date.now()
let {
id,
info: { supportsPromptCache },
@ -294,7 +423,15 @@ export class AnthropicVertexHandler extends BaseProvider implements SingleComple
stream: false,
}
if (ApiInferenceLogger.isEnabled()) {
ApiInferenceLogger.logRaw(`[API][request][${this.providerName}][${id}]`, params)
}
const response = await this.client.messages.create(params)
if (ApiInferenceLogger.isEnabled()) {
const durationMs = Date.now() - startedAt
ApiInferenceLogger.logRaw(`[API][response][${this.providerName}][${id}][${durationMs}ms]`, response)
}
const content = response.content[0]
if (content.type === "text") {
@ -303,6 +440,10 @@ export class AnthropicVertexHandler extends BaseProvider implements SingleComple
return ""
} catch (error) {
const modelId = this.options.apiModelId ?? vertexDefaultModelId
if (ApiInferenceLogger.isEnabled()) {
ApiInferenceLogger.logRawError(`[API][error][${this.providerName}][${modelId}][0ms]`, error)
}
if (error instanceof Error) {
throw new Error(`Vertex completion error: ${error.message}`)
}

View file

@ -29,6 +29,8 @@ import {
convertOpenAIToolsToAnthropic,
convertOpenAIToolChoiceToAnthropic,
} from "../../core/prompts/tools/native-tools/converters"
import { ApiInferenceLogger } from "../logging/ApiInferenceLogger"
import { createLoggingFetch } from "../logging/logging-fetch"
export class AnthropicHandler extends BaseProvider implements SingleCompletionHandler {
private options: ApiHandlerOptions
@ -45,6 +47,7 @@ export class AnthropicHandler extends BaseProvider implements SingleCompletionHa
this.client = new Anthropic({
baseURL: this.options.anthropicBaseUrl || undefined,
[apiKeyFieldName]: this.options.apiKey,
fetch: ApiInferenceLogger.isEnabled() ? createLoggingFetch({ provider: this.providerName }) : undefined,
})
}
@ -98,291 +101,252 @@ export class AnthropicHandler extends BaseProvider implements SingleCompletionHa
}
: {}
// Variable to hold the log handle - will be created after request body is built
let logHandle: ReturnType<typeof this.inferenceLogger.start> | undefined
try {
switch (modelId) {
case "claude-sonnet-4-5":
case "claude-sonnet-4-20250514":
case "claude-opus-4-5-20251101":
case "claude-opus-4-1-20250805":
case "claude-opus-4-20250514":
case "claude-3-7-sonnet-20250219":
case "claude-3-5-sonnet-20241022":
case "claude-3-5-haiku-20241022":
case "claude-3-opus-20240229":
case "claude-haiku-4-5-20251001":
case "claude-3-haiku-20240307": {
/**
* The latest message will be the new user message, one before
* will be the assistant message from a previous request, and
* the user message before that will be a previously cached user
* message. So we need to mark the latest user message as
* ephemeral to cache it for the next request, and mark the
* second to last user message as ephemeral to let the server
* know the last message to retrieve from the cache for the
* current request.
*/
const userMsgIndices = sanitizedMessages.reduce(
(acc, msg, index) => (msg.role === "user" ? [...acc, index] : acc),
[] as number[],
)
const lastUserMsgIndex = userMsgIndices[userMsgIndices.length - 1] ?? -1
const secondLastMsgUserIndex = userMsgIndices[userMsgIndices.length - 2] ?? -1
// Build the request body for logging and API call
const requestBody = {
model: modelId,
max_tokens: maxTokens ?? ANTHROPIC_DEFAULT_MAX_TOKENS,
temperature,
thinking,
// Setting cache breakpoint for system prompt so new tasks can reuse it.
system: [{ text: systemPrompt, type: "text" as const, cache_control: cacheControl }],
messages: sanitizedMessages.map((message, index) => {
if (index === lastUserMsgIndex || index === secondLastMsgUserIndex) {
return {
...message,
content:
typeof message.content === "string"
? [
{
type: "text" as const,
text: message.content,
cache_control: cacheControl,
},
]
: message.content.map((content, contentIndex) =>
contentIndex === message.content.length - 1
? { ...content, cache_control: cacheControl }
: content,
),
}
}
return message
}),
stream: true as const,
...nativeToolParams,
}
// Start inference logging with actual request body
logHandle = this.inferenceLogger.start(
{
provider: this.providerName,
operation: "createMessage",
model: modelId,
},
requestBody,
)
try {
// Determine request options (beta headers)
betas.push("prompt-caching-2024-07-31")
const requestOptions = { headers: { "anthropic-beta": betas.join(",") } }
stream = await this.client.messages.create(requestBody, requestOptions)
} catch (error) {
TelemetryService.instance.captureException(
new ApiProviderError(
error instanceof Error ? error.message : String(error),
this.providerName,
modelId,
"createMessage",
),
)
throw error
}
break
}
default: {
// Build the request body for logging and API call
const requestBody = {
model: modelId,
max_tokens: maxTokens ?? ANTHROPIC_DEFAULT_MAX_TOKENS,
temperature,
system: [{ text: systemPrompt, type: "text" as const }],
messages: sanitizedMessages,
stream: true as const,
...nativeToolParams,
}
// Start inference logging with actual request body
logHandle = this.inferenceLogger.start(
{
provider: this.providerName,
operation: "createMessage",
model: modelId,
},
requestBody,
)
try {
stream = (await this.client.messages.create(requestBody)) as any
} catch (error) {
TelemetryService.instance.captureException(
new ApiProviderError(
error instanceof Error ? error.message : String(error),
this.providerName,
modelId,
"createMessage",
),
)
throw error
}
break
}
}
let inputTokens = 0
let outputTokens = 0
let cacheWriteTokens = 0
let cacheReadTokens = 0
for await (const chunk of stream) {
switch (chunk.type) {
case "message_start": {
// Tells us cache reads/writes/input/output.
const {
input_tokens = 0,
output_tokens = 0,
cache_creation_input_tokens,
cache_read_input_tokens,
} = chunk.message.usage
yield {
type: "usage",
inputTokens: input_tokens,
outputTokens: output_tokens,
cacheWriteTokens: cache_creation_input_tokens || undefined,
cacheReadTokens: cache_read_input_tokens || undefined,
}
inputTokens += input_tokens
outputTokens += output_tokens
cacheWriteTokens += cache_creation_input_tokens || 0
cacheReadTokens += cache_read_input_tokens || 0
break
}
case "message_delta":
// Tells us stop_reason, stop_sequence, and output tokens
// along the way and at the end of the message.
yield {
type: "usage",
inputTokens: 0,
outputTokens: chunk.usage.output_tokens || 0,
}
break
case "message_stop":
// No usage data, just an indicator that the message is done.
break
case "content_block_start":
switch (chunk.content_block.type) {
case "thinking":
// We may receive multiple text blocks, in which
// case just insert a line break between them.
if (chunk.index > 0) {
accumulatedReasoning.push("\n")
yield { type: "reasoning", text: "\n" }
}
accumulatedReasoning.push(chunk.content_block.thinking)
yield { type: "reasoning", text: chunk.content_block.thinking }
break
case "text":
// We may receive multiple text blocks, in which
// case just insert a line break between them.
if (chunk.index > 0) {
accumulatedText.push("\n")
yield { type: "text", text: "\n" }
}
accumulatedText.push(chunk.content_block.text)
yield { type: "text", text: chunk.content_block.text }
break
case "tool_use": {
// Track tool call for logging
toolCalls.push({
id: chunk.content_block.id,
name: chunk.content_block.name,
})
// Emit initial tool call partial with id and name
yield {
type: "tool_call_partial",
index: chunk.index,
id: chunk.content_block.id,
name: chunk.content_block.name,
arguments: undefined,
}
break
}
}
break
case "content_block_delta":
switch (chunk.delta.type) {
case "thinking_delta":
accumulatedReasoning.push(chunk.delta.thinking)
yield { type: "reasoning", text: chunk.delta.thinking }
break
case "text_delta":
accumulatedText.push(chunk.delta.text)
yield { type: "text", text: chunk.delta.text }
break
case "input_json_delta": {
// Emit tool call partial chunks as arguments stream in
yield {
type: "tool_call_partial",
index: chunk.index,
id: undefined,
name: undefined,
arguments: chunk.delta.partial_json,
}
break
}
}
break
case "content_block_stop":
// Block complete - no action needed for now.
// NativeToolCallParser handles tool call completion
// Note: Signature for multi-turn thinking would require using stream.finalMessage()
// after iteration completes, which requires restructuring the streaming approach.
break
}
}
if (inputTokens > 0 || outputTokens > 0 || cacheWriteTokens > 0 || cacheReadTokens > 0) {
const { totalCost } = calculateApiCostAnthropic(
this.getModel().info,
inputTokens,
outputTokens,
cacheWriteTokens,
cacheReadTokens,
switch (modelId) {
case "claude-sonnet-4-5":
case "claude-sonnet-4-20250514":
case "claude-opus-4-5-20251101":
case "claude-opus-4-1-20250805":
case "claude-opus-4-20250514":
case "claude-3-7-sonnet-20250219":
case "claude-3-5-sonnet-20241022":
case "claude-3-5-haiku-20241022":
case "claude-3-opus-20240229":
case "claude-haiku-4-5-20251001":
case "claude-3-haiku-20240307": {
/**
* The latest message will be the new user message, one before
* will be the assistant message from a previous request, and
* the user message before that will be a previously cached user
* message. So we need to mark the latest user message as
* ephemeral to cache it for the next request, and mark the
* second to last user message as ephemeral to let the server
* know the last message to retrieve from the cache for the
* current request.
*/
const userMsgIndices = sanitizedMessages.reduce(
(acc, msg, index) => (msg.role === "user" ? [...acc, index] : acc),
[] as number[],
)
yield {
type: "usage",
inputTokens: 0,
outputTokens: 0,
totalCost,
}
}
const lastUserMsgIndex = userMsgIndices[userMsgIndices.length - 1] ?? -1
const secondLastMsgUserIndex = userMsgIndices[userMsgIndices.length - 2] ?? -1
// Log successful response
logHandle.success({
text: accumulatedText.join(""),
reasoning: accumulatedReasoning.length > 0 ? accumulatedReasoning.join("") : undefined,
toolCalls: toolCalls.length > 0 ? toolCalls : undefined,
usage: { inputTokens, outputTokens, cacheWriteTokens, cacheReadTokens },
})
} catch (error) {
// logHandle may not be assigned if error occurs before request body is built
if (logHandle) {
logHandle.error(error)
// Build the request body for logging and API call
const requestBody = {
model: modelId,
max_tokens: maxTokens ?? ANTHROPIC_DEFAULT_MAX_TOKENS,
temperature,
thinking,
// Setting cache breakpoint for system prompt so new tasks can reuse it.
system: [{ text: systemPrompt, type: "text" as const, cache_control: cacheControl }],
messages: sanitizedMessages.map((message, index) => {
if (index === lastUserMsgIndex || index === secondLastMsgUserIndex) {
return {
...message,
content:
typeof message.content === "string"
? [
{
type: "text" as const,
text: message.content,
cache_control: cacheControl,
},
]
: message.content.map((content, contentIndex) =>
contentIndex === message.content.length - 1
? { ...content, cache_control: cacheControl }
: content,
),
}
}
return message
}),
stream: true as const,
...nativeToolParams,
}
try {
// Determine request options (beta headers)
betas.push("prompt-caching-2024-07-31")
const requestOptions = { headers: { "anthropic-beta": betas.join(",") } }
stream = await this.client.messages.create(requestBody, requestOptions)
} catch (error) {
TelemetryService.instance.captureException(
new ApiProviderError(
error instanceof Error ? error.message : String(error),
this.providerName,
modelId,
"createMessage",
),
)
throw error
}
break
}
default: {
// Build the request body for logging and API call
const requestBody = {
model: modelId,
max_tokens: maxTokens ?? ANTHROPIC_DEFAULT_MAX_TOKENS,
temperature,
system: [{ text: systemPrompt, type: "text" as const }],
messages: sanitizedMessages,
stream: true as const,
...nativeToolParams,
}
try {
stream = (await this.client.messages.create(requestBody)) as any
} catch (error) {
TelemetryService.instance.captureException(
new ApiProviderError(
error instanceof Error ? error.message : String(error),
this.providerName,
modelId,
"createMessage",
),
)
throw error
}
break
}
}
let inputTokens = 0
let outputTokens = 0
let cacheWriteTokens = 0
let cacheReadTokens = 0
for await (const chunk of stream) {
switch (chunk.type) {
case "message_start": {
// Tells us cache reads/writes/input/output.
const {
input_tokens = 0,
output_tokens = 0,
cache_creation_input_tokens,
cache_read_input_tokens,
} = chunk.message.usage
yield {
type: "usage",
inputTokens: input_tokens,
outputTokens: output_tokens,
cacheWriteTokens: cache_creation_input_tokens || undefined,
cacheReadTokens: cache_read_input_tokens || undefined,
}
inputTokens += input_tokens
outputTokens += output_tokens
cacheWriteTokens += cache_creation_input_tokens || 0
cacheReadTokens += cache_read_input_tokens || 0
break
}
case "message_delta":
// Tells us stop_reason, stop_sequence, and output tokens
// along the way and at the end of the message.
yield {
type: "usage",
inputTokens: 0,
outputTokens: chunk.usage.output_tokens || 0,
}
break
case "message_stop":
// No usage data, just an indicator that the message is done.
break
case "content_block_start":
switch (chunk.content_block.type) {
case "thinking":
// We may receive multiple text blocks, in which
// case just insert a line break between them.
if (chunk.index > 0) {
accumulatedReasoning.push("\n")
yield { type: "reasoning", text: "\n" }
}
accumulatedReasoning.push(chunk.content_block.thinking)
yield { type: "reasoning", text: chunk.content_block.thinking }
break
case "text":
// We may receive multiple text blocks, in which
// case just insert a line break between them.
if (chunk.index > 0) {
accumulatedText.push("\n")
yield { type: "text", text: "\n" }
}
accumulatedText.push(chunk.content_block.text)
yield { type: "text", text: chunk.content_block.text }
break
case "tool_use": {
// Track tool call for logging
toolCalls.push({
id: chunk.content_block.id,
name: chunk.content_block.name,
})
// Emit initial tool call partial with id and name
yield {
type: "tool_call_partial",
index: chunk.index,
id: chunk.content_block.id,
name: chunk.content_block.name,
arguments: undefined,
}
break
}
}
break
case "content_block_delta":
switch (chunk.delta.type) {
case "thinking_delta":
accumulatedReasoning.push(chunk.delta.thinking)
yield { type: "reasoning", text: chunk.delta.thinking }
break
case "text_delta":
accumulatedText.push(chunk.delta.text)
yield { type: "text", text: chunk.delta.text }
break
case "input_json_delta": {
// Emit tool call partial chunks as arguments stream in
yield {
type: "tool_call_partial",
index: chunk.index,
id: undefined,
name: undefined,
arguments: chunk.delta.partial_json,
}
break
}
}
break
case "content_block_stop":
// Block complete - no action needed for now.
// NativeToolCallParser handles tool call completion
// Note: Signature for multi-turn thinking would require using stream.finalMessage()
// after iteration completes, which requires restructuring the streaming approach.
break
}
}
if (inputTokens > 0 || outputTokens > 0 || cacheWriteTokens > 0 || cacheReadTokens > 0) {
const { totalCost } = calculateApiCostAnthropic(
this.getModel().info,
inputTokens,
outputTokens,
cacheWriteTokens,
cacheReadTokens,
)
yield {
type: "usage",
inputTokens: 0,
outputTokens: 0,
totalCost,
}
throw error
}
}

View file

@ -14,6 +14,8 @@ import { BaseProvider } from "./base-provider"
import { handleOpenAIError } from "./utils/openai-error-handler"
import { calculateApiCostOpenAI } from "../../shared/cost"
import { getApiRequestTimeout } from "./utils/timeout-config"
import { ApiInferenceLogger } from "../logging/ApiInferenceLogger"
import { createLoggingFetch } from "../logging/logging-fetch"
type BaseOpenAiCompatibleProviderOptions<ModelName extends string> = ApiHandlerOptions & {
providerName: string
@ -64,6 +66,7 @@ export abstract class BaseOpenAiCompatibleProvider<ModelName extends string>
apiKey: this.options.apiKey,
defaultHeaders: DEFAULT_HEADERS,
timeout: getApiRequestTimeout(),
fetch: ApiInferenceLogger.isEnabled() ? createLoggingFetch({ provider: this.providerName }) : undefined,
})
}
@ -149,135 +152,89 @@ export abstract class BaseOpenAiCompatibleProvider<ModelName extends string>
;(requestParams as any).thinking = { type: "enabled" }
}
// Start inference logging with the actual request params
const logHandle = this.inferenceLogger.start(
{
provider: this.providerName,
operation: "createMessage",
model,
},
requestParams,
)
// Accumulators for final response logging
const accumulatedText: string[] = []
const accumulatedReasoning: string[] = []
const toolCalls: Array<{ id?: string; name?: string; arguments?: string }> = []
let lastUsage: OpenAI.CompletionUsage | undefined
const activeToolCallIds = new Set<string>()
try {
const stream = await this.createStream(systemPrompt, messages, metadata)
const stream = await this.createStream(systemPrompt, messages, metadata)
const matcher = new XmlMatcher(
"think",
(chunk) =>
({
type: chunk.matched ? "reasoning" : "text",
text: chunk.data,
}) as const,
)
const matcher = new XmlMatcher(
"think",
(chunk) =>
({
type: chunk.matched ? "reasoning" : "text",
text: chunk.data,
}) as const,
)
for await (const chunk of stream) {
// Check for provider-specific error responses (e.g., MiniMax base_resp)
const chunkAny = chunk as any
if (chunkAny.base_resp?.status_code && chunkAny.base_resp.status_code !== 0) {
const error = new Error(
`${this.providerName} API Error (${chunkAny.base_resp.status_code}): ${chunkAny.base_resp.status_msg || "Unknown error"}`,
)
logHandle.error(error)
throw error
}
for await (const chunk of stream) {
// Check for provider-specific error responses (e.g., MiniMax base_resp)
const chunkAny = chunk as any
if (chunkAny.base_resp?.status_code && chunkAny.base_resp.status_code !== 0) {
const error = new Error(
`${this.providerName} API Error (${chunkAny.base_resp.status_code}): ${chunkAny.base_resp.status_msg || "Unknown error"}`,
)
throw error
}
const delta = chunk.choices?.[0]?.delta
const finishReason = chunk.choices?.[0]?.finish_reason
const delta = chunk.choices?.[0]?.delta
const finishReason = chunk.choices?.[0]?.finish_reason
if (delta?.content) {
for (const processedChunk of matcher.update(delta.content)) {
if (processedChunk.type === "text") {
accumulatedText.push(processedChunk.text)
} else if (processedChunk.type === "reasoning") {
accumulatedReasoning.push(processedChunk.text)
}
yield processedChunk
}
}
if (delta) {
for (const key of ["reasoning_content", "reasoning"] as const) {
if (key in delta) {
const reasoning_content = ((delta as any)[key] as string | undefined) || ""
if (reasoning_content?.trim()) {
accumulatedReasoning.push(reasoning_content)
yield { type: "reasoning", text: reasoning_content }
}
break
}
}
}
// Emit raw tool call chunks - NativeToolCallParser handles state management
if (delta?.tool_calls) {
for (const toolCall of delta.tool_calls) {
// Track tool calls for logging
if (toolCall.id) {
activeToolCallIds.add(toolCall.id)
}
if (toolCall.id || toolCall.function?.name) {
toolCalls.push({
id: toolCall.id,
name: toolCall.function?.name,
arguments: toolCall.function?.arguments,
})
}
yield {
type: "tool_call_partial",
index: toolCall.index,
id: toolCall.id,
name: toolCall.function?.name,
arguments: toolCall.function?.arguments,
}
}
}
// Emit tool_call_end events when finish_reason is "tool_calls"
// This ensures tool calls are finalized even if the stream doesn't properly close
if (finishReason === "tool_calls" && activeToolCallIds.size > 0) {
for (const id of activeToolCallIds) {
yield { type: "tool_call_end", id }
}
activeToolCallIds.clear()
}
if (chunk.usage) {
lastUsage = chunk.usage
if (delta?.content) {
for (const processedChunk of matcher.update(delta.content)) {
yield processedChunk
}
}
if (lastUsage) {
yield this.processUsageMetrics(lastUsage, this.getModel().info)
}
// Process any remaining content
for (const processedChunk of matcher.final()) {
if (processedChunk.type === "text") {
accumulatedText.push(processedChunk.text)
} else if (processedChunk.type === "reasoning") {
accumulatedReasoning.push(processedChunk.text)
if (delta) {
for (const key of ["reasoning_content", "reasoning"] as const) {
if (key in delta) {
const reasoning_content = ((delta as any)[key] as string | undefined) || ""
if (reasoning_content?.trim()) {
yield { type: "reasoning", text: reasoning_content }
}
break
}
}
yield processedChunk
}
// Log successful response
logHandle.success({
text: accumulatedText.join(""),
reasoning: accumulatedReasoning.length > 0 ? accumulatedReasoning.join("") : undefined,
toolCalls: toolCalls.length > 0 ? toolCalls : undefined,
usage: lastUsage,
})
} catch (error) {
logHandle.error(error)
throw error
// Emit raw tool call chunks - NativeToolCallParser handles state management
if (delta?.tool_calls) {
for (const toolCall of delta.tool_calls) {
// Track tool call IDs for finishReason handling
if (toolCall.id) {
activeToolCallIds.add(toolCall.id)
}
yield {
type: "tool_call_partial",
index: toolCall.index,
id: toolCall.id,
name: toolCall.function?.name,
arguments: toolCall.function?.arguments,
}
}
}
// Emit tool_call_end events when finish_reason is "tool_calls"
// This ensures tool calls are finalized even if the stream doesn't properly close
if (finishReason === "tool_calls" && activeToolCallIds.size > 0) {
for (const id of activeToolCallIds) {
yield { type: "tool_call_end", id }
}
activeToolCallIds.clear()
}
if (chunk.usage) {
lastUsage = chunk.usage
}
}
if (lastUsage) {
yield this.processUsageMetrics(lastUsage, this.getModel().info)
}
// Process any remaining content
for (const processedChunk of matcher.final()) {
yield processedChunk
}
}

View file

@ -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 { ApiInferenceLogger } from "../logging/ApiInferenceLogger"
/************************************************************************************
*
@ -356,6 +357,9 @@ export class AwsBedrockHandler extends BaseProvider implements SingleCompletionH
}
},
): ApiStream {
const startedAt = Date.now()
const shouldLog = ApiInferenceLogger.isEnabled()
const modelConfig = this.getModel()
const usePromptCache = Boolean(this.options.awsUsePromptCache && this.supportsAwsPromptCache(modelConfig))
@ -483,6 +487,55 @@ export class AwsBedrockHandler extends BaseProvider implements SingleCompletionH
...(useServiceTier && { service_tier: this.options.awsBedrockServiceTier }),
}
if (shouldLog) {
ApiInferenceLogger.logRaw(`[API][request][${this.providerName}][${modelConfig.id}]`, payload)
}
const textParts: string[] = []
const reasoningParts: string[] = []
const toolCallsByIndex = new Map<
number,
{
index: number
id?: string
name?: string
argsParts: string[]
}
>()
let lastUsage:
| {
inputTokens: number
outputTokens: number
cacheReadTokens: number
cacheWriteTokens: number
}
| undefined
const debugEvents: StreamEvent[] = []
let totalDebugEvents = 0
const MAX_DEBUG_EVENTS = 50
function appendToolCallPartial(entry: { index: number; id?: string; name?: string; arguments?: string }) {
let current = toolCallsByIndex.get(entry.index)
if (!current) {
current = { index: entry.index, argsParts: [] }
toolCallsByIndex.set(entry.index, current)
}
if (!current.id && entry.id) current.id = entry.id
if (!current.name && entry.name) current.name = entry.name
if (typeof entry.arguments === "string" && entry.arguments.length > 0)
current.argsParts.push(entry.arguments)
}
function tryParseJsonString(input: string): unknown {
try {
return JSON.parse(input)
} catch {
return input
}
}
// Create AbortController with 10 minute timeout
const controller = new AbortController()
let timeoutId: NodeJS.Timeout | undefined
@ -519,6 +572,11 @@ export class AwsBedrockHandler extends BaseProvider implements SingleCompletionH
continue
}
totalDebugEvents++
if (shouldLog && debugEvents.length < MAX_DEBUG_EVENTS) {
debugEvents.push(streamEvent)
}
// Handle metadata events first
if (streamEvent.metadata?.usage) {
const usage = (streamEvent.metadata?.usage || {}) as UsageType
@ -528,6 +586,13 @@ export class AwsBedrockHandler extends BaseProvider implements SingleCompletionH
const cacheWriteTokens = usage.cacheWriteInputTokens || usage.cacheWriteInputTokenCount || 0
// Always include all available token information
lastUsage = {
inputTokens: usage.inputTokens || 0,
outputTokens: usage.outputTokens || 0,
cacheReadTokens: cacheReadTokens,
cacheWriteTokens: cacheWriteTokens,
}
yield {
type: "usage",
inputTokens: usage.inputTokens || 0,
@ -592,8 +657,10 @@ export class AwsBedrockHandler extends BaseProvider implements SingleCompletionH
// Check if this is a reasoning block (AWS SDK structure)
if (cbStart.contentBlock?.reasoningContent) {
if (cbStart.contentBlockIndex && cbStart.contentBlockIndex > 0) {
reasoningParts.push("\n")
yield { type: "reasoning", text: "\n" }
}
reasoningParts.push(cbStart.contentBlock.reasoningContent.text || "")
yield {
type: "reasoning",
text: cbStart.contentBlock.reasoningContent.text || "",
@ -605,9 +672,11 @@ export class AwsBedrockHandler extends BaseProvider implements SingleCompletionH
else if (cbStart.contentBlock?.type === "thinking" || cbStart.content_block?.type === "thinking") {
const contentBlock = cbStart.contentBlock || cbStart.content_block
if (cbStart.contentBlockIndex && cbStart.contentBlockIndex > 0) {
reasoningParts.push("\n")
yield { type: "reasoning", text: "\n" }
}
if (contentBlock?.thinking) {
reasoningParts.push(contentBlock.thinking)
yield {
type: "reasoning",
text: contentBlock.thinking,
@ -618,6 +687,12 @@ export class AwsBedrockHandler extends BaseProvider implements SingleCompletionH
else if (cbStart.start?.toolUse || cbStart.contentBlock?.toolUse) {
const toolUse = cbStart.start?.toolUse || cbStart.contentBlock?.toolUse
if (toolUse) {
appendToolCallPartial({
index: cbStart.contentBlockIndex ?? 0,
id: toolUse.toolUseId,
name: toolUse.name,
arguments: undefined,
})
yield {
type: "tool_call_partial",
index: cbStart.contentBlockIndex ?? 0,
@ -627,6 +702,7 @@ export class AwsBedrockHandler extends BaseProvider implements SingleCompletionH
}
}
} else if (cbStart.start?.text) {
textParts.push(cbStart.start.text)
yield {
type: "text",
text: cbStart.start.text,
@ -649,6 +725,7 @@ export class AwsBedrockHandler extends BaseProvider implements SingleCompletionH
if (delta) {
// Check for reasoningContent property (AWS SDK structure)
if (delta.reasoningContent?.text) {
reasoningParts.push(delta.reasoningContent.text)
yield {
type: "reasoning",
text: delta.reasoningContent.text,
@ -658,6 +735,12 @@ export class AwsBedrockHandler extends BaseProvider implements SingleCompletionH
// Handle tool use input delta
if (delta.toolUse?.input) {
appendToolCallPartial({
index: cbDelta.contentBlockIndex ?? 0,
id: undefined,
name: undefined,
arguments: delta.toolUse.input,
})
yield {
type: "tool_call_partial",
index: cbDelta.contentBlockIndex ?? 0,
@ -670,11 +753,13 @@ export class AwsBedrockHandler extends BaseProvider implements SingleCompletionH
// Handle alternative thinking structure (fallback for older SDK versions)
if (delta.type === "thinking_delta" && delta.thinking) {
reasoningParts.push(delta.thinking)
yield {
type: "reasoning",
text: delta.thinking,
}
} else if (delta.text) {
textParts.push(delta.text)
yield {
type: "text",
text: delta.text,
@ -688,12 +773,51 @@ export class AwsBedrockHandler extends BaseProvider implements SingleCompletionH
continue
}
}
if (shouldLog) {
const durationMs = Date.now() - startedAt
const toolCalls = Array.from(toolCallsByIndex.values())
.sort((a, b) => a.index - b.index)
.map((tc) => ({
index: tc.index,
...(tc.id ? { id: tc.id } : {}),
...(tc.name ? { name: tc.name } : {}),
...(tc.argsParts.length > 0 ? { arguments: tryParseJsonString(tc.argsParts.join("")) } : {}),
}))
ApiInferenceLogger.logRaw(
`[API][response][${this.providerName}][${modelConfig.id}][${durationMs}ms][streaming]`,
{
model: modelConfig.id,
message: {
role: "assistant",
content: textParts.join(""),
...(reasoningParts.length > 0 ? { reasoning: reasoningParts.join("") } : {}),
...(toolCalls.length > 0 ? { tool_calls: toolCalls } : {}),
},
...(lastUsage ? { usage: lastUsage } : {}),
__stream: {
format: "bedrock",
totalEvents: totalDebugEvents,
events: debugEvents,
},
},
)
}
// Clear timeout after stream completes
clearTimeout(timeoutId)
} catch (error: unknown) {
// Clear timeout on error
clearTimeout(timeoutId)
if (shouldLog) {
const durationMs = Date.now() - startedAt
ApiInferenceLogger.logRawError(
`[API][error][${this.providerName}][${modelConfig.id}][${durationMs}ms]`,
error,
)
}
// Capture error in telemetry before processing
const errorMessage = error instanceof Error ? error.message : String(error)
const apiError = new ApiProviderError(errorMessage, this.providerName, modelConfig.id, "createMessage")
@ -748,6 +872,7 @@ export class AwsBedrockHandler extends BaseProvider implements SingleCompletionH
async completePrompt(prompt: string): Promise<string> {
try {
const startedAt = Date.now()
const modelConfig = this.getModel()
// For completePrompt, thinking is typically not used, but we should still check
@ -782,9 +907,21 @@ export class AwsBedrockHandler extends BaseProvider implements SingleCompletionH
inferenceConfig,
}
if (ApiInferenceLogger.isEnabled()) {
ApiInferenceLogger.logRaw(`[API][request][${this.providerName}][${modelConfig.id}]`, payload)
}
const command = new ConverseCommand(payload)
const response = await this.client.send(command)
if (ApiInferenceLogger.isEnabled()) {
const durationMs = Date.now() - startedAt
ApiInferenceLogger.logRaw(
`[API][response][${this.providerName}][${modelConfig.id}][${durationMs}ms]`,
response,
)
}
if (
response?.output?.message?.content &&
response.output.message.content.length > 0 &&
@ -808,6 +945,10 @@ export class AwsBedrockHandler extends BaseProvider implements SingleCompletionH
const apiError = new ApiProviderError(telemetryErrorMessage, this.providerName, model.id, "completePrompt")
TelemetryService.instance.captureException(apiError)
if (ApiInferenceLogger.isEnabled()) {
ApiInferenceLogger.logRawError(`[API][error][${this.providerName}][${model.id}][0ms]`, error)
}
// 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

View file

@ -12,6 +12,8 @@ import type { ApiHandlerCreateMessageMetadata, SingleCompletionHandler } from ".
import { BaseProvider } from "./base-provider"
import { DEFAULT_HEADERS } from "./constants"
import { t } from "../../i18n"
import { ApiInferenceLogger } from "../logging/ApiInferenceLogger"
import { createLoggingFetch } from "../logging/logging-fetch"
const CEREBRAS_BASE_URL = "https://api.cerebras.ai/v1"
const CEREBRAS_DEFAULT_TEMPERATURE = 0
@ -129,7 +131,9 @@ export class CerebrasHandler extends BaseProvider implements SingleCompletionHan
}
try {
const response = await fetch(`${CEREBRAS_BASE_URL}/chat/completions`, {
const fetchFn = ApiInferenceLogger.isEnabled() ? createLoggingFetch({ provider: this.providerName }) : fetch
const response = await fetchFn(`${CEREBRAS_BASE_URL}/chat/completions`, {
method: "POST",
headers: {
...DEFAULT_HEADERS,
@ -291,7 +295,9 @@ export class CerebrasHandler extends BaseProvider implements SingleCompletionHan
}
try {
const response = await fetch(`${CEREBRAS_BASE_URL}/chat/completions`, {
const fetchFn = ApiInferenceLogger.isEnabled() ? createLoggingFetch({ provider: this.providerName }) : fetch
const response = await fetchFn(`${CEREBRAS_BASE_URL}/chat/completions`, {
method: "POST",
headers: {
...DEFAULT_HEADERS,

View file

@ -199,120 +199,84 @@ export class ClaudeCodeHandler extends BaseProvider implements ApiHandler, Singl
},
}
// Start inference logging with request params
const logHandle = this.inferenceLogger.start(
{
provider: this.providerName,
operation: "createMessage",
model: modelId,
},
requestParams,
)
// HTTP-level request/response logging is handled by logging-fetch injected into
// the Claude Code streaming client.
const stream = createStreamingMessage({
accessToken,
...requestParams,
})
// Accumulators for response logging
const accumulatedText: string[] = []
const accumulatedReasoning: string[] = []
const toolCalls: Array<{ id?: string; name?: string }> = []
// Track usage for cost calculation
let inputTokens = 0
let outputTokens = 0
let cacheReadTokens = 0
let cacheWriteTokens = 0
try {
// Create streaming request using OAuth
const stream = createStreamingMessage({
accessToken,
...requestParams,
})
for await (const chunk of stream) {
switch (chunk.type) {
case "text":
yield {
type: "text",
text: chunk.text,
}
break
// Track usage for cost calculation
let inputTokens = 0
let outputTokens = 0
let cacheReadTokens = 0
let cacheWriteTokens = 0
let lastUsage: any
case "reasoning":
yield {
type: "reasoning",
text: chunk.text,
}
break
for await (const chunk of stream) {
switch (chunk.type) {
case "text":
accumulatedText.push(chunk.text)
yield {
type: "text",
text: chunk.text,
}
break
case "thinking_complete":
// Capture the signature for persistence in api_conversation_history
// This enables tool use continuations where thinking blocks must be passed back
if (chunk.signature) {
this.lastThinkingSignature = chunk.signature
}
// Emit a complete thinking block with signature
// This is critical for interleaved thinking with tool use
// The signature must be included when passing thinking blocks back to the API
yield {
type: "reasoning",
text: chunk.thinking,
signature: chunk.signature,
}
break
case "reasoning":
accumulatedReasoning.push(chunk.text)
yield {
type: "reasoning",
text: chunk.text,
}
break
case "tool_call_partial":
yield {
type: "tool_call_partial",
index: chunk.index,
id: chunk.id,
name: chunk.name,
arguments: chunk.arguments,
}
break
case "thinking_complete":
// Capture the signature for persistence in api_conversation_history
// This enables tool use continuations where thinking blocks must be passed back
if (chunk.signature) {
this.lastThinkingSignature = chunk.signature
}
accumulatedReasoning.push(chunk.thinking)
// Emit a complete thinking block with signature
// This is critical for interleaved thinking with tool use
// The signature must be included when passing thinking blocks back to the API
yield {
type: "reasoning",
text: chunk.thinking,
signature: chunk.signature,
}
break
case "usage": {
inputTokens = chunk.inputTokens
outputTokens = chunk.outputTokens
cacheReadTokens = chunk.cacheReadTokens || 0
cacheWriteTokens = chunk.cacheWriteTokens || 0
case "tool_call_partial":
if (chunk.id || chunk.name) {
toolCalls.push({ id: chunk.id, name: chunk.name })
}
yield {
type: "tool_call_partial",
index: chunk.index,
id: chunk.id,
name: chunk.name,
arguments: chunk.arguments,
}
break
case "usage": {
inputTokens = chunk.inputTokens
outputTokens = chunk.outputTokens
cacheReadTokens = chunk.cacheReadTokens || 0
cacheWriteTokens = chunk.cacheWriteTokens || 0
// Claude Code is subscription-based, no per-token cost
const usageChunk: ApiStreamUsageChunk = {
type: "usage",
inputTokens,
outputTokens,
cacheReadTokens: cacheReadTokens > 0 ? cacheReadTokens : undefined,
cacheWriteTokens: cacheWriteTokens > 0 ? cacheWriteTokens : undefined,
totalCost: 0,
}
lastUsage = usageChunk
yield usageChunk
break
// Claude Code is subscription-based, no per-token cost
const usageChunk: ApiStreamUsageChunk = {
type: "usage",
inputTokens,
outputTokens,
cacheReadTokens: cacheReadTokens > 0 ? cacheReadTokens : undefined,
cacheWriteTokens: cacheWriteTokens > 0 ? cacheWriteTokens : undefined,
totalCost: 0,
}
case "error":
throw new Error(chunk.error)
yield usageChunk
break
}
}
// Log successful response
logHandle.success({
text: accumulatedText.join(""),
reasoning: accumulatedReasoning.length > 0 ? accumulatedReasoning.join("") : undefined,
toolCalls: toolCalls.length > 0 ? toolCalls : undefined,
usage: lastUsage,
})
} catch (error) {
logHandle.error(error)
throw error
case "error":
throw new Error(chunk.error)
}
}
}

View file

@ -5,6 +5,8 @@ import { parseApiPrice } from "../../../shared/cost"
import { DEFAULT_HEADERS } from "../constants"
import { resolveVersionedSettings, type VersionedSettings } from "./versionedSettings"
import { ApiInferenceLogger } from "../../logging/ApiInferenceLogger"
import { createLoggingFetch } from "../../logging/logging-fetch"
/**
* Fetches available models from the Roo Code Cloud provider
@ -35,7 +37,8 @@ export async function getRooModels(baseUrl: string, apiKey?: string): Promise<Mo
const timeoutId = setTimeout(() => controller.abort(), 10000)
try {
const response = await fetch(url, {
const fetchFn = ApiInferenceLogger.isEnabled() ? createLoggingFetch({ provider: "Roo Code Cloud" }) : fetch
const response = await fetchFn(url, {
headers,
signal: controller.signal,
})

View file

@ -27,6 +27,8 @@ import type { ApiStream, GroundingSource } from "../transform/stream"
import { getModelParams } from "../transform/model-params"
import { handleProviderError } from "./utils/error-handler"
import { ApiInferenceLogger } from "../logging/ApiInferenceLogger"
import type { SingleCompletionHandler, ApiHandlerCreateMessageMetadata } from "../index"
import { BaseProvider } from "./base-provider"
@ -77,6 +79,9 @@ export class GeminiHandler extends BaseProvider implements SingleCompletionHandl
messages: Anthropic.Messages.MessageParam[],
metadata?: ApiHandlerCreateMessageMetadata,
): ApiStream {
const startedAt = Date.now()
const loggingEnabled = ApiInferenceLogger.isEnabled()
const { id: model, info, reasoning: thinkingConfig, maxTokens } = this.getModel()
// Reset per-request metadata that we persist into apiConversationHistory.
this.lastThoughtSignature = undefined
@ -201,10 +206,21 @@ export class GeminiHandler extends BaseProvider implements SingleCompletionHandl
}
const params: GenerateContentParameters = { model, contents, config }
if (loggingEnabled) {
ApiInferenceLogger.logRaw(`[API][request][${this.providerName}][${model}]`, params)
}
try {
const result = await this.client.models.generateContentStream(params)
// Accumulators for a coherent final response log.
const assembledParts: Array<{
thought?: boolean
text?: string
thoughtSignature?: string
functionCall?: { name: string; args: Record<string, unknown> }
}> = []
let lastUsageMetadata: GenerateContentResponseUsageMetadata | undefined
let pendingGroundingMetadata: GroundingMetadata | undefined
let finalResponse: { responseId?: string } | undefined
@ -235,6 +251,17 @@ export class GeminiHandler extends BaseProvider implements SingleCompletionHandl
thoughtSignature?: string
functionCall?: { name: string; args: Record<string, unknown> }
}>) {
if (loggingEnabled) {
assembledParts.push({
...(typeof part.thought === "boolean" ? { thought: part.thought } : {}),
...(typeof part.text === "string" ? { text: part.text } : {}),
...(typeof part.thoughtSignature === "string"
? { thoughtSignature: part.thoughtSignature }
: {}),
...(part.functionCall ? { functionCall: part.functionCall } : {}),
})
}
// Capture thought signatures so they can be persisted into API history.
const thoughtSignature = part.thoughtSignature
// Persist encrypted reasoning when using reasoning. Both effort-based
@ -331,7 +358,31 @@ export class GeminiHandler extends BaseProvider implements SingleCompletionHandl
}),
}
}
if (loggingEnabled) {
const durationMs = Date.now() - startedAt
ApiInferenceLogger.logRaw(
`[API][response][${this.providerName}][${model}][${durationMs}ms][streaming]`,
{
responseId: this.lastResponseId,
model,
candidates: [
{
finishReason,
content: { parts: assembledParts },
...(pendingGroundingMetadata ? { groundingMetadata: pendingGroundingMetadata } : {}),
},
],
...(lastUsageMetadata ? { usageMetadata: lastUsageMetadata } : {}),
},
)
}
} catch (error) {
if (loggingEnabled) {
const durationMs = Date.now() - startedAt
ApiInferenceLogger.logRawError(`[API][error][${this.providerName}][${model}][${durationMs}ms]`, error)
}
const errorMessage = error instanceof Error ? error.message : String(error)
const apiError = new ApiProviderError(errorMessage, this.providerName, model, "createMessage")
TelemetryService.instance.captureException(apiError)
@ -400,6 +451,8 @@ export class GeminiHandler extends BaseProvider implements SingleCompletionHandl
async completePrompt(prompt: string): Promise<string> {
const { id: model, info } = this.getModel()
const startedAt = Date.now()
const loggingEnabled = ApiInferenceLogger.isEnabled()
try {
const tools: GenerateContentConfig["tools"] = []
@ -428,8 +481,15 @@ export class GeminiHandler extends BaseProvider implements SingleCompletionHandl
contents: [{ role: "user", parts: [{ text: prompt }] }],
config: promptConfig,
}
if (loggingEnabled) {
ApiInferenceLogger.logRaw(`[API][request][${this.providerName}][${model}]`, request)
}
const result = await this.client.models.generateContent(request)
if (loggingEnabled) {
const durationMs = Date.now() - startedAt
ApiInferenceLogger.logRaw(`[API][response][${this.providerName}][${model}][${durationMs}ms]`, result)
}
let text = result.text ?? ""
@ -443,6 +503,11 @@ export class GeminiHandler extends BaseProvider implements SingleCompletionHandl
return text
} catch (error) {
if (loggingEnabled) {
const durationMs = Date.now() - startedAt
ApiInferenceLogger.logRawError(`[API][error][${this.providerName}][${model}][${durationMs}ms]`, error)
}
const errorMessage = error instanceof Error ? error.message : String(error)
const apiError = new ApiProviderError(errorMessage, this.providerName, model, "completePrompt")
TelemetryService.instance.captureException(apiError)

View file

@ -9,6 +9,8 @@ import { DEFAULT_HEADERS } from "./constants"
import { BaseProvider } from "./base-provider"
import { getHuggingFaceModels, getCachedHuggingFaceModels } from "./fetchers/huggingface"
import { handleOpenAIError } from "./utils/openai-error-handler"
import { ApiInferenceLogger } from "../logging/ApiInferenceLogger"
import { createLoggingFetch } from "../logging/logging-fetch"
export class HuggingFaceHandler extends BaseProvider implements SingleCompletionHandler {
private client: OpenAI
@ -28,6 +30,7 @@ export class HuggingFaceHandler extends BaseProvider implements SingleCompletion
baseURL: "https://router.huggingface.co/v1",
apiKey: this.options.huggingFaceApiKey,
defaultHeaders: DEFAULT_HEADERS,
fetch: ApiInferenceLogger.isEnabled() ? createLoggingFetch({ provider: this.providerName }) : undefined,
})
// Try to get cached models first

View file

@ -17,6 +17,8 @@ import type { SingleCompletionHandler, ApiHandlerCreateMessageMetadata } from ".
import { getModelsFromCache } from "./fetchers/modelCache"
import { getApiRequestTimeout } from "./utils/timeout-config"
import { handleOpenAIError } from "./utils/openai-error-handler"
import { ApiInferenceLogger } from "../logging/ApiInferenceLogger"
import { createLoggingFetch } from "../logging/logging-fetch"
export class LmStudioHandler extends BaseProvider implements SingleCompletionHandler {
protected options: ApiHandlerOptions
@ -34,6 +36,7 @@ export class LmStudioHandler extends BaseProvider implements SingleCompletionHan
baseURL: (this.options.lmStudioBaseUrl || "http://localhost:1234") + "/v1",
apiKey: apiKey,
timeout: getApiRequestTimeout(),
fetch: ApiInferenceLogger.isEnabled() ? createLoggingFetch({ provider: this.providerName }) : undefined,
})
}

View file

@ -15,6 +15,8 @@ import { BaseProvider } from "./base-provider"
import type { SingleCompletionHandler, ApiHandlerCreateMessageMetadata } from "../index"
import { calculateApiCostAnthropic } from "../../shared/cost"
import { convertOpenAIToolsToAnthropic } from "../../core/prompts/tools/native-tools/converters"
import { ApiInferenceLogger } from "../logging/ApiInferenceLogger"
import { createLoggingFetch } from "../logging/logging-fetch"
/**
* Converts OpenAI tool_choice to Anthropic ToolChoice format
@ -74,6 +76,7 @@ export class MiniMaxHandler extends BaseProvider implements SingleCompletionHand
this.client = new Anthropic({
baseURL,
apiKey: options.minimaxApiKey,
fetch: ApiInferenceLogger.isEnabled() ? createLoggingFetch({ provider: this.providerName }) : undefined,
})
}

View file

@ -8,6 +8,7 @@ import type { ApiHandlerOptions } from "../../shared/api"
import { getOllamaModels } from "./fetchers/ollama"
import { XmlMatcher } from "../../utils/xml-matcher"
import type { SingleCompletionHandler, ApiHandlerCreateMessageMetadata } from "../index"
import { ApiInferenceLogger } from "../logging/ApiInferenceLogger"
interface OllamaChatOptions {
temperature: number
@ -206,6 +207,9 @@ export class NativeOllamaHandler extends BaseProvider implements SingleCompletio
messages: Anthropic.Messages.MessageParam[],
metadata?: ApiHandlerCreateMessageMetadata,
): ApiStream {
const startedAt = Date.now()
const shouldLog = ApiInferenceLogger.isEnabled()
const client = this.ensureClient()
const { id: modelId, info: modelInfo } = await this.fetchModel()
const useR1Format = modelId.toLowerCase().includes("deepseek-r1")
@ -230,6 +234,19 @@ export class NativeOllamaHandler extends BaseProvider implements SingleCompletio
supportsNativeTools && metadata?.tools && metadata.tools.length > 0 && metadata?.toolProtocol !== "xml"
try {
if (shouldLog) {
ApiInferenceLogger.logRaw(`[API][request][${this.providerName}][${modelId}]`, {
model: modelId,
messages: ollamaMessages,
stream: true,
options: {
temperature: this.options.modelTemperature ?? (useR1Format ? DEEP_SEEK_DEFAULT_TEMPERATURE : 0),
...(this.options.ollamaNumCtx !== undefined ? { num_ctx: this.options.ollamaNumCtx } : {}),
},
...(useNativeTools ? { tools: this.convertToolsToOllama(metadata.tools) } : {}),
})
}
// Build options object conditionally
const chatOptions: OllamaChatOptions = {
temperature: this.options.modelTemperature ?? (useR1Format ? DEEP_SEEK_DEFAULT_TEMPERATURE : 0),
@ -254,12 +271,17 @@ export class NativeOllamaHandler extends BaseProvider implements SingleCompletio
let totalOutputTokens = 0
// Track tool calls across chunks (Ollama may send complete tool_calls in final chunk)
let toolCallIndex = 0
const toolCalls: Array<{ id: string; name: string; arguments: unknown }> = []
let assembledText = ""
let assembledReasoning = ""
try {
for await (const chunk of stream) {
if (typeof chunk.message.content === "string" && chunk.message.content.length > 0) {
// Process content through matcher for reasoning detection
for (const matcherChunk of matcher.update(chunk.message.content)) {
if (matcherChunk.type === "text") assembledText += matcherChunk.text
if (matcherChunk.type === "reasoning") assembledReasoning += matcherChunk.text
yield matcherChunk
}
}
@ -269,6 +291,11 @@ export class NativeOllamaHandler extends BaseProvider implements SingleCompletio
for (const toolCall of chunk.message.tool_calls) {
// Generate a unique ID for this tool call
const toolCallId = `ollama-tool-${toolCallIndex}`
toolCalls.push({
id: toolCallId,
name: toolCall.function.name,
arguments: toolCall.function.arguments,
})
yield {
type: "tool_call_partial",
index: toolCallIndex,
@ -293,6 +320,8 @@ export class NativeOllamaHandler extends BaseProvider implements SingleCompletio
// Yield any remaining content from the matcher
for (const chunk of matcher.final()) {
if (chunk.type === "text") assembledText += chunk.text
if (chunk.type === "reasoning") assembledReasoning += chunk.text
yield chunk
}
@ -304,11 +333,42 @@ export class NativeOllamaHandler extends BaseProvider implements SingleCompletio
outputTokens: totalOutputTokens,
}
}
if (shouldLog) {
const durationMs = Date.now() - startedAt
ApiInferenceLogger.logRaw(
`[API][response][${this.providerName}][${modelId}][${durationMs}ms][streaming]`,
{
model: modelId,
message: {
role: "assistant",
content: assembledText,
...(assembledReasoning.length > 0 ? { reasoning: assembledReasoning } : {}),
...(toolCalls.length > 0 ? { tool_calls: toolCalls } : {}),
},
usage:
totalInputTokens > 0 || totalOutputTokens > 0
? { inputTokens: totalInputTokens, outputTokens: totalOutputTokens }
: undefined,
},
)
}
} catch (streamError: any) {
if (shouldLog) {
const durationMs = Date.now() - startedAt
ApiInferenceLogger.logRawError(
`[API][error][${this.providerName}][${modelId}][${durationMs}ms]`,
streamError,
)
}
console.error("Error processing Ollama stream:", streamError)
throw new Error(`Ollama stream processing error: ${streamError.message || "Unknown error"}`)
}
} catch (error: any) {
if (shouldLog) {
const durationMs = Date.now() - startedAt
ApiInferenceLogger.logRawError(`[API][error][${this.providerName}][${modelId}][${durationMs}ms]`, error)
}
// Enhance error reporting
const statusCode = error.status || error.statusCode
const errorMessage = error.message || "Unknown error"
@ -343,6 +403,9 @@ export class NativeOllamaHandler extends BaseProvider implements SingleCompletio
async completePrompt(prompt: string): Promise<string> {
try {
const startedAt = Date.now()
const shouldLog = ApiInferenceLogger.isEnabled()
const client = this.ensureClient()
const { id: modelId } = await this.fetchModel()
const useR1Format = modelId.toLowerCase().includes("deepseek-r1")
@ -357,6 +420,15 @@ export class NativeOllamaHandler extends BaseProvider implements SingleCompletio
chatOptions.num_ctx = this.options.ollamaNumCtx
}
if (shouldLog) {
ApiInferenceLogger.logRaw(`[API][request][${this.providerName}][${modelId}]`, {
model: modelId,
messages: [{ role: "user", content: prompt }],
stream: false,
options: chatOptions,
})
}
const response = await client.chat({
model: modelId,
messages: [{ role: "user", content: prompt }],
@ -364,8 +436,20 @@ export class NativeOllamaHandler extends BaseProvider implements SingleCompletio
options: chatOptions,
})
if (shouldLog) {
const durationMs = Date.now() - startedAt
ApiInferenceLogger.logRaw(
`[API][response][${this.providerName}][${modelId}][${durationMs}ms]`,
response,
)
}
return response.message?.content || ""
} catch (error) {
const modelId = this.options.ollamaModelId || this.options.apiModelId || "unknown"
if (ApiInferenceLogger.isEnabled()) {
ApiInferenceLogger.logRawError(`[API][error][${this.providerName}][${modelId}][0ms]`, error)
}
if (error instanceof Error) {
throw new Error(`Ollama completion error: ${error.message}`)
}

View file

@ -25,6 +25,8 @@ import { getModelParams } from "../transform/model-params"
import { BaseProvider } from "./base-provider"
import type { SingleCompletionHandler, ApiHandlerCreateMessageMetadata } from "../index"
import { isMcpTool } from "../../utils/mcp-name"
import { ApiInferenceLogger } from "../logging/ApiInferenceLogger"
import { createLoggingFetch } from "../logging/logging-fetch"
export type OpenAiNativeModel = ReturnType<OpenAiNativeHandler["getModel"]>
@ -68,7 +70,11 @@ export class OpenAiNativeHandler extends BaseProvider implements SingleCompletio
this.options.enableResponsesReasoningSummary = true
}
const apiKey = this.options.openAiNativeApiKey ?? "not-provided"
this.client = new OpenAI({ baseURL: this.options.openAiNativeBaseUrl, apiKey })
this.client = new OpenAI({
baseURL: this.options.openAiNativeBaseUrl,
apiKey,
fetch: ApiInferenceLogger.isEnabled() ? createLoggingFetch({ provider: this.providerName }) : undefined,
})
}
private normalizeUsage(usage: any, model: OpenAiNativeModel): ApiStreamUsageChunk | undefined {
@ -175,53 +181,28 @@ export class OpenAiNativeHandler extends BaseProvider implements SingleCompletio
metadata,
)
// Start inference logging with actual request body
const logHandle = this.inferenceLogger.start(
{
provider: this.providerName,
operation: "createMessage",
model: model.id,
},
requestBody,
)
// Accumulators for response logging
const accumulatedText: string[] = []
const accumulatedReasoning: string[] = []
const toolCalls: Array<{ id?: string; name?: string }> = []
let lastUsage: any
try {
// Make the request (pass systemPrompt and messages for potential retry)
for await (const chunk of this.executeRequest(requestBody, model, metadata, systemPrompt, messages)) {
// Accumulate for logging
if (chunk.type === "text") {
accumulatedText.push(chunk.text)
} else if (chunk.type === "reasoning") {
accumulatedReasoning.push(chunk.text)
} else if (chunk.type === "tool_call" || chunk.type === "tool_call_partial") {
if (chunk.id || chunk.name) {
toolCalls.push({ id: chunk.id, name: chunk.name })
}
} else if (chunk.type === "usage") {
lastUsage = chunk
// Make the request (pass systemPrompt and messages for potential retry)
for await (const chunk of this.executeRequest(requestBody, model, metadata, systemPrompt, messages)) {
// Accumulate for logging
if (chunk.type === "text") {
accumulatedText.push(chunk.text)
} else if (chunk.type === "reasoning") {
accumulatedReasoning.push(chunk.text)
} else if (chunk.type === "tool_call" || chunk.type === "tool_call_partial") {
if (chunk.id || chunk.name) {
toolCalls.push({ id: chunk.id, name: chunk.name })
}
yield chunk
} else if (chunk.type === "usage") {
lastUsage = chunk
}
// Log successful response
logHandle.success({
text: accumulatedText.join(""),
reasoning: accumulatedReasoning.length > 0 ? accumulatedReasoning.join("") : undefined,
toolCalls: toolCalls.length > 0 ? toolCalls : undefined,
usage: lastUsage,
responseId: this.lastResponseId,
responseOutput: this.lastResponseOutput,
})
} catch (error) {
logHandle.error(error)
throw error
yield chunk
}
}
@ -517,7 +498,8 @@ export class OpenAiNativeHandler extends BaseProvider implements SingleCompletio
this.abortController = new AbortController()
try {
const response = await fetch(url, {
const fetchFn = ApiInferenceLogger.isEnabled() ? createLoggingFetch({ provider: this.providerName }) : fetch
const response = await fetchFn(url, {
method: "POST",
headers: {
"Content-Type": "application/json",

View file

@ -26,6 +26,8 @@ import { BaseProvider } from "./base-provider"
import type { SingleCompletionHandler, ApiHandlerCreateMessageMetadata } from "../index"
import { getApiRequestTimeout } from "./utils/timeout-config"
import { handleOpenAIError } from "./utils/openai-error-handler"
import { ApiInferenceLogger } from "../logging/ApiInferenceLogger"
import { createLoggingFetch } from "../logging/logging-fetch"
// TODO: Rename this to OpenAICompatibleHandler. Also, I think the
// `OpenAINativeHandler` can subclass from this, since it's obviously
@ -60,6 +62,7 @@ export class OpenAiHandler extends BaseProvider implements SingleCompletionHandl
defaultHeaders: headers,
defaultQuery: { "api-version": this.options.azureApiVersion || "2024-05-01-preview" },
timeout,
fetch: ApiInferenceLogger.isEnabled() ? createLoggingFetch({ provider: this.providerName }) : undefined,
})
} else if (isAzureOpenAi) {
// Azure API shape slightly differs from the core API shape:
@ -70,6 +73,7 @@ export class OpenAiHandler extends BaseProvider implements SingleCompletionHandl
apiVersion: this.options.azureApiVersion || azureOpenAiDefaultApiVersion,
defaultHeaders: headers,
timeout,
fetch: ApiInferenceLogger.isEnabled() ? createLoggingFetch({ provider: this.providerName }) : undefined,
})
} else {
this.client = new OpenAI({
@ -77,6 +81,7 @@ export class OpenAiHandler extends BaseProvider implements SingleCompletionHandl
apiKey,
defaultHeaders: headers,
timeout,
fetch: ApiInferenceLogger.isEnabled() ? createLoggingFetch({ provider: this.providerName }) : undefined,
})
}
}
@ -182,99 +187,76 @@ export class OpenAiHandler extends BaseProvider implements SingleCompletionHandl
// Add max_tokens if needed
this.addMaxTokensIfNeeded(requestOptions, modelInfo)
// Start inference logging with actual request params
const logHandle = this.inferenceLogger.start(
{
provider: this.providerName,
operation: "createMessage",
model: modelId,
},
requestOptions,
let stream
try {
stream = await this.client.chat.completions.create(
requestOptions,
isAzureAiInference ? { path: OPENAI_AZURE_AI_INFERENCE_PATH } : {},
)
} catch (error) {
throw handleOpenAIError(error, this.providerName)
}
const matcher = new XmlMatcher(
"think",
(chunk) =>
({
type: chunk.matched ? "reasoning" : "text",
text: chunk.data,
}) as const,
)
try {
let stream
try {
stream = await this.client.chat.completions.create(
requestOptions,
isAzureAiInference ? { path: OPENAI_AZURE_AI_INFERENCE_PATH } : {},
)
} catch (error) {
throw handleOpenAIError(error, this.providerName)
const activeToolCallIds = new Set<string>()
for await (const chunk of stream) {
const delta = chunk.choices?.[0]?.delta ?? {}
const finishReason = chunk.choices?.[0]?.finish_reason
if (delta.content) {
for (const matchedChunk of matcher.update(delta.content)) {
if (matchedChunk.type === "text") {
accumulatedText.push(matchedChunk.text)
} else if (matchedChunk.type === "reasoning") {
accumulatedReasoning.push(matchedChunk.text)
}
yield matchedChunk
}
}
const matcher = new XmlMatcher(
"think",
(chunk) =>
({
type: chunk.matched ? "reasoning" : "text",
text: chunk.data,
}) as const,
)
if ("reasoning_content" in delta && delta.reasoning_content) {
accumulatedReasoning.push((delta.reasoning_content as string | undefined) || "")
yield {
type: "reasoning",
text: (delta.reasoning_content as string | undefined) || "",
}
}
const activeToolCallIds = new Set<string>()
for await (const chunk of stream) {
const delta = chunk.choices?.[0]?.delta ?? {}
const finishReason = chunk.choices?.[0]?.finish_reason
if (delta.content) {
for (const matchedChunk of matcher.update(delta.content)) {
if (matchedChunk.type === "text") {
accumulatedText.push(matchedChunk.text)
} else if (matchedChunk.type === "reasoning") {
accumulatedReasoning.push(matchedChunk.text)
}
yield matchedChunk
// Track tool calls for logging and use processToolCalls for proper tool_call_end events
if (delta.tool_calls) {
for (const toolCall of delta.tool_calls) {
if (toolCall.id || toolCall.function?.name) {
toolCalls.push({ id: toolCall.id, name: toolCall.function?.name })
}
}
if ("reasoning_content" in delta && delta.reasoning_content) {
accumulatedReasoning.push((delta.reasoning_content as string | undefined) || "")
yield {
type: "reasoning",
text: (delta.reasoning_content as string | undefined) || "",
}
}
// Track tool calls for logging and use processToolCalls for proper tool_call_end events
if (delta.tool_calls) {
for (const toolCall of delta.tool_calls) {
if (toolCall.id || toolCall.function?.name) {
toolCalls.push({ id: toolCall.id, name: toolCall.function?.name })
}
}
}
yield* this.processToolCalls(delta, finishReason, activeToolCallIds)
if (chunk.usage) {
lastUsage = chunk.usage
}
}
yield* this.processToolCalls(delta, finishReason, activeToolCallIds)
for (const matchedChunk of matcher.final()) {
if (matchedChunk.type === "text") {
accumulatedText.push(matchedChunk.text)
} else if (matchedChunk.type === "reasoning") {
accumulatedReasoning.push(matchedChunk.text)
}
yield matchedChunk
if (chunk.usage) {
lastUsage = chunk.usage
}
}
if (lastUsage) {
yield this.processUsageMetrics(lastUsage, modelInfo)
for (const matchedChunk of matcher.final()) {
if (matchedChunk.type === "text") {
accumulatedText.push(matchedChunk.text)
} else if (matchedChunk.type === "reasoning") {
accumulatedReasoning.push(matchedChunk.text)
}
yield matchedChunk
}
// Log successful response
logHandle.success({
text: accumulatedText.join(""),
reasoning: accumulatedReasoning.length > 0 ? accumulatedReasoning.join("") : undefined,
toolCalls: toolCalls.length > 0 ? toolCalls : undefined,
usage: lastUsage,
})
} catch (error) {
logHandle.error(error)
throw error
if (lastUsage) {
yield this.processUsageMetrics(lastUsage, modelInfo)
}
} else {
// Non-streaming path
@ -295,63 +277,40 @@ export class OpenAiHandler extends BaseProvider implements SingleCompletionHandl
// Add max_tokens if needed
this.addMaxTokensIfNeeded(requestOptions, modelInfo)
// Start inference logging with actual request params
const logHandle = this.inferenceLogger.start(
{
provider: this.providerName,
operation: "createMessage",
model: modelId,
},
requestOptions,
)
let response
try {
let response
try {
response = await this.client.chat.completions.create(
requestOptions,
this._isAzureAiInference(modelUrl) ? { path: OPENAI_AZURE_AI_INFERENCE_PATH } : {},
)
} catch (error) {
throw handleOpenAIError(error, this.providerName)
}
response = await this.client.chat.completions.create(
requestOptions,
this._isAzureAiInference(modelUrl) ? { path: OPENAI_AZURE_AI_INFERENCE_PATH } : {},
)
} catch (error) {
throw handleOpenAIError(error, this.providerName)
}
const message = response.choices?.[0]?.message
const message = response.choices?.[0]?.message
if (message?.tool_calls) {
for (const toolCall of message.tool_calls) {
if (toolCall.type === "function") {
toolCalls.push({ id: toolCall.id, name: toolCall.function.name })
yield {
type: "tool_call",
id: toolCall.id,
name: toolCall.function.name,
arguments: toolCall.function.arguments,
}
if (message?.tool_calls) {
for (const toolCall of message.tool_calls) {
if (toolCall.type === "function") {
toolCalls.push({ id: toolCall.id, name: toolCall.function.name })
yield {
type: "tool_call",
id: toolCall.id,
name: toolCall.function.name,
arguments: toolCall.function.arguments,
}
}
}
accumulatedText.push(message?.content || "")
yield {
type: "text",
text: message?.content || "",
}
lastUsage = response.usage
yield this.processUsageMetrics(response.usage, modelInfo)
// Log successful response
logHandle.success({
text: accumulatedText.join(""),
reasoning: accumulatedReasoning.length > 0 ? accumulatedReasoning.join("") : undefined,
toolCalls: toolCalls.length > 0 ? toolCalls : undefined,
usage: lastUsage,
})
} catch (error) {
logHandle.error(error)
throw error
}
accumulatedText.push(message?.content || "")
yield {
type: "text",
text: message?.content || "",
}
lastUsage = response.usage
yield this.processUsageMetrics(response.usage, modelInfo)
}
}
@ -454,72 +413,50 @@ export class OpenAiHandler extends BaseProvider implements SingleCompletionHandl
// This allows O3 models to limit response length when includeMaxTokens is enabled
this.addMaxTokensIfNeeded(requestOptions, modelInfo)
// Start inference logging with actual request params
const logHandle = this.inferenceLogger.start(
{
provider: this.providerName,
operation: "createMessage",
model: modelId,
},
requestOptions,
)
let stream
try {
let stream
try {
stream = await this.client.chat.completions.create(
requestOptions,
methodIsAzureAiInference ? { path: OPENAI_AZURE_AI_INFERENCE_PATH } : {},
)
} catch (error) {
throw handleOpenAIError(error, this.providerName)
}
const activeToolCallIds = new Set<string>()
for await (const chunk of stream) {
const delta = chunk.choices?.[0]?.delta
const finishReason = chunk.choices?.[0]?.finish_reason
if (delta) {
if (delta.content) {
accumulatedText.push(delta.content)
yield {
type: "text",
text: delta.content,
}
}
// Track tool calls for logging and use processToolCalls for proper tool_call_end events
if (delta.tool_calls) {
for (const toolCall of delta.tool_calls) {
if (toolCall.id || toolCall.function?.name) {
toolCalls.push({ id: toolCall.id, name: toolCall.function?.name })
}
}
}
yield* this.processToolCalls(delta, finishReason, activeToolCallIds)
}
if (chunk.usage) {
lastUsage = chunk.usage
yield {
type: "usage",
inputTokens: chunk.usage.prompt_tokens || 0,
outputTokens: chunk.usage.completion_tokens || 0,
}
}
}
// Log successful response
logHandle.success({
text: accumulatedText.join(""),
toolCalls: toolCalls.length > 0 ? toolCalls : undefined,
usage: lastUsage,
})
stream = await this.client.chat.completions.create(
requestOptions,
methodIsAzureAiInference ? { path: OPENAI_AZURE_AI_INFERENCE_PATH } : {},
)
} catch (error) {
logHandle.error(error)
throw error
throw handleOpenAIError(error, this.providerName)
}
const activeToolCallIds = new Set<string>()
for await (const chunk of stream) {
const delta = chunk.choices?.[0]?.delta
const finishReason = chunk.choices?.[0]?.finish_reason
if (delta) {
if (delta.content) {
accumulatedText.push(delta.content)
yield {
type: "text",
text: delta.content,
}
}
// Track tool calls for logging and use processToolCalls for proper tool_call_end events
if (delta.tool_calls) {
for (const toolCall of delta.tool_calls) {
if (toolCall.id || toolCall.function?.name) {
toolCalls.push({ id: toolCall.id, name: toolCall.function?.name })
}
}
}
yield* this.processToolCalls(delta, finishReason, activeToolCallIds)
}
if (chunk.usage) {
lastUsage = chunk.usage
yield {
type: "usage",
inputTokens: chunk.usage.prompt_tokens || 0,
outputTokens: chunk.usage.completion_tokens || 0,
}
}
}
} else {
const requestOptions: OpenAI.Chat.Completions.ChatCompletionCreateParamsNonStreaming = {
@ -545,61 +482,39 @@ export class OpenAiHandler extends BaseProvider implements SingleCompletionHandl
// This allows O3 models to limit response length when includeMaxTokens is enabled
this.addMaxTokensIfNeeded(requestOptions, modelInfo)
// Start inference logging with actual request params
const logHandle = this.inferenceLogger.start(
{
provider: this.providerName,
operation: "createMessage",
model: modelId,
},
requestOptions,
)
let response
try {
let response
try {
response = await this.client.chat.completions.create(
requestOptions,
methodIsAzureAiInference ? { path: OPENAI_AZURE_AI_INFERENCE_PATH } : {},
)
} catch (error) {
throw handleOpenAIError(error, this.providerName)
}
response = await this.client.chat.completions.create(
requestOptions,
methodIsAzureAiInference ? { path: OPENAI_AZURE_AI_INFERENCE_PATH } : {},
)
} catch (error) {
throw handleOpenAIError(error, this.providerName)
}
const message = response.choices?.[0]?.message
if (message?.tool_calls) {
for (const toolCall of message.tool_calls) {
if (toolCall.type === "function") {
toolCalls.push({ id: toolCall.id, name: toolCall.function.name })
yield {
type: "tool_call",
id: toolCall.id,
name: toolCall.function.name,
arguments: toolCall.function.arguments,
}
const message = response.choices?.[0]?.message
if (message?.tool_calls) {
for (const toolCall of message.tool_calls) {
if (toolCall.type === "function") {
toolCalls.push({ id: toolCall.id, name: toolCall.function.name })
yield {
type: "tool_call",
id: toolCall.id,
name: toolCall.function.name,
arguments: toolCall.function.arguments,
}
}
}
accumulatedText.push(message?.content || "")
yield {
type: "text",
text: message?.content || "",
}
lastUsage = response.usage
yield this.processUsageMetrics(response.usage)
// Log successful response
logHandle.success({
text: accumulatedText.join(""),
toolCalls: toolCalls.length > 0 ? toolCalls : undefined,
usage: lastUsage,
})
} catch (error) {
logHandle.error(error)
throw error
}
accumulatedText.push(message?.content || "")
yield {
type: "text",
text: message?.content || "",
}
lastUsage = response.usage
yield this.processUsageMetrics(response.usage)
}
}

View file

@ -36,6 +36,8 @@ import type { ApiHandlerCreateMessageMetadata, SingleCompletionHandler } from ".
import { handleOpenAIError } from "./utils/openai-error-handler"
import { generateImageWithProvider, ImageGenerationResult } from "./utils/image-generation"
import { applyRouterToolPreferences } from "./utils/router-tool-preferences"
import { ApiInferenceLogger } from "../logging/ApiInferenceLogger"
import { createLoggingFetch } from "../logging/logging-fetch"
// Add custom interface for OpenRouter params.
type OpenRouterChatCompletionParams = OpenAI.Chat.ChatCompletionCreateParams & {
@ -150,7 +152,12 @@ 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 })
this.client = new OpenAI({
baseURL,
apiKey,
defaultHeaders: DEFAULT_HEADERS,
fetch: ApiInferenceLogger.isEnabled() ? createLoggingFetch({ provider: this.providerName }) : undefined,
})
// Load models asynchronously to populate cache before getModel() is called
this.loadDynamicModels().catch((error) => {
@ -319,235 +326,197 @@ export class OpenRouterHandler extends BaseProvider implements SingleCompletionH
? { headers: { "x-anthropic-beta": "fine-grained-tool-streaming-2025-05-14" } }
: undefined
// Start inference logging with actual request params
const logHandle = this.inferenceLogger.start(
{
provider: this.providerName,
operation: "createMessage",
model: modelId,
},
{ completionParams, requestOptions },
)
// Accumulators for response logging
const accumulatedText: string[] = []
const accumulatedReasoning: string[] = []
const toolCalls: Array<{ id?: string; name?: string }> = []
let stream
try {
let stream
try {
stream = await this.client.chat.completions.create(completionParams, requestOptions)
} catch (error) {
// Try to parse as OpenRouter error structure using Zod
const parseResult = OpenRouterErrorResponseSchema.safeParse(error)
if (parseResult.success && parseResult.data.error) {
const openRouterError = parseResult.data
const rawString = openRouterError.error?.metadata?.raw
const parsedError = extractErrorFromMetadataRaw(rawString)
const rawErrorMessage = parsedError || openRouterError.error?.message || "Unknown error"
const apiError = Object.assign(
new ApiProviderError(
rawErrorMessage,
this.providerName,
modelId,
"createMessage",
openRouterError.error?.code,
),
{
status: openRouterError.error?.code,
error: openRouterError.error,
},
)
TelemetryService.instance.captureException(apiError)
throw handleOpenAIError(error, this.providerName)
} else {
// Fallback for non-OpenRouter errors
const errorMessage = error instanceof Error ? error.message : String(error)
const apiError = new ApiProviderError(errorMessage, this.providerName, modelId, "createMessage")
TelemetryService.instance.captureException(apiError)
throw handleOpenAIError(error, this.providerName)
}
}
let lastUsage: CompletionUsage | undefined = undefined
// Accumulator for reasoning_details FROM the API.
// We preserve the original shape of reasoning_details to prevent malformed responses.
const reasoningDetailsAccumulator = new Map<
string,
{
type: string
text?: string
summary?: string
data?: string
id?: string | null
format?: string
signature?: string
index: number
}
>()
// Track whether we've yielded displayable text from reasoning_details.
// When reasoning_details has displayable content (reasoning.text or reasoning.summary),
// we skip yielding the top-level reasoning field to avoid duplicate display.
let hasYieldedReasoningFromDetails = false
for await (const chunk of stream) {
// OpenRouter returns an error object instead of the OpenAI SDK throwing an error.
if ("error" in chunk) {
logHandle.error(chunk.error)
this.handleStreamingError(chunk.error as OpenRouterError, modelId, "createMessage")
}
const delta = chunk.choices[0]?.delta
const finishReason = chunk.choices[0]?.finish_reason
if (delta) {
// Handle reasoning_details array format (used by Gemini 3, Claude, OpenAI o-series, etc.)
// See: https://openrouter.ai/docs/use-cases/reasoning-tokens#preserving-reasoning-blocks
// Priority: Check for reasoning_details first, as it's the newer format
const deltaWithReasoning = delta as typeof delta & {
reasoning_details?: Array<{
type: string
text?: string
summary?: string
data?: string
id?: string | null
format?: string
signature?: string
index?: number
}>
}
if (deltaWithReasoning.reasoning_details && Array.isArray(deltaWithReasoning.reasoning_details)) {
for (const detail of deltaWithReasoning.reasoning_details) {
const index = detail.index ?? 0
const key = `${detail.type}-${index}`
const existing = reasoningDetailsAccumulator.get(key)
if (existing) {
// Accumulate text/summary/data for existing reasoning detail
if (detail.text !== undefined) {
existing.text = (existing.text || "") + detail.text
}
if (detail.summary !== undefined) {
existing.summary = (existing.summary || "") + detail.summary
}
if (detail.data !== undefined) {
existing.data = (existing.data || "") + detail.data
}
// Update other fields if provided
if (detail.id !== undefined) existing.id = detail.id
if (detail.format !== undefined) existing.format = detail.format
if (detail.signature !== undefined) existing.signature = detail.signature
} else {
// Start new reasoning detail accumulation
reasoningDetailsAccumulator.set(key, {
type: detail.type,
text: detail.text,
summary: detail.summary,
data: detail.data,
id: detail.id,
format: detail.format,
signature: detail.signature,
index,
})
}
// Yield text for display (still fragmented for live streaming)
// Only reasoning.text and reasoning.summary have displayable content
// reasoning.encrypted is intentionally skipped as it contains redacted content
let reasoningText: string | undefined
if (detail.type === "reasoning.text" && typeof detail.text === "string") {
reasoningText = detail.text
} else if (detail.type === "reasoning.summary" && typeof detail.summary === "string") {
reasoningText = detail.summary
}
if (reasoningText) {
hasYieldedReasoningFromDetails = true
accumulatedReasoning.push(reasoningText)
yield { type: "reasoning", text: reasoningText }
}
}
}
// Handle top-level reasoning field for UI display.
// Skip if we've already yielded from reasoning_details to avoid duplicate display.
if ("reasoning" in delta && delta.reasoning && typeof delta.reasoning === "string") {
if (!hasYieldedReasoningFromDetails) {
accumulatedReasoning.push(delta.reasoning)
yield { type: "reasoning", text: delta.reasoning }
}
}
// Emit raw tool call chunks - NativeToolCallParser handles state management
if ("tool_calls" in delta && Array.isArray(delta.tool_calls)) {
for (const toolCall of delta.tool_calls) {
if (toolCall.id || toolCall.function?.name) {
toolCalls.push({ id: toolCall.id, name: toolCall.function?.name })
}
yield {
type: "tool_call_partial",
index: toolCall.index,
id: toolCall.id,
name: toolCall.function?.name,
arguments: toolCall.function?.arguments,
}
}
}
if (delta.content) {
accumulatedText.push(delta.content)
yield { type: "text", text: delta.content }
}
}
// Process finish_reason to emit tool_call_end events
// This ensures tool calls are finalized even if the stream doesn't properly close
if (finishReason) {
const endEvents = NativeToolCallParser.processFinishReason(finishReason)
for (const event of endEvents) {
yield event
}
}
if (chunk.usage) {
lastUsage = chunk.usage
}
}
// After streaming completes, store ONLY the reasoning_details we received from the API.
if (reasoningDetailsAccumulator.size > 0) {
this.currentReasoningDetails = Array.from(reasoningDetailsAccumulator.values())
}
if (lastUsage) {
yield {
type: "usage",
inputTokens: lastUsage.prompt_tokens || 0,
outputTokens: lastUsage.completion_tokens || 0,
cacheReadTokens: lastUsage.prompt_tokens_details?.cached_tokens,
reasoningTokens: lastUsage.completion_tokens_details?.reasoning_tokens,
totalCost: (lastUsage.cost_details?.upstream_inference_cost || 0) + (lastUsage.cost || 0),
}
}
// Log successful response
logHandle.success({
text: accumulatedText.join(""),
reasoning: accumulatedReasoning.length > 0 ? accumulatedReasoning.join("") : undefined,
toolCalls: toolCalls.length > 0 ? toolCalls : undefined,
usage: lastUsage,
reasoningDetails:
reasoningDetailsAccumulator.size > 0 ? Array.from(reasoningDetailsAccumulator.values()) : undefined,
})
stream = await this.client.chat.completions.create(completionParams, requestOptions)
} catch (error) {
logHandle.error(error)
throw error
// Try to parse as OpenRouter error structure using Zod
const parseResult = OpenRouterErrorResponseSchema.safeParse(error)
if (parseResult.success && parseResult.data.error) {
const openRouterError = parseResult.data
const rawString = openRouterError.error?.metadata?.raw
const parsedError = extractErrorFromMetadataRaw(rawString)
const rawErrorMessage = parsedError || openRouterError.error?.message || "Unknown error"
const apiError = Object.assign(
new ApiProviderError(
rawErrorMessage,
this.providerName,
modelId,
"createMessage",
openRouterError.error?.code,
),
{
status: openRouterError.error?.code,
error: openRouterError.error,
},
)
TelemetryService.instance.captureException(apiError)
throw handleOpenAIError(error, this.providerName)
}
// Fallback for non-OpenRouter errors
const errorMessage = error instanceof Error ? error.message : String(error)
const apiError = new ApiProviderError(errorMessage, this.providerName, modelId, "createMessage")
TelemetryService.instance.captureException(apiError)
throw handleOpenAIError(error, this.providerName)
}
let lastUsage: CompletionUsage | undefined = undefined
// Accumulator for reasoning_details: accumulate text by type-index key
const reasoningDetailsAccumulator = new Map<
string,
{
type: string
text?: string
summary?: string
data?: string
id?: string | null
format?: string
signature?: string
index: number
}
>()
// Track whether we've yielded displayable text from reasoning_details.
// When reasoning_details has displayable content (reasoning.text or reasoning.summary),
// we skip yielding the top-level reasoning field to avoid duplicate display.
let hasYieldedReasoningFromDetails = false
for await (const chunk of stream) {
// OpenRouter returns an error object instead of the OpenAI SDK throwing an error.
if ("error" in chunk) {
this.handleStreamingError(chunk.error as OpenRouterError, modelId, "createMessage")
}
const delta = chunk.choices[0]?.delta
const finishReason = chunk.choices[0]?.finish_reason
if (delta) {
// Handle reasoning_details array format (used by Gemini 3, Claude, OpenAI o-series, etc.)
// See: https://openrouter.ai/docs/use-cases/reasoning-tokens#preserving-reasoning-blocks
// Priority: Check for reasoning_details first, as it's the newer format
const deltaWithReasoning = delta as typeof delta & {
reasoning_details?: Array<{
type: string
text?: string
summary?: string
data?: string
id?: string | null
format?: string
signature?: string
index?: number
}>
}
if (deltaWithReasoning.reasoning_details && Array.isArray(deltaWithReasoning.reasoning_details)) {
for (const detail of deltaWithReasoning.reasoning_details) {
const index = detail.index ?? 0
const key = `${detail.type}-${index}`
const existing = reasoningDetailsAccumulator.get(key)
if (existing) {
// Accumulate text/summary/data for existing reasoning detail
if (detail.text !== undefined) {
existing.text = (existing.text || "") + detail.text
}
if (detail.summary !== undefined) {
existing.summary = (existing.summary || "") + detail.summary
}
if (detail.data !== undefined) {
existing.data = (existing.data || "") + detail.data
}
// Update other fields if provided
if (detail.id !== undefined) existing.id = detail.id
if (detail.format !== undefined) existing.format = detail.format
if (detail.signature !== undefined) existing.signature = detail.signature
} else {
// Start new reasoning detail accumulation
reasoningDetailsAccumulator.set(key, {
type: detail.type,
text: detail.text,
summary: detail.summary,
data: detail.data,
id: detail.id,
format: detail.format,
signature: detail.signature,
index,
})
}
// Yield text for display (still fragmented for live streaming)
// Only reasoning.text and reasoning.summary have displayable content
// reasoning.encrypted is intentionally skipped as it contains redacted content
let reasoningText: string | undefined
if (detail.type === "reasoning.text" && typeof detail.text === "string") {
reasoningText = detail.text
} else if (detail.type === "reasoning.summary" && typeof detail.summary === "string") {
reasoningText = detail.summary
}
if (reasoningText) {
hasYieldedReasoningFromDetails = true
yield { type: "reasoning", text: reasoningText }
}
}
}
// Handle top-level reasoning field for UI display.
// Skip if we've already yielded from reasoning_details to avoid duplicate display.
if ("reasoning" in delta && delta.reasoning && typeof delta.reasoning === "string") {
if (!hasYieldedReasoningFromDetails) {
yield { type: "reasoning", text: delta.reasoning }
}
}
// Emit raw tool call chunks - NativeToolCallParser handles state management
if ("tool_calls" in delta && Array.isArray(delta.tool_calls)) {
for (const toolCall of delta.tool_calls) {
yield {
type: "tool_call_partial",
index: toolCall.index,
id: toolCall.id,
name: toolCall.function?.name,
arguments: toolCall.function?.arguments,
}
}
}
if (delta.content) {
yield { type: "text", text: delta.content }
}
}
// Process finish_reason to emit tool_call_end events
// This ensures tool calls are finalized even if the stream doesn't properly close
if (finishReason) {
const endEvents = NativeToolCallParser.processFinishReason(finishReason)
for (const event of endEvents) {
yield event
}
}
if (chunk.usage) {
lastUsage = chunk.usage
}
}
// After streaming completes, store the accumulated reasoning_details
if (reasoningDetailsAccumulator.size > 0) {
this.currentReasoningDetails = Array.from(reasoningDetailsAccumulator.values())
}
if (lastUsage) {
yield {
type: "usage",
inputTokens: lastUsage.prompt_tokens || 0,
outputTokens: lastUsage.completion_tokens || 0,
cacheReadTokens: lastUsage.prompt_tokens_details?.cached_tokens,
reasoningTokens: lastUsage.completion_tokens_details?.reasoning_tokens,
totalCost: (lastUsage.cost_details?.upstream_inference_cost || 0) + (lastUsage.cost || 0),
}
}
}

View file

@ -15,6 +15,9 @@ import { ApiStream } from "../transform/stream"
import { BaseProvider } from "./base-provider"
import type { SingleCompletionHandler, ApiHandlerCreateMessageMetadata } from "../index"
import { safeWriteJson } from "../../utils/safeWriteJson"
import { ApiInferenceLogger } from "../logging/ApiInferenceLogger"
import { createLoggingFetch } from "../logging/logging-fetch"
const QWEN_OAUTH_BASE_URL = "https://chat.qwen.ai"
const QWEN_OAUTH_TOKEN_ENDPOINT = `${QWEN_OAUTH_BASE_URL}/api/v1/oauth2/token`
@ -70,6 +73,7 @@ export class QwenCodeHandler extends BaseProvider implements SingleCompletionHan
this.client = new OpenAI({
apiKey: "dummy-key-will-be-replaced",
baseURL: "https://dashscope.aliyuncs.com/compatible-mode/v1",
fetch: ApiInferenceLogger.isEnabled() ? createLoggingFetch({ provider: this.providerName }) : undefined,
})
}
return this.client
@ -147,7 +151,7 @@ export class QwenCodeHandler extends BaseProvider implements SingleCompletionHan
const filePath = getQwenCachedCredentialPath(this.options.qwenCodeOauthPath)
try {
await fs.writeFile(filePath, JSON.stringify(newCredentials, null, 2))
await safeWriteJson(filePath, newCredentials)
} catch (error) {
console.error("Failed to save refreshed credentials:", error)
// Continue with the refreshed token in memory even if file write fails

View file

@ -25,6 +25,8 @@ import type { SingleCompletionHandler, ApiHandlerCreateMessageMetadata } from ".
import { toRequestyServiceUrl } from "../../shared/utils/requesty"
import { handleOpenAIError } from "./utils/openai-error-handler"
import { applyRouterToolPreferences } from "./utils/router-tool-preferences"
import { ApiInferenceLogger } from "../logging/ApiInferenceLogger"
import { createLoggingFetch } from "../logging/logging-fetch"
// Requesty usage includes an extra field for Anthropic use cases.
// Safely cast the prompt token details section to the appropriate structure.
@ -75,6 +77,7 @@ export class RequestyHandler extends BaseProvider implements SingleCompletionHan
baseURL: this.baseURL,
apiKey: apiKey,
defaultHeaders: DEFAULT_HEADERS,
fetch: ApiInferenceLogger.isEnabled() ? createLoggingFetch({ provider: this.providerName }) : undefined,
})
}

View file

@ -125,35 +125,7 @@ export class RooHandler extends BaseOpenAiCompatibleProvider<string> {
messages: Anthropic.Messages.MessageParam[],
metadata?: ApiHandlerCreateMessageMetadata,
): ApiStream {
const { id: model, info } = this.getModel()
// Get model parameters for logging
const params = getModelParams({
format: "openai",
modelId: model,
model: info,
settings: this.options,
defaultTemperature: this.defaultTemperature,
})
// Start inference logging
const logHandle = this.inferenceLogger.start(
{
provider: this.providerName,
operation: "createMessage",
model,
taskId: metadata?.taskId,
},
{
model,
maxTokens: params.maxTokens,
temperature: params.temperature,
messageCount: messages.length,
hasTools: !!metadata?.tools,
toolCount: metadata?.tools?.length ?? 0,
toolChoice: metadata?.tool_choice,
},
)
const { id: model } = this.getModel()
// Accumulators for final response logging
const accumulatedText: string[] = []
@ -360,17 +332,7 @@ export class RooHandler extends BaseOpenAiCompatibleProvider<string> {
totalCost: isFreeModel ? 0 : (lastUsage.cost ?? 0),
}
}
// Log successful response
logHandle.success({
text: accumulatedText.join(""),
reasoning: accumulatedReasoning.length > 0 ? accumulatedReasoning.join("") : undefined,
toolCalls: toolCalls.length > 0 ? toolCalls : undefined,
usage: lastUsage,
})
} catch (error) {
logHandle.error(error)
const errorContext = {
error: error instanceof Error ? error.message : String(error),
stack: error instanceof Error ? error.stack : undefined,

View file

@ -8,6 +8,8 @@ import { BaseProvider } from "./base-provider"
import { getModels, getModelsFromCache } from "./fetchers/modelCache"
import { DEFAULT_HEADERS } from "./constants"
import { ApiInferenceLogger } from "../logging/ApiInferenceLogger"
import { createLoggingFetch } from "../logging/logging-fetch"
type RouterProviderOptions = {
name: RouterName
@ -56,6 +58,7 @@ export abstract class RouterProvider extends BaseProvider {
...DEFAULT_HEADERS,
...(options.openAiHeaders || {}),
},
fetch: ApiInferenceLogger.isEnabled() ? createLoggingFetch({ provider: this.providerName }) : undefined,
})
}

View file

@ -10,6 +10,7 @@ import { normalizeToolSchema } from "../../utils/json-schema"
import { ApiStream } from "../transform/stream"
import { convertToVsCodeLmMessages, extractTextCountFromMessage } from "../transform/vscode-lm-format"
import { ApiInferenceLogger } from "../logging/ApiInferenceLogger"
import { BaseProvider } from "./base-provider"
import type { SingleCompletionHandler, ApiHandlerCreateMessageMetadata } from "../index"
@ -373,6 +374,21 @@ export class VsCodeLmHandler extends BaseProvider implements SingleCompletionHan
...convertToVsCodeLmMessages(cleanedMessages),
]
// Inference logging (VS Code LM is not HTTP-based, so we log at provider level)
const modelId = this.getModel().id
const startedAt = Date.now()
if (ApiInferenceLogger.isEnabled()) {
ApiInferenceLogger.logRaw(`[API][request][${this.providerName}][${modelId}]`, {
model: modelId,
system: systemPrompt,
messages: cleanedMessages,
toolProtocol: metadata?.toolProtocol,
tool_choice: metadata?.tool_choice,
parallelToolCalls: metadata?.parallelToolCalls,
hasTools: Boolean(metadata?.tools && metadata.tools.length > 0),
})
}
// Initialize cancellation token for the request
this.currentRequestCancellation = new vscode.CancellationTokenSource()
@ -482,6 +498,16 @@ export class VsCodeLmHandler extends BaseProvider implements SingleCompletionHan
// Count tokens in the accumulated text after stream completion
const totalOutputTokens: number = await this.internalCountTokens(accumulatedText)
if (ApiInferenceLogger.isEnabled()) {
ApiInferenceLogger.logRaw(
`[API][response][${this.providerName}][${modelId}][${Date.now() - startedAt}ms][streaming]`,
{
text: accumulatedText,
usage: { inputTokens: totalInputTokens, outputTokens: totalOutputTokens },
},
)
}
// Report final usage after stream completion
yield {
type: "usage",
@ -491,6 +517,13 @@ export class VsCodeLmHandler extends BaseProvider implements SingleCompletionHan
} catch (error: unknown) {
this.ensureCleanState()
if (ApiInferenceLogger.isEnabled()) {
ApiInferenceLogger.logRawError(
`[API][error][${this.providerName}][${modelId}][${Date.now() - startedAt}ms]`,
error,
)
}
if (error instanceof vscode.CancellationError) {
throw new Error("Roo Code <Language Model API>: Request cancelled by user")
}

View file

@ -15,6 +15,8 @@ import { DEFAULT_HEADERS } from "./constants"
import { BaseProvider } from "./base-provider"
import type { SingleCompletionHandler, ApiHandlerCreateMessageMetadata } from "../index"
import { handleOpenAIError } from "./utils/openai-error-handler"
import { ApiInferenceLogger } from "../logging/ApiInferenceLogger"
import { createLoggingFetch } from "../logging/logging-fetch"
const XAI_DEFAULT_TEMPERATURE = 0
@ -33,6 +35,7 @@ export class XAIHandler extends BaseProvider implements SingleCompletionHandler
baseURL: "https://api.x.ai/v1",
apiKey: apiKey,
defaultHeaders: DEFAULT_HEADERS,
fetch: ApiInferenceLogger.isEnabled() ? createLoggingFetch({ provider: this.providerName }) : undefined,
})
}

View file

@ -75,7 +75,8 @@ export async function activate(context: vscode.ExtensionContext) {
// Configure API inference logger for debugging (enable via ROO_CODE_API_LOGGING=true)
ApiInferenceLogger.configure({
enabled: process.env.ROO_CODE_API_LOGGING === "true",
sink: createOutputChannelLogger(outputChannel),
// Log only to the Extension Host Debug Console.
sink: (...args: unknown[]) => console.log(...args),
})
// Set extension path for custom tool registry to find bundled esbuild

View file

@ -1,4 +1,5 @@
import { CLAUDE_CODE_API_CONFIG } from "../streaming-client"
import { ApiInferenceLogger } from "../../../api/logging/ApiInferenceLogger"
describe("Claude Code Streaming Client", () => {
describe("CLAUDE_CODE_API_CONFIG", () => {
@ -27,12 +28,48 @@ describe("Claude Code Streaming Client", () => {
beforeEach(() => {
originalFetch = global.fetch
// Ensure we start from disabled state per test
ApiInferenceLogger.configure({ enabled: false, sink: () => {} })
})
afterEach(() => {
global.fetch = originalFetch
})
test("should wrap fetch with logging when ApiInferenceLogger is enabled", async () => {
const sink = vi.fn()
ApiInferenceLogger.configure({ enabled: true, sink })
const emptyStream = new ReadableStream<Uint8Array>({
start(controller) {
controller.close()
},
})
const mockFetch = vi
.fn()
.mockResolvedValue(new Response(emptyStream, { headers: { "content-type": "text/event-stream" } }))
global.fetch = mockFetch
const { createStreamingMessage } = await import("../streaming-client")
const stream = createStreamingMessage({
accessToken: "test-token",
model: "claude-3-5-sonnet-20241022",
systemPrompt: "You are helpful",
messages: [{ role: "user", content: "Hello" }],
})
for await (const _ of stream) {
// drain
}
expect(sink).toHaveBeenCalledWith(
expect.stringMatching(/^\[API\]\[request\]\[Claude Code\]\[.+\]$/),
expect.anything(),
)
})
test("should make request with correct headers", async () => {
const mockFetch = vi.fn().mockResolvedValue({
ok: true,

View file

@ -1,6 +1,8 @@
import type { Anthropic } from "@anthropic-ai/sdk"
import type { ClaudeCodeRateLimitInfo } from "@roo-code/types"
import { Package } from "../../shared/package"
import { ApiInferenceLogger } from "../../api/logging/ApiInferenceLogger"
import { createLoggingFetch } from "../../api/logging/logging-fetch"
/**
* Set of content block types that are valid for Anthropic API.
@ -370,6 +372,10 @@ export async function* createStreamingMessage(options: StreamMessageOptions): As
const { accessToken, model, systemPrompt, messages, maxTokens, thinking, tools, toolChoice, metadata, signal } =
options
const fetchFn: typeof fetch = ApiInferenceLogger.isEnabled()
? createLoggingFetch({ provider: "Claude Code" }, fetch)
: fetch
// Filter out non-Anthropic blocks before processing
const sanitizedMessages = filterNonAnthropicBlocks(messages)
@ -430,7 +436,7 @@ export async function* createStreamingMessage(options: StreamMessageOptions): As
}
// Make the request
const response = await fetch(`${CLAUDE_CODE_API_CONFIG.endpoint}?beta=true`, {
const response = await fetchFn(`${CLAUDE_CODE_API_CONFIG.endpoint}?beta=true`, {
method: "POST",
headers,
body: JSON.stringify(body),
@ -713,6 +719,10 @@ function parseRateLimitHeaders(headers: Headers): ClaudeCodeRateLimitInfo {
* Uses a small request to get the response headers containing rate limit data
*/
export async function fetchRateLimitInfo(accessToken: string): Promise<ClaudeCodeRateLimitInfo> {
const fetchFn: typeof fetch = ApiInferenceLogger.isEnabled()
? createLoggingFetch({ provider: "Claude Code" }, fetch)
: fetch
// Build minimal request body - use haiku for speed and lowest cost
const body = {
model: "claude-haiku-4-5",
@ -731,7 +741,7 @@ export async function fetchRateLimitInfo(accessToken: string): Promise<ClaudeCod
}
// Make the request
const response = await fetch(`${CLAUDE_CODE_API_CONFIG.endpoint}?beta=true`, {
const response = await fetchFn(`${CLAUDE_CODE_API_CONFIG.endpoint}?beta=true`, {
method: "POST",
headers,
body: JSON.stringify(body),