From 983bdd60c7a0de1c6170407d1f4c3b9a46464de9 Mon Sep 17 00:00:00 2001 From: Joe Cheng Date: Tue, 18 Aug 2026 16:54:24 -0400 Subject: [PATCH 1/2] Add opt-in raw HTTP request/response logging MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit A fetch wrapper (raw-http-logging.ts) that captures byte-faithful .http request/response pairs for wire-level debugging of provider rejections, unlike the AI SDK-structured JsonRequestLogger view. Opt-in and dynamic: active while the configured raw-http/ directory exists (late binding, checked per chat call — mkdir mid-session to enable), or always-on via PA_RAW_HTTP_LOG_DIR. Credential-bearing header values are redacted; bodies are always byte-for-byte. All logging errors are swallowed so capture can never break a request. Wired into every AI SDK-backed model client (OpenAI, Anthropic, DeepSeek, Gemini, Vertex, Ollama, OpenRouter, Posit AI, Snowflake, Bedrock), composing with existing custom-fetch wrappers. --- packages/ai-provider-bridge/src/index.ts | 3 + .../src/model-clients/AnthropicClient.ts | 6 + .../src/model-clients/BedrockClient.ts | 8 + .../src/model-clients/DeepSeekClient.ts | 13 +- .../src/model-clients/GeminiClient.ts | 6 + .../src/model-clients/GoogleVertexClient.ts | 8 + .../src/model-clients/OllamaClient.ts | 10 +- .../src/model-clients/OpenAIClient.ts | 4 +- .../src/model-clients/OpenRouterClient.ts | 6 + .../src/model-clients/PositAiClient.ts | 10 +- .../src/model-clients/SnowflakeClient.ts | 24 +- .../__tests__/raw-http-logging.test.ts | 243 +++++++++++++ .../src/model-clients/raw-http-logging.ts | 331 ++++++++++++++++++ 13 files changed, 661 insertions(+), 11 deletions(-) create mode 100644 packages/ai-provider-bridge/src/model-clients/__tests__/raw-http-logging.test.ts create mode 100644 packages/ai-provider-bridge/src/model-clients/raw-http-logging.ts diff --git a/packages/ai-provider-bridge/src/index.ts b/packages/ai-provider-bridge/src/index.ts index 48f0245..061decb 100644 --- a/packages/ai-provider-bridge/src/index.ts +++ b/packages/ai-provider-bridge/src/index.ts @@ -50,6 +50,9 @@ export type { LanguageModelUsage, ModelMessage } from "ai"; // StepLogger interface export type { StepLogData, StepLogger } from "./StepLogger"; +// Raw HTTP request/response logging (opt-in dev feature) +export { configureRawHttpLogging, withRawHttpLogging } from "./model-clients/raw-http-logging"; + // CredentialProvider interface export type { CredentialProvider, Disposable } from "./CredentialProvider"; diff --git a/packages/ai-provider-bridge/src/model-clients/AnthropicClient.ts b/packages/ai-provider-bridge/src/model-clients/AnthropicClient.ts index f727d13..d80c976 100644 --- a/packages/ai-provider-bridge/src/model-clients/AnthropicClient.ts +++ b/packages/ai-provider-bridge/src/model-clients/AnthropicClient.ts @@ -21,6 +21,7 @@ import { suppressAiSdkDefaultErrorLogging, } from "./ai-sdk-helpers"; import type { ModelClient, ModelClientChatParams } from "./ModelClient"; +import { withRawHttpLogging } from "./raw-http-logging"; /** Maximum number of web searches per request */ const WEB_SEARCH_MAX_USES = 5; @@ -67,9 +68,14 @@ export class AnthropicClient implements ModelClient { // (see base-url.ts), not here. const effectiveBaseUrl = params.baseUrl ?? this.baseURL; const headers = safeSdkCustomHeaders(this.customHeaders); + const loggedFetch = withRawHttpLogging(undefined, { + provider: "anthropic", + model: params.model, + }); const provider = createAnthropic({ ...anthropicAuthSettings(this.auth), ...(effectiveBaseUrl && { baseURL: effectiveBaseUrl }), + ...(loggedFetch && { fetch: loggedFetch }), ...(headers && { headers }), }); const model = provider(params.model); diff --git a/packages/ai-provider-bridge/src/model-clients/BedrockClient.ts b/packages/ai-provider-bridge/src/model-clients/BedrockClient.ts index 620a4e9..23b4c22 100644 --- a/packages/ai-provider-bridge/src/model-clients/BedrockClient.ts +++ b/packages/ai-provider-bridge/src/model-clients/BedrockClient.ts @@ -34,6 +34,7 @@ import { } from "./ai-sdk-helpers"; import type { ModelClient, ModelClientChatParams } from "./ModelClient"; import { prepareExplicitOpenAIRequest } from "./openai-prompt-caching"; +import { withRawHttpLogging } from "./raw-http-logging"; const EXPLICIT_PROMPT_CACHE_OPTIONS: { mode: "explicit"; ttl: "30m" } = { mode: "explicit", @@ -251,6 +252,10 @@ export class BedrockClient implements ModelClient { ): LanguageModelV3 { const credentialProvider = createAwsCredentialProvider(this.config); const headers = safeSdkCustomHeaders(this.config.customHeaders); + const loggedFetch = withRawHttpLogging(undefined, { + provider: "bedrock", + model: modelId, + }); if (protocol === "openai-chat" || protocol === "openai-responses") { if (!transport.mantleEnabled) { @@ -266,6 +271,7 @@ export class BedrockClient implements ModelClient { // Enforce the AWS-credentials-only contract. Without this explicit // opt-out, a stale AWS_BEARER_TOKEN_BEDROCK overrides SigV4. apiKey: "", + ...(loggedFetch && { fetch: loggedFetch }), }); return protocol === "openai-chat" ? mantle.chat(modelId) : mantle.responses(modelId); } @@ -292,6 +298,7 @@ export class BedrockClient implements ModelClient { baseURL: baseUrl ?? transport.runtimeBaseUrl, headers, credentialProvider, + ...(loggedFetch && { fetch: loggedFetch }), })(modelId); } @@ -300,6 +307,7 @@ export class BedrockClient implements ModelClient { baseURL: baseUrl ?? transport.runtimeBaseUrl, headers, credentialProvider, + ...(loggedFetch && { fetch: loggedFetch }), })(modelId); } } diff --git a/packages/ai-provider-bridge/src/model-clients/DeepSeekClient.ts b/packages/ai-provider-bridge/src/model-clients/DeepSeekClient.ts index 7600190..58e19fa 100644 --- a/packages/ai-provider-bridge/src/model-clients/DeepSeekClient.ts +++ b/packages/ai-provider-bridge/src/model-clients/DeepSeekClient.ts @@ -14,6 +14,7 @@ import { createStepLogger, } from "./ai-sdk-helpers"; import type { ModelClient, ModelClientChatParams } from "./ModelClient"; +import { withRawHttpLogging } from "./raw-http-logging"; /** Map our thinking effort string to DeepSeek's reasoning_effort parameter. */ function mapReasoningEffort(effort: string): string { @@ -66,12 +67,18 @@ export class DeepSeekClient implements ModelClient { const thinkingOn = isThinkingEnabled(params.thinkingEffort); const headers = safeSdkCustomHeaders(this.customHeaders); + const baseFetch = thinkingOn + ? createFetchWithReasoningEffort(params.thinkingEffort!) + : undefined; + const loggedFetch = withRawHttpLogging(baseFetch, { + provider: "deepseek", + model: params.model, + }); + const effectiveFetch = loggedFetch ?? baseFetch; const provider = createDeepSeek({ apiKey: this.apiKey, ...(effectiveBaseUrl && { baseURL: effectiveBaseUrl }), - ...(thinkingOn && { - fetch: createFetchWithReasoningEffort(params.thinkingEffort!), - }), + ...(effectiveFetch && { fetch: effectiveFetch }), ...(headers && { headers }), }); diff --git a/packages/ai-provider-bridge/src/model-clients/GeminiClient.ts b/packages/ai-provider-bridge/src/model-clients/GeminiClient.ts index 68ea521..4461d02 100644 --- a/packages/ai-provider-bridge/src/model-clients/GeminiClient.ts +++ b/packages/ai-provider-bridge/src/model-clients/GeminiClient.ts @@ -26,6 +26,7 @@ import { createStepLogger, } from "./ai-sdk-helpers"; import type { ModelClient, ModelClientChatParams } from "./ModelClient"; +import { withRawHttpLogging } from "./raw-http-logging"; // --------------------------------------------------------------------------- // Interaction ID extraction (compaction-aware) @@ -343,9 +344,14 @@ export class GeminiClient implements ModelClient { // correction happens at the config seam (see base-url.ts), not here. const effectiveBaseUrl = params.baseUrl ?? this.baseURL; const headers = safeSdkCustomHeaders(this.customHeaders); + const loggedFetch = withRawHttpLogging(undefined, { + provider: "gemini", + model: params.model, + }); const provider = createGoogleGenerativeAI({ apiKey: this.apiKey, ...(effectiveBaseUrl && { baseURL: effectiveBaseUrl }), + ...(loggedFetch && { fetch: loggedFetch }), ...(headers && { headers }), }); diff --git a/packages/ai-provider-bridge/src/model-clients/GoogleVertexClient.ts b/packages/ai-provider-bridge/src/model-clients/GoogleVertexClient.ts index f7802c2..58190e2 100644 --- a/packages/ai-provider-bridge/src/model-clients/GoogleVertexClient.ts +++ b/packages/ai-provider-bridge/src/model-clients/GoogleVertexClient.ts @@ -26,6 +26,7 @@ import { createStepLogger, } from "./ai-sdk-helpers"; import type { ModelClient, ModelClientChatParams } from "./ModelClient"; +import { withRawHttpLogging } from "./raw-http-logging"; /** * Check if a Vertex model ID refers to an Anthropic partner model. @@ -160,11 +161,17 @@ export class GoogleVertexClient implements ModelClient { ? "global" : getEffectiveLocation(modelId, this.config.location); + const loggedFetch = withRawHttpLogging(undefined, { + provider: "google-vertex", + model: modelId, + }); + if (useAnthropicApi) { return createVertexAnthropic({ project: this.config.project, location, googleAuthOptions, + ...(loggedFetch && { fetch: loggedFetch }), })(modelId); } @@ -172,6 +179,7 @@ export class GoogleVertexClient implements ModelClient { project: this.config.project, location, googleAuthOptions, + ...(loggedFetch && { fetch: loggedFetch }), })(modelId); } } diff --git a/packages/ai-provider-bridge/src/model-clients/OllamaClient.ts b/packages/ai-provider-bridge/src/model-clients/OllamaClient.ts index 0f59ee1..f7bed45 100644 --- a/packages/ai-provider-bridge/src/model-clients/OllamaClient.ts +++ b/packages/ai-provider-bridge/src/model-clients/OllamaClient.ts @@ -25,6 +25,7 @@ import { createStepLogger, } from "./ai-sdk-helpers"; import type { ModelClient, ModelClientChatParams } from "./ModelClient"; +import { withRawHttpLogging } from "./raw-http-logging"; /** The `think` parameter type accepted by Ollama's native API. */ type OllamaThinkParam = boolean | "low" | "medium" | "high"; @@ -69,7 +70,14 @@ export class OllamaClient implements ModelClient { async chat(params: ModelClientChatParams): Promise> { // Create Ollama provider pointing at the server root const effectiveBaseUrl = params.baseUrl ?? this.endpoint; - const provider = createOllama({ baseURL: effectiveBaseUrl }); + const loggedFetch = withRawHttpLogging(undefined, { + provider: "ollama", + model: params.model, + }); + const provider = createOllama({ + baseURL: effectiveBaseUrl, + ...(loggedFetch && { fetch: loggedFetch }), + }); // Build model settings const think = ollamaThinkParam(params.thinkingEffort); diff --git a/packages/ai-provider-bridge/src/model-clients/OpenAIClient.ts b/packages/ai-provider-bridge/src/model-clients/OpenAIClient.ts index 45638de..de99358 100644 --- a/packages/ai-provider-bridge/src/model-clients/OpenAIClient.ts +++ b/packages/ai-provider-bridge/src/model-clients/OpenAIClient.ts @@ -27,6 +27,7 @@ import { } from "./ai-sdk-helpers"; import type { ModelClient, ModelClientChatParams } from "./ModelClient"; import { prepareExplicitOpenAIRequest } from "./openai-prompt-caching"; +import { withRawHttpLogging } from "./raw-http-logging"; export type OpenAIApiMode = "completions" | "responses"; @@ -102,10 +103,11 @@ export class OpenAIClient implements ModelClient { } : undefined); const headers = safeSdkCustomHeaders(this.customHeaders); + const loggedFetch = withRawHttpLogging(fetchFn, { provider: "openai", model: params.model }); const provider = createOpenAI({ apiKey: isEmptyKey ? "sk-placeholder" : this.apiKey, ...(effectiveBaseUrl && { baseURL: effectiveBaseUrl }), - ...(fetchFn && { fetch: fetchFn }), + ...((loggedFetch ?? fetchFn) && { fetch: loggedFetch ?? fetchFn }), ...(headers && { headers }), }); const model = diff --git a/packages/ai-provider-bridge/src/model-clients/OpenRouterClient.ts b/packages/ai-provider-bridge/src/model-clients/OpenRouterClient.ts index 635c4e9..e9d5453 100644 --- a/packages/ai-provider-bridge/src/model-clients/OpenRouterClient.ts +++ b/packages/ai-provider-bridge/src/model-clients/OpenRouterClient.ts @@ -15,6 +15,7 @@ import { suppressAiSdkDefaultErrorLogging, } from "./ai-sdk-helpers"; import type { ModelClient, ModelClientChatParams } from "./ModelClient"; +import { withRawHttpLogging } from "./raw-http-logging"; type OpenRouterReasoningSettings = { effort: "high" | "medium" | "low" | "none" }; const OPENROUTER_DEFAULT_BASE_URL = "https://openrouter.ai/api/v1"; @@ -53,11 +54,16 @@ export class OpenRouterClient implements ModelClient { async chat(params: ModelClientChatParams): Promise> { const headers = safeSdkCustomHeaders(this.customHeaders); + const loggedFetch = withRawHttpLogging(undefined, { + provider: "openrouter", + model: params.model, + }); const provider = createOpenRouter({ apiKey: this.apiKey, baseURL: this.baseURL, appName: "Posit Assistant", appUrl: "https://posit.co", + ...(loggedFetch && { fetch: loggedFetch }), ...(headers && { headers }), }); diff --git a/packages/ai-provider-bridge/src/model-clients/PositAiClient.ts b/packages/ai-provider-bridge/src/model-clients/PositAiClient.ts index 45a5400..b9f5240 100644 --- a/packages/ai-provider-bridge/src/model-clients/PositAiClient.ts +++ b/packages/ai-provider-bridge/src/model-clients/PositAiClient.ts @@ -37,6 +37,7 @@ import { createStepLogger, } from "./ai-sdk-helpers"; import type { ModelClient, ModelClientChatParams } from "./ModelClient"; +import { withRawHttpLogging } from "./raw-http-logging"; /** * Custom fetch wrapper that replaces x-api-key header with Authorization: Bearer @@ -184,6 +185,11 @@ export class PositAiClient implements ModelClient { onCreditsDepleted, onAgreementRequired, ); + // Raw HTTP logging wraps the authenticated fetch so the log reflects the + // final wire request (auth headers are redacted in the log files). + const loggedFetch = + withRawHttpLogging(authenticatedFetch, { provider: "positai", model: params.model }) ?? + authenticatedFetch; // Create abort controller with cleanup to prevent EventEmitter memory leaks const { abortController, cleanup } = createAbortControllerFromToken(params.cancellationToken); @@ -205,7 +211,7 @@ export class PositAiClient implements ModelClient { const provider = createAnthropic({ apiKey: this.accessToken, // Required for SDK initialization, not used in header baseURL: joinPath(effectiveBaseUrl, "/anthropic/v1"), - fetch: authenticatedFetch, + fetch: loggedFetch, }); const model = provider(params.model); @@ -248,7 +254,7 @@ export class PositAiClient implements ModelClient { const provider = createOpenAICompatible({ name: "positai", baseURL: joinPath(effectiveBaseUrl, "/openai/v1"), - fetch: authenticatedFetch, + fetch: loggedFetch, ...(thinkingFields && { transformRequestBody: (body: Record) => ({ ...body, diff --git a/packages/ai-provider-bridge/src/model-clients/SnowflakeClient.ts b/packages/ai-provider-bridge/src/model-clients/SnowflakeClient.ts index 6d01186..0a9219f 100644 --- a/packages/ai-provider-bridge/src/model-clients/SnowflakeClient.ts +++ b/packages/ai-provider-bridge/src/model-clients/SnowflakeClient.ts @@ -27,6 +27,7 @@ import { } from "./ai-sdk-helpers"; import type { ModelClient, ModelClientChatParams } from "./ModelClient"; import { createOpenAICompatibleFetch } from "./openai-compat-fetch"; +import { withRawHttpLogging } from "./raw-http-logging"; /** * How the credential's token authenticates with Snowflake Cortex: @@ -224,18 +225,27 @@ export class SnowflakeClient implements ModelClient { baseUrl: string, ): Promise> { const headers = safeSdkCustomHeaders(this.customHeaders); + const baseFetch = this.isSessionAuth + ? createSnowflakeSessionFetch(this.token, globalThis.fetch, this.sessionRefresh) + : undefined; + const loggedFetch = withRawHttpLogging(baseFetch, { + provider: "snowflake-cortex", + model: params.model, + }); + const effectiveFetch = loggedFetch ?? baseFetch; const provider = this.isSessionAuth ? createAnthropic({ // Auth is applied by the session fetch wrapper; this placeholder key // just satisfies the SDK (its x-api-key header is stripped there). apiKey: "session-auth", baseURL: baseUrl, - fetch: createSnowflakeSessionFetch(this.token, globalThis.fetch, this.sessionRefresh), + ...(effectiveFetch && { fetch: effectiveFetch }), ...(headers && { headers }), }) : createAnthropic({ authToken: this.token, baseURL: baseUrl, + ...(effectiveFetch && { fetch: effectiveFetch }), ...(headers && { headers }), }); const model = provider(params.model); @@ -297,12 +307,18 @@ export class SnowflakeClient implements ModelClient { const compatFetch = this.isSessionAuth ? createOpenAICompatibleFetch("Snowflake", "session-auth", this.customHeaders) : createOpenAICompatibleFetch("Snowflake", this.token, this.customHeaders); + const baseFetch = this.isSessionAuth + ? createSnowflakeSessionFetch(this.token, compatFetch, this.sessionRefresh) + : compatFetch; + const loggedFetch = + withRawHttpLogging(baseFetch, { + provider: "snowflake-cortex", + model: params.model, + }) ?? baseFetch; const provider = createOpenAI({ apiKey: this.token || "sk-placeholder", baseURL: baseUrl, - fetch: this.isSessionAuth - ? createSnowflakeSessionFetch(this.token, compatFetch, this.sessionRefresh) - : compatFetch, + fetch: loggedFetch, }); const model = provider.chat(params.model); diff --git a/packages/ai-provider-bridge/src/model-clients/__tests__/raw-http-logging.test.ts b/packages/ai-provider-bridge/src/model-clients/__tests__/raw-http-logging.test.ts new file mode 100644 index 0000000..71ddf14 --- /dev/null +++ b/packages/ai-provider-bridge/src/model-clients/__tests__/raw-http-logging.test.ts @@ -0,0 +1,243 @@ +/*--------------------------------------------------------------------------------------------- + * Copyright (C) 2026 Posit Software, PBC. All rights reserved. + *--------------------------------------------------------------------------------------------*/ + +import { mkdirSync, mkdtempSync, readFileSync, readdirSync, rmSync, writeFileSync } from "node:fs"; +import { tmpdir } from "node:os"; +import { join } from "node:path"; + +import { afterEach, beforeEach, describe, expect, it } from "vitest"; + +import { + configureRawHttpLogging, + resetRawHttpLoggingForTests, + withRawHttpLogging, +} from "../raw-http-logging"; + +const ENV_VAR = "PA_RAW_HTTP_LOG_DIR"; + +let workDir: string; + +beforeEach(() => { + workDir = mkdtempSync(join(tmpdir(), "raw-http-logging-test-")); +}); + +afterEach(() => { + resetRawHttpLoggingForTests(); + delete process.env[ENV_VAR]; + rmSync(workDir, { recursive: true, force: true }); +}); + +function listFiles(dir: string): string[] { + return readdirSync(dir).sort(); +} + +function readPair(dir: string): { request: Buffer; response: Buffer } { + const files = listFiles(dir); + const requestFile = files.find((f) => f.endsWith("-request.http")); + const responseFile = files.find((f) => f.endsWith("-response.http")); + if (!requestFile || !responseFile) { + throw new Error(`Expected request/response pair, found: ${files.join(", ")}`); + } + // Pair must share a base name. + expect(requestFile.replace("-request.http", "")).toBe(responseFile.replace("-response.http", "")); + return { + request: readFileSync(join(dir, requestFile)), + response: readFileSync(join(dir, responseFile)), + }; +} + +/** Split a raw .http log file into header section text and body bytes. */ +function splitMessage(contents: Buffer): { head: string; body: Buffer } { + const separator = contents.indexOf("\n\n"); + expect(separator).toBeGreaterThan(-1); + return { + head: contents.subarray(0, separator).toString("utf8"), + body: contents.subarray(separator + 2), + }; +} + +function sseStream(chunks: string[]): ReadableStream { + const encoder = new TextEncoder(); + return new ReadableStream({ + start(controller) { + for (const chunk of chunks) { + controller.enqueue(encoder.encode(chunk)); + } + controller.close(); + }, + }); +} + +function fakeSseFetch(chunks: string[]): typeof globalThis.fetch { + return async () => + new Response(sseStream(chunks), { + status: 200, + headers: { + "content-type": "text/event-stream", + "anthropic-ratelimit-tokens-remaining": "19999", + }, + }); +} + +async function settle(): Promise { + // Allow background file writes to complete. + for (let i = 0; i < 50; i++) { + await new Promise((resolve) => setTimeout(resolve, 10)); + } +} + +describe("withRawHttpLogging", () => { + it("returns undefined when disabled (no env var, no configured dir)", () => { + expect(withRawHttpLogging(undefined, { provider: "test", model: "m" })).toBeUndefined(); + }); + + it("returns undefined when the configured dir does not exist", () => { + configureRawHttpLogging({ outputDir: join(workDir, "does-not-exist") }); + expect(withRawHttpLogging(undefined, { provider: "test", model: "m" })).toBeUndefined(); + }); + + it("enables when the configured dir exists (late binding)", () => { + const logDir = join(workDir, "raw-http"); + configureRawHttpLogging({ outputDir: logDir }); + expect(withRawHttpLogging(undefined, { provider: "test", model: "m" })).toBeUndefined(); + mkdirSync(logDir); + expect(withRawHttpLogging(undefined, { provider: "test", model: "m" })).toBeDefined(); + }); + + it("env var enables logging and auto-creates the directory", () => { + const logDir = join(workDir, "env-logs"); + process.env[ENV_VAR] = logDir; + const wrapped = withRawHttpLogging(undefined, { provider: "test", model: "m" }); + expect(wrapped).toBeDefined(); + }); + + it("env var wins over a missing configured dir", () => { + configureRawHttpLogging({ outputDir: join(workDir, "nope") }); + process.env[ENV_VAR] = join(workDir, "env-logs"); + expect(withRawHttpLogging(undefined, { provider: "test", model: "m" })).toBeDefined(); + }); + + it("writes request and response files with byte-identical bodies", async () => { + process.env[ENV_VAR] = workDir; + const requestBody = JSON.stringify({ prompt: "héllo wörld ✨", n: 1 }); + const sseChunks = [ + 'data: {"delta":"héllo"}\n\n', + 'data: {"delta":" wörld ✨"}\n\n', + "data: [DONE]\n\n", + ]; + const wrapped = withRawHttpLogging(fakeSseFetch(sseChunks), { + provider: "test-provider", + model: "test/model:1", + }); + expect(wrapped).toBeDefined(); + + const response = await wrapped!("https://api.example.com/v1/chat?x=1", { + method: "POST", + headers: { + "content-type": "application/json", + authorization: "Bearer sk-secret-key", + "x-api-key": "another-secret", + }, + body: requestBody, + }); + // Consume the SDK-visible stream. + const seenByConsumer = Buffer.from(await response.arrayBuffer()); + await settle(); + + const { request, response: responseFile } = readPair(workDir); + + // Request: well-formed head, byte-identical body. + const req = splitMessage(request); + expect(req.head).toContain("POST /v1/chat?x=1 HTTP/1.1"); + expect(req.head).toContain("host: api.example.com"); + expect(req.head).toContain("content-type: application/json"); + expect(req.body.equals(Buffer.from(requestBody, "utf8"))).toBe(true); + + // Response: byte-identical reassembled SSE body. + const res = splitMessage(responseFile); + expect(res.head).toContain("HTTP/1.1 200"); + expect(res.body.equals(Buffer.from(sseChunks.join(""), "utf8"))).toBe(true); + + // The consumer saw the same bytes that were logged. + expect(seenByConsumer.equals(Buffer.from(sseChunks.join(""), "utf8"))).toBe(true); + }); + + it("redacts credential-bearing headers but not other headers or the body", async () => { + process.env[ENV_VAR] = workDir; + const wrapped = withRawHttpLogging(fakeSseFetch(["data: [DONE]\n\n"]), { + provider: "test", + model: "m", + }); + const response = await wrapped!("https://api.example.com/v1/chat", { + method: "POST", + headers: { + authorization: "Bearer sk-secret", + "x-api-key": "secret2", + "x-custom-auth-token": "secret3", + "content-type": "application/json", + }, + body: "sk-secret stays in the body verbatim", + }); + await response.arrayBuffer(); + await settle(); + + const { head } = splitMessage(readPair(workDir).request); + expect(head).toContain("authorization: [REDACTED]"); + expect(head).toContain("x-api-key: [REDACTED]"); + expect(head).toContain("x-custom-auth-token: [REDACTED]"); + expect(head).toContain("content-type: application/json"); + expect(head).not.toContain("sk-secret"); + + // Rate-limit style headers mentioning "tokens" are not credentials. + const resHead = splitMessage(readPair(workDir).response).head; + expect(resHead).toContain("content-type: text/event-stream"); + expect(resHead).toContain("anthropic-ratelimit-tokens-remaining: 19999"); + + // Bodies are never redacted. + const { body } = splitMessage(readPair(workDir).request); + expect(body.toString("utf8")).toBe("sk-secret stays in the body verbatim"); + }); + + it("sanitizes provider/model for file names", async () => { + process.env[ENV_VAR] = workDir; + const wrapped = withRawHttpLogging(fakeSseFetch(["data: [DONE]\n\n"]), { + provider: "my provider", + model: "a/b:c", + }); + const response = await wrapped!("https://api.example.com/", { method: "POST", body: "{}" }); + await response.arrayBuffer(); + await settle(); + + const files = listFiles(workDir); + expect(files.some((f) => f.includes("my-provider") && f.includes("a-b-c"))).toBe(true); + }); + + it("writes a response file with an error marker when fetch throws", async () => { + process.env[ENV_VAR] = workDir; + const failing: typeof globalThis.fetch = async () => { + throw new Error("connection refused"); + }; + const wrapped = withRawHttpLogging(failing, { provider: "test", model: "m" }); + await expect( + wrapped!("https://api.example.com/", { method: "POST", body: "{}" }), + ).rejects.toThrow("connection refused"); + await settle(); + + const files = listFiles(workDir); + const responseFile = files.find((f) => f.endsWith("-response.http")); + expect(responseFile).toBeDefined(); + expect(readFileSync(join(workDir, responseFile!), "utf8")).toContain( + "[error: connection refused]", + ); + }); + + it("survives logging failures without breaking the response", async () => { + // Point the env var at a path that cannot be created (a file blocks it). + const blocker = join(workDir, "blocker"); + writeFileSync(blocker, "x"); + process.env[ENV_VAR] = join(blocker, "impossible"); + // mkdirSync fails → wrapper disabled entirely. + expect(withRawHttpLogging(undefined, { provider: "test", model: "m" })).toBeUndefined(); + }); +}); diff --git a/packages/ai-provider-bridge/src/model-clients/raw-http-logging.ts b/packages/ai-provider-bridge/src/model-clients/raw-http-logging.ts new file mode 100644 index 0000000..709bb29 --- /dev/null +++ b/packages/ai-provider-bridge/src/model-clients/raw-http-logging.ts @@ -0,0 +1,331 @@ +/*--------------------------------------------------------------------------------------------- + * Copyright (C) 2026 Posit Software, PBC. All rights reserved. + *--------------------------------------------------------------------------------------------*/ + +/** + * Raw HTTP request/response logging + * + * A fetch wrapper that captures the exact bytes sent to and received from an + * LLM provider, for debugging wire-level problems (e.g. a provider rejecting a + * request as invalid) where the AI SDK's structured request/response view + * (JsonRequestLogger) hides the actual wire format. + * + * Opt-in, two mechanisms: + * + * 1. Late-binding directory: `configureRawHttpLogging({ outputDir })` is called + * once at startup by @assistant/node with the platform log dir. Logging is + * active only while that directory exists on disk — a developer enables it + * mid-session with `mkdir -p ` and disables it by removing the dir. + * 2. Explicit override: the `PA_RAW_HTTP_LOG_DIR` environment variable. When + * set, the directory is created automatically and logging is always on. + * + * Output: two files per HTTP call sharing a `{timestamp}-{provider}-{model}-{seq}` + * base name: + * + * - `...-request.http`: request line, headers (best-effort reconstruction; the + * Fetch API hides exact wire order/casing), blank line, then the body + * byte-for-byte as sent. + * - `...-response.http`: status line, headers, blank line, then the body + * byte-for-byte as received (SSE chunks concatenated verbatim). Written when + * the body stream completes; on error, whatever bytes arrived plus an + * `[error: ...]` marker. + * + * Credential-bearing header values (authorization, api-key, token, secret, + * etc.) are replaced with `[REDACTED]`. Bodies are never modified. + * + * All logging failures are swallowed: the wrapped fetch never throws for + * logging reasons and never alters the bytes seen by the SDK. + */ + +import { existsSync, mkdirSync, writeFile } from "node:fs"; +import { join } from "node:path"; + +const ENV_VAR = "PA_RAW_HTTP_LOG_DIR"; + +/** + * Headers whose values are replaced with [REDACTED] in log files. "token" + * only matches as a trailing segment (`x-auth-token`, `session-token`) so + * rate-limit headers like `anthropic-ratelimit-tokens-remaining` survive. + */ +const SENSITIVE_HEADER_PATTERN = + /authorization|api[-_]?key|secret|x-amz-security-token|(?:^|[-_])token$/i; + +let configuredOutputDir: string | undefined; +let envDirCreated = false; +let sequence = 0; + +/** + * Register the late-binding output directory. Called once at startup by + * @assistant/node. Logging via this directory is active only while it exists + * on disk (checked per chat() call). + */ +export function configureRawHttpLogging(config: { outputDir: string }): void { + configuredOutputDir = config.outputDir; +} + +/** Test hook: reset module state between tests. */ +export function resetRawHttpLoggingForTests(): void { + configuredOutputDir = undefined; + envDirCreated = false; + sequence = 0; +} + +/** + * Resolve the active output directory for this call, or undefined if logging + * is disabled. Env var wins and is always-on; the configured dir is + * late-binding (must exist on disk). + */ +function resolveOutputDir(): string | undefined { + const envDir = process.env[ENV_VAR]; + if (envDir) { + if (!envDirCreated) { + try { + mkdirSync(envDir, { recursive: true }); + envDirCreated = true; + } catch { + return undefined; + } + } + return envDir; + } + if (configuredOutputDir && existsSync(configuredOutputDir)) { + return configuredOutputDir; + } + return undefined; +} + +/** Make a string safe for use in a file name. */ +function sanitizeForFilename(value: string): string { + return value.replace(/[^a-zA-Z0-9._-]/g, "-"); +} + +/** Filesystem-safe timestamp (colons and dots are problematic on Windows). */ +function timestamp(): string { + return new Date().toISOString().replace(/[:.]/g, "-"); +} + +function redactHeaders(headers: Headers): string[] { + const lines: string[] = []; + headers.forEach((value, name) => { + lines.push(`${name}: ${SENSITIVE_HEADER_PATTERN.test(name) ? "[REDACTED]" : value}`); + }); + return lines; +} + +/** + * Result of capturing a request body. `immediate` is set when the bytes are + * available synchronously (the common case: the AI SDK sends JSON strings). + * `pending` is set for stream bodies, where the bytes only become available + * as the underlying fetch consumes the stream. + */ +type CapturedBody = { immediate: Buffer | undefined } | { pending: Promise }; + +/** + * Best-effort extraction of the request body as raw bytes, without disturbing + * the body that will be passed to the underlying fetch. + * + * - string/Buffer/TypedArray/ArrayBuffer bodies are copied directly. + * - ReadableStream bodies are tee'd: `init.body` is replaced with one branch + * and the other is buffered in the background for the log. + * - Request-object bodies are cloned before the original is consumed. + */ +function captureRequestBody( + input: string | URL | Request, + init: RequestInit | undefined, +): CapturedBody { + const body = init?.body; + if (body === null || body === undefined) { + if (input instanceof Request && input.body !== null) { + const clone = input.clone(); + return { + pending: clone.arrayBuffer().then((buf) => Buffer.from(buf)), + }; + } + return { immediate: undefined }; + } + if (typeof body === "string") { + return { immediate: Buffer.from(body, "utf8") }; + } + if (body instanceof ArrayBuffer) { + return { immediate: Buffer.from(body) }; + } + if (ArrayBuffer.isView(body)) { + return { immediate: Buffer.from(body.buffer, body.byteOffset, body.byteLength) }; + } + if (body instanceof ReadableStream) { + const [forFetch, forLog] = body.tee(); + init!.body = forFetch; + return { + pending: (async () => { + const chunks: Buffer[] = []; + const reader = forLog.getReader(); + for (;;) { + const { done, value } = await reader.read(); + if (done) { + break; + } + chunks.push(Buffer.from(value)); + } + return Buffer.concat(chunks); + })(), + }; + } + // URLSearchParams, FormData, Blob, etc. — not produced by the AI SDK; + // skip capture rather than risk disturbing the request. + return { immediate: undefined }; +} + +function formatRequestFile( + method: string, + url: URL, + headers: Headers, + body: Buffer | undefined, +): Buffer { + const lines = [ + `${method} ${url.pathname}${url.search} HTTP/1.1`, + `host: ${url.host}`, + ...redactHeaders(headers), + "", + ]; + return Buffer.concat([Buffer.from(lines.join("\n") + "\n", "utf8"), body ?? Buffer.alloc(0)]); +} + +function formatResponseFile(response: Response, body: Buffer, error?: unknown): Buffer { + const lines = [ + `HTTP/1.1 ${response.status} ${response.statusText}`.trimEnd(), + ...redactHeaders(response.headers), + "", + ]; + const parts = [Buffer.from(lines.join("\n") + "\n", "utf8"), body]; + if (error !== undefined) { + parts.push( + Buffer.from( + `\n\n[error: ${error instanceof Error ? error.message : String(error)}]\n`, + "utf8", + ), + ); + } + return Buffer.concat(parts); +} + +function writeLogFile(outputDir: string, baseName: string, suffix: string, contents: Buffer): void { + writeFile(join(outputDir, `${baseName}-${suffix}.http`), contents, () => { + // Errors are swallowed by design: logging must never break a request. + }); +} + +/** + * Wrap a fetch implementation so every call is logged to the active raw-HTTP + * log directory. Returns undefined when logging is disabled, so callers can + * conditionally spread the result into provider options without changing + * behavior in the common case. + * + * @param fetchFn - The fetch the client would otherwise use (may be undefined + * to wrap the global fetch). + * @param context - Provider and model names, used in log file names. + */ +export function withRawHttpLogging( + fetchFn: typeof globalThis.fetch | undefined, + context: { provider: string; model: string }, +): typeof globalThis.fetch | undefined { + const outputDir = resolveOutputDir(); + if (!outputDir) { + return undefined; + } + const underlying = fetchFn ?? globalThis.fetch; + const provider = sanitizeForFilename(context.provider); + const model = sanitizeForFilename(context.model); + + return async (input: string | URL | Request, init?: RequestInit): Promise => { + const baseName = `${timestamp()}-${provider}-${model}-${sequence++}`; + + // Capture the request (teeing stream bodies so the SDK's bytes are + // undisturbed) and write the request file — immediately for + // already-available bodies, in the background for stream bodies. + try { + const captured = captureRequestBody(input, init); + let method = "POST"; + let url: URL | undefined; + let requestHeaders = new Headers(); + if (input instanceof Request) { + method = input.method; + url = new URL(input.url); + requestHeaders = new Headers(input.headers); + } + if (init) { + if (init.method) { + method = init.method; + } + if (init.headers) { + requestHeaders = new Headers(init.headers); + } + } + if (!url) { + url = new URL( + typeof input === "string" ? input : input instanceof URL ? input.href : input.url, + ); + } + const resolvedUrl = url; + const writeRequest = (body: Buffer | undefined) => + writeLogFile( + outputDir, + baseName, + "request", + formatRequestFile(method, resolvedUrl, requestHeaders, body), + ); + if ("pending" in captured) { + void captured.pending.then(writeRequest, () => writeRequest(undefined)); + } else { + writeRequest(captured.immediate); + } + } catch { + // Swallow: never let logging break the request. + } + + let response: Response; + try { + response = await underlying(input, init); + } catch (error) { + // Record the transport-level failure, then rethrow. + try { + writeLogFile( + outputDir, + baseName, + "response", + Buffer.from( + `HTTP/1.1 0 ERROR\n\n[error: ${error instanceof Error ? error.message : String(error)}]\n`, + "utf8", + ), + ); + } catch { + // Swallow. + } + throw error; + } + + // Tee the response body: the SDK reads the original; a background clone + // accumulates the raw bytes and writes the response file on completion. + try { + const clone = response.clone(); + void (async () => { + let body: Buffer; + let error: unknown; + try { + body = Buffer.from(await clone.arrayBuffer()); + } catch (readError) { + body = Buffer.alloc(0); + error = readError; + } + try { + writeLogFile(outputDir, baseName, "response", formatResponseFile(response, body, error)); + } catch { + // Swallow. + } + })(); + } catch { + // Swallow. + } + + return response; + }; +} From e26f47a71b29ec37b0e22b5335b099e0247645f0 Mon Sep 17 00:00:00 2001 From: Joe Cheng Date: Wed, 19 Aug 2026 11:53:58 -0400 Subject: [PATCH 2/2] Make raw-http-logging browser-bundle-safe Look up node:fs lazily via process.getBuiltinModule instead of static node: imports so the module can be bundled into the Positron webview frontend (which shares chunks with the model clients). Outside Node, logging is simply disabled. --- .../src/model-clients/raw-http-logging.ts | 24 ++++++++++++++----- 1 file changed, 18 insertions(+), 6 deletions(-) diff --git a/packages/ai-provider-bridge/src/model-clients/raw-http-logging.ts b/packages/ai-provider-bridge/src/model-clients/raw-http-logging.ts index 709bb29..167ee09 100644 --- a/packages/ai-provider-bridge/src/model-clients/raw-http-logging.ts +++ b/packages/ai-provider-bridge/src/model-clients/raw-http-logging.ts @@ -37,11 +37,19 @@ * logging reasons and never alters the bytes seen by the SDK. */ -import { existsSync, mkdirSync, writeFile } from "node:fs"; -import { join } from "node:path"; - const ENV_VAR = "PA_RAW_HTTP_LOG_DIR"; +/** + * Node builtins are looked up lazily (never imported statically) so this + * module stays bundleable for browser targets like the Positron webview + * frontend, which shares chunks with the model clients. Outside Node, + * `nodeFs` is undefined and logging is simply disabled. + */ +const nodeFs = + typeof process !== "undefined" + ? (process.getBuiltinModule?.("node:fs") as typeof import("node:fs") | undefined) + : undefined; + /** * Headers whose values are replaced with [REDACTED] in log files. "token" * only matches as a trailing segment (`x-auth-token`, `session-token`) so @@ -76,11 +84,14 @@ export function resetRawHttpLoggingForTests(): void { * late-binding (must exist on disk). */ function resolveOutputDir(): string | undefined { + if (!nodeFs || typeof process === "undefined") { + return undefined; + } const envDir = process.env[ENV_VAR]; if (envDir) { if (!envDirCreated) { try { - mkdirSync(envDir, { recursive: true }); + nodeFs.mkdirSync(envDir, { recursive: true }); envDirCreated = true; } catch { return undefined; @@ -88,7 +99,7 @@ function resolveOutputDir(): string | undefined { } return envDir; } - if (configuredOutputDir && existsSync(configuredOutputDir)) { + if (configuredOutputDir && nodeFs.existsSync(configuredOutputDir)) { return configuredOutputDir; } return undefined; @@ -209,7 +220,8 @@ function formatResponseFile(response: Response, body: Buffer, error?: unknown): } function writeLogFile(outputDir: string, baseName: string, suffix: string, contents: Buffer): void { - writeFile(join(outputDir, `${baseName}-${suffix}.http`), contents, () => { + // Forward slash works on Windows for fs calls; avoids importing node:path. + nodeFs?.writeFile(`${outputDir}/${baseName}-${suffix}.http`, contents, () => { // Errors are swallowed by design: logging must never break a request. }); }