Add opt-in raw HTTP request/response logging - #93
Conversation
|
Some feedback from
|
|
Another round of review after the fixes:
|
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.
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.
The logger previously wrapped each client's custom fetch, so it recorded SDK input rather than wire input: DeepSeek logs omitted the injected reasoning_effort, Posit AI logs preceded the final auth headers, and Snowflake logs hid session-refresh retries and captured post-normalized responses. Middleware now takes a delegate fetch and composes as SDK -> transform/auth/retry -> raw logger -> global fetch, so every physical call is logged with its final mutations, raw SSE is captured before compatibility rewrites, and each attempt of a retry gets its own request/response pair.
The previous tee-and-drain capture changed behavior of the wrapped fetch: eagerly draining response.clone() meant SDK cancellation no longer cancelled the underlying response (an aborted generation kept consuming provider output), the faster tee branch could buffer without bound, partial response bytes were discarded on a read error despite the documented partial-body guarantee, and request capture mutated the caller's RequestInit after tee() had locked the original body — breaking the request outright if the init was frozen. Both request and response bodies now flow through a recording pass-through: chunks are recorded as the real consumer pulls them, cancellation is forwarded to the source, and the log file is written on completion, error, or cancellation with whatever bytes arrived plus a marker. Request capture copies the init instead of mutating it.
- Redact Cookie and Set-Cookie headers; they carry reusable session credentials from enterprise gateways. - Install raw logging in GeminiGenerateContentClient (Databricks google-generative route), beneath the bearer rewrite in bearer mode. - Resolve the env-var directory with an idempotent mkdir on every call, so a deleted override directory is recreated and env-var changes are picked up (drops the stale envDirCreated flag). - Include a process-unique nonce in log file names so concurrent Assistant/RStudio/TUI processes sharing a directory cannot overwrite each other's files. - Log GET (the Fetch default) for calls without an explicit method instead of POST. - Replace fixed 500ms test settles with condition-based waits.
OpenAIClient composed its fetch as SDK -> raw logger -> customFetch -> network, so the generic OpenAI-compatible, Foundry, and Databricks routes (and the empty-key auth stripper) logged request bodies and headers before the compat middleware mutated them and responses after its SSE rewrite. customFetch is now a factory receiving the wire fetch (the raw-HTTP- logging wrapper when active, otherwise the global fetch), composing SDK -> custom middleware -> raw logger -> global fetch — the same ordering the Snowflake client already used. New composition tests cover the customFetch path (post-transform request, raw SSE) and the empty-key auth strip.
- Bodyful Request inputs now use the recording pass-through via a rewritten Request instead of clone().arrayBuffer(), so cancelling or slowly consuming the upload propagates to the source and the log branch cannot buffer the full upload. - The wrapped response preserves url, redirected, and type (shadowed onto the wrapper, which the Response constructor cannot set); the narrowed headers-guard contract is documented on withRawHttpLogging. - The filename nonce is a full UUID, making the process-uniqueness the comment claims actual rather than likely. - Log files are published with temp-file-plus-rename, so an existing .http file always holds complete contents; test helpers now poll for existence instead of racing in-progress writes.
A bodyful Request that cannot be rewritten with a recording body (keepalive/no-cors, or a failed rewrite) previously logged an empty body, which reads as "the SDK sent no body" when debugging wire problems. Write a [body omitted: ...] marker instead, matching the response side's [error: ...] convention.
Record stream terminal state as a discriminated union instead of an optional error value: the Streams API permits controller.error() with no argument, so a stream can fail with an undefined rejection, which an optional error field cannot distinguish from a clean completion. Such failures now log an [error: ...] marker on both the request and response sides, with regression coverage. Also consolidate the synthetic fetch-rejection response on formatErrorMarker, rewrite the typed-array snapshot test to assert the log matches the bytes the delegate sent, and point internal OpenAI-compatible composition docs at createOpenAICompatibleFetchMiddleware.
|
Another round after previous fixes:
|
The env-selected directory was created with default permissions and log files with the process umask — typically 0755/0644 — even though bodies are deliberately unredacted and can contain prompts, source, tool output, and credentials. Directories are now created 0700 and temp files 0600 (rename preserves the mode).
2 participants
Adds a fetch wrapper (
raw-http-logging.ts) that captures byte-faithful.httprequest/response pairs for wire-level debugging of provider rejections — the AI SDK-structuredJsonRequestLoggerview in the monorepo shows the SDK's interpretation of a call, not the actual bytes on the wire, which is exactly what you need when a provider returns a 400 you can't explain.Behavior
raw-http/directory exists — late binding, checked per chat call, so you canmkdirmid-session to enable capture without a restart.PA_RAW_HTTP_LOG_DIRturns it on unconditionally.node:fsis looked up lazily viaprocess.getBuiltinModulerather than a staticnode:import, so the module can be bundled into the Positron webview frontend (which shares chunks with the model clients). Outside Node, logging simply disables itself.Wired into every AI SDK-backed model client — OpenAI, Anthropic, DeepSeek, Gemini, Vertex, Ollama, OpenRouter, Posit AI, Snowflake, Bedrock — composing with each client's existing custom-fetch wrappers rather than replacing them.
Consumer
Needed by posit-dev/assistant#2015, which pins this branch and adds the per-deployment
raw-http/log directories plus therawHttpLogging.mdmemory-bank doc. That PR can't merge until this one does.🤖 Generated with Claude Code