fix(logging): address PR review feedback

- withLogging: count tool_call_partial chunks using index-based tracking
  to avoid undercounting (resolves fix-id: 085ec7dcd8)
- createLoggingFetch: handle non-string request bodies (Blob, ArrayBuffer,
  FormData, ReadableStream) by returning descriptive placeholders instead
  of misleading toString() output (resolves fix-id: 78ceafcb0f)
- Added comprehensive tests for both fixes
This commit is contained in:
Hannes Rudolph 2025-12-17 21:02:47 -07:00 committed by daniel-lxs
parent 6abacbe59f
commit 5d588c427a
No known key found for this signature in database
GPG key ID: 21C74479048B3AA6
5 changed files with 376 additions and 8 deletions

View file

@ -0,0 +1,274 @@
/**
* @fileoverview Tests for the HTTP interceptor logging module
*/
import { createLoggingFetch } from "../http-interceptor"
import * as envConfig from "../env-config"
// Mock the env-config module
vi.mock("../env-config", () => ({
isLoggingEnabled: vi.fn(),
}))
describe("createLoggingFetch", () => {
let consoleSpy: ReturnType<typeof vi.spyOn>
let mockFetch: ReturnType<typeof vi.fn>
beforeEach(() => {
vi.clearAllMocks()
consoleSpy = vi.spyOn(console, "log").mockImplementation(() => {})
// Mock global fetch
mockFetch = vi.fn().mockResolvedValue(
new Response(JSON.stringify({ result: "success" }), {
status: 200,
statusText: "OK",
headers: { "content-type": "application/json" },
}),
)
vi.stubGlobal("fetch", mockFetch)
})
afterEach(() => {
vi.unstubAllGlobals()
})
describe("body parsing", () => {
beforeEach(() => {
vi.mocked(envConfig.isLoggingEnabled).mockReturnValue(true)
})
it("should parse JSON string body correctly", async () => {
const loggingFetch = createLoggingFetch("TestProvider")
const body = JSON.stringify({ message: "hello" })
await loggingFetch("https://api.example.com/test", {
method: "POST",
body,
})
expect(consoleSpy).toHaveBeenCalledWith(
"[TestProvider] RAW HTTP REQUEST",
expect.objectContaining({
body: { message: "hello" },
}),
)
})
it("should handle plain string body", async () => {
const loggingFetch = createLoggingFetch("TestProvider")
await loggingFetch("https://api.example.com/test", {
method: "POST",
body: "plain text content",
})
expect(consoleSpy).toHaveBeenCalledWith(
"[TestProvider] RAW HTTP REQUEST",
expect.objectContaining({
body: "plain text content",
}),
)
})
it("should handle URLSearchParams body", async () => {
const loggingFetch = createLoggingFetch("TestProvider")
const params = new URLSearchParams({ key: "value", foo: "bar" })
await loggingFetch("https://api.example.com/test", {
method: "POST",
body: params,
})
expect(consoleSpy).toHaveBeenCalledWith(
"[TestProvider] RAW HTTP REQUEST",
expect.objectContaining({
body: "key=value&foo=bar",
}),
)
})
it("should handle Blob body with placeholder", async () => {
const loggingFetch = createLoggingFetch("TestProvider")
const blob = new Blob(["binary content"], { type: "application/octet-stream" })
await loggingFetch("https://api.example.com/test", {
method: "POST",
body: blob,
})
expect(consoleSpy).toHaveBeenCalledWith(
"[TestProvider] RAW HTTP REQUEST",
expect.objectContaining({
body: expect.stringMatching(/^\[Blob: \d+ bytes, type: application\/octet-stream\]$/),
}),
)
})
it("should handle ArrayBuffer body with placeholder", async () => {
const loggingFetch = createLoggingFetch("TestProvider")
const buffer = new ArrayBuffer(16)
await loggingFetch("https://api.example.com/test", {
method: "POST",
body: buffer,
})
expect(consoleSpy).toHaveBeenCalledWith(
"[TestProvider] RAW HTTP REQUEST",
expect.objectContaining({
body: "[ArrayBuffer: 16 bytes]",
}),
)
})
it("should handle FormData body with placeholder", async () => {
const loggingFetch = createLoggingFetch("TestProvider")
const formData = new FormData()
formData.append("field", "value")
await loggingFetch("https://api.example.com/test", {
method: "POST",
body: formData,
})
expect(consoleSpy).toHaveBeenCalledWith(
"[TestProvider] RAW HTTP REQUEST",
expect.objectContaining({
body: "[FormData]",
}),
)
})
it("should handle undefined body", async () => {
const loggingFetch = createLoggingFetch("TestProvider")
await loggingFetch("https://api.example.com/test", {
method: "GET",
})
expect(consoleSpy).toHaveBeenCalledWith(
"[TestProvider] RAW HTTP REQUEST",
expect.objectContaining({
body: undefined,
}),
)
})
it("should handle null body", async () => {
const loggingFetch = createLoggingFetch("TestProvider")
await loggingFetch("https://api.example.com/test", {
method: "POST",
body: null,
})
expect(consoleSpy).toHaveBeenCalledWith(
"[TestProvider] RAW HTTP REQUEST",
expect.objectContaining({
body: undefined,
}),
)
})
})
describe("when logging is disabled", () => {
it("should not log requests or responses", async () => {
vi.mocked(envConfig.isLoggingEnabled).mockReturnValue(false)
const loggingFetch = createLoggingFetch("TestProvider")
await loggingFetch("https://api.example.com/test", {
method: "POST",
body: JSON.stringify({ test: true }),
})
expect(consoleSpy).not.toHaveBeenCalled()
})
})
describe("header sanitization", () => {
beforeEach(() => {
vi.mocked(envConfig.isLoggingEnabled).mockReturnValue(true)
})
it("should mask authorization header values", async () => {
const loggingFetch = createLoggingFetch("TestProvider")
await loggingFetch("https://api.example.com/test", {
method: "GET",
headers: {
Authorization: "Bearer sk-1234567890abcdef",
},
})
expect(consoleSpy).toHaveBeenCalledWith(
"[TestProvider] RAW HTTP REQUEST",
expect.objectContaining({
headers: expect.objectContaining({
Authorization: "Bear...cdef",
}),
}),
)
})
it("should mask x-api-key header values", async () => {
const loggingFetch = createLoggingFetch("TestProvider")
await loggingFetch("https://api.example.com/test", {
method: "GET",
headers: {
"x-api-key": "api-key-12345678",
},
})
expect(consoleSpy).toHaveBeenCalledWith(
"[TestProvider] RAW HTTP REQUEST",
expect.objectContaining({
headers: expect.objectContaining({
"x-api-key": "api-...5678",
}),
}),
)
})
})
describe("response handling", () => {
beforeEach(() => {
vi.mocked(envConfig.isLoggingEnabled).mockReturnValue(true)
})
it("should log streaming responses without body", async () => {
mockFetch.mockResolvedValueOnce(
new Response("data: test\n\n", {
status: 200,
statusText: "OK",
headers: { "content-type": "text/event-stream" },
}),
)
const loggingFetch = createLoggingFetch("TestProvider")
await loggingFetch("https://api.example.com/stream")
expect(consoleSpy).toHaveBeenCalledWith(
"[TestProvider] RAW HTTP RESPONSE",
expect.objectContaining({
status: 200,
streaming: true,
}),
)
})
it("should log non-streaming responses with body", async () => {
const loggingFetch = createLoggingFetch("TestProvider")
await loggingFetch("https://api.example.com/test")
expect(consoleSpy).toHaveBeenCalledWith(
"[TestProvider] RAW HTTP RESPONSE",
expect.objectContaining({
status: 200,
body: { result: "success" },
}),
)
})
})
})

View file

@ -179,6 +179,54 @@ describe("withLogging", () => {
)
})
it("should count tool_call_partial chunks without overcounting", async () => {
// Simulates streaming tool calls with multiple partial chunks per tool
const chunks: ApiStreamChunk[] = [
// First tool call (index 0) - multiple partials
{ type: "tool_call_partial", index: 0, id: "call1", name: "read_file" },
{ type: "tool_call_partial", index: 0, arguments: '{"path":' },
{ type: "tool_call_partial", index: 0, arguments: '"/src/file.ts"}' },
// Second tool call (index 1) - multiple partials
{ type: "tool_call_partial", index: 1, id: "call2", name: "write_file" },
{ type: "tool_call_partial", index: 1, arguments: '{"path":' },
{ type: "tool_call_partial", index: 1, arguments: '"/src/new.ts",' },
{ type: "tool_call_partial", index: 1, arguments: '"content":"hello"}' },
]
const stream = withLogging({ context: baseContext, request: baseRequest }, () => createMockStream(chunks))
await collectStream(stream)
// Should count only 2 unique tool calls (by index), not 7 partial chunks
expect(ApiLogger.logResponse).toHaveBeenCalledWith(
"mock-request-id",
baseContext,
expect.objectContaining({ toolCallCount: 2 }),
)
})
it("should count single tool_call_partial chunk correctly", async () => {
const chunks: ApiStreamChunk[] = [
{
type: "tool_call_partial",
index: 0,
id: "call1",
name: "read_file",
arguments: '{"path":"/file.ts"}',
},
]
const stream = withLogging({ context: baseContext, request: baseRequest }, () => createMockStream(chunks))
await collectStream(stream)
expect(ApiLogger.logResponse).toHaveBeenCalledWith(
"mock-request-id",
baseContext,
expect.objectContaining({ toolCallCount: 1 }),
)
})
it("should capture usage metrics from usage chunk", async () => {
const chunks: ApiStreamChunk[] = [
{ type: "text", text: "Response" },

View file

@ -31,15 +31,48 @@ function sanitizeHeaders(headers: Record<string, string>): Record<string, string
}
/**
* Parse body as JSON if possible, otherwise return as-is
* Parse body as JSON if possible, otherwise return as-is.
* Only processes string and URLSearchParams bodies; returns a placeholder
* for binary types (Blob, ArrayBuffer, FormData) to avoid misleading output.
*/
function parseBodyIfJson(body: BodyInit | string): unknown {
try {
const bodyStr = typeof body === "string" ? body : body.toString()
return JSON.parse(bodyStr)
} catch {
return body
function parseBodyIfJson(body: BodyInit | null | undefined): unknown {
if (body === null || body === undefined) {
return undefined
}
// Handle string bodies directly
if (typeof body === "string") {
try {
return JSON.parse(body)
} catch {
return body
}
}
// URLSearchParams can be safely converted to string
if (body instanceof URLSearchParams) {
return body.toString()
}
// For binary types, return a placeholder to avoid misleading output
if (body instanceof Blob) {
return `[Blob: ${body.size} bytes, type: ${body.type || "unknown"}]`
}
if (body instanceof ArrayBuffer) {
return `[ArrayBuffer: ${body.byteLength} bytes]`
}
if (typeof FormData !== "undefined" && body instanceof FormData) {
return "[FormData]"
}
if (typeof ReadableStream !== "undefined" && body instanceof ReadableStream) {
return "[ReadableStream]"
}
// For any other type (e.g., BufferSource), return a generic placeholder
return "[non-string body]"
}
/**

View file

@ -47,6 +47,8 @@ export async function* withLogging(options: WithLoggingOptions, generator: () =>
let reasoningLength = 0
let toolCallCount = 0
let usage: ApiStreamUsageChunk | undefined
// Track seen tool_call_partial indices to avoid overcounting
const seenToolCallPartialIndices = new Set<number>()
try {
for await (const chunk of generator()) {
@ -62,6 +64,13 @@ export async function* withLogging(options: WithLoggingOptions, generator: () =>
case "tool_call_start":
toolCallCount++
break
case "tool_call_partial":
// Count each unique tool call only once using index
if (!seenToolCallPartialIndices.has(chunk.index)) {
seenToolCallPartialIndices.add(chunk.index)
toolCallCount++
}
break
case "usage":
usage = chunk
break

View file

@ -1,7 +1,11 @@
// npx vitest run src/api/providers/__tests__/vertex.spec.ts
// Mock vscode first to avoid import errors
vitest.mock("vscode", () => ({}))
vitest.mock("vscode", () => ({
workspace: {
workspaceFolders: undefined,
},
}))
import { Anthropic } from "@anthropic-ai/sdk"