fix(core): log the OpenAI request actually sent on the wire - #3767
Merged
Conversation
Collaborator
Author
E2E Test ReportStatus: VERIFIED_FIXED Command: node dist/cli.js "say hello" --approval-mode yolo --output-format json \
--model mock-thinking-model \
--openai-logging --openai-logging-dir /tmp/openai-logging-fix-verify/logsReproduction (before the fix)The captured
Confirmed against two production configurations: Verification (after the fix)The captured Field-by-field comparison:
Unit tests317 tests pass in
|
Contributor
Code Coverage Summary
CLI Package - Full Text ReportCore Package - Full Text ReportFor detailed HTML reports, please see the 'coverage-reports-22.x-ubuntu-latest' artifact from the main CI run. |
wenshao
approved these changes
May 1, 2026
wenshao
left a comment
wenshao
left a comment
Collaborator
There was a problem hiding this comment.
No issues found. LGTM! ✅ — claude-opus-4-7 via Claude Code /qreview
Bojun-Vvibe
added a commit
to Bojun-Vvibe/oss-contributions
that referenced
this pull request
May 2, 2026
- BerriAI/litellm#27059 (Grok 4.20 azure_ai metadata) merge-after-nits - QwenLM/qwen-code#3743 (path-vs-slash-command classifier) merge-after-nits - QwenLM/qwen-code#3767 (capture actual wire request in OpenAI logger) merge-after-nits - google-gemini/gemini-cli#26306 (bound retry fallback to prevent infinite loop) merge-after-nits - google-gemini/gemini-cli#26305 (/mcp remove slash command) merge-after-nits
wenshao
requested changes
May 3, 2026
wenshao
left a comment
wenshao
left a comment
Collaborator
There was a problem hiding this comment.
Suggestion: Test coverage gaps: missing tests for (a) catch path with active capture, (b) streaming capture-less fallback, (c) stream error with active capture. See loggingContentGenerator.test.ts.
This was referenced May 3, 2026
wenshao
reviewed
May 3, 2026
wenshao
reviewed
May 6, 2026
wenshao
left a comment
wenshao
left a comment
Collaborator
There was a problem hiding this comment.
Overview
The PR replaces the parallel "logging-only" reconstruction (buildOpenAIRequestForLogging) with a faithful capture of the exact OpenAI.Chat.ChatCompletionCreateParams object handed to the SDK. The mechanism is a tiny AsyncLocalStorage<OpenAIRequestCapture> channel:
pipeline.tscallsopenaiRequestCaptureContext.getStore()?.(openaiRequest)once, afterbuildRequest(post provider enhancement, post reasoning-disable) and before the SDK call.LoggingContentGeneratorwraps the inner call inopenaiRequestCaptureContext.run((built) => { captured = built; }, fn), then reads the closure variable.- Falls back to the existing synthetic build when nothing was captured (Anthropic/Gemini generators) or for internal prompts.
The fields previously dropped — extra_body, DashScope metadata, stream/stream_options, and samplingParams pass-throughs like reasoning_effort — now appear in the log.
Code quality and style
- The capture point is well-placed. The call in
pipeline.tsruns after provider mutation and the disable-reasoning logic, so the captured object is the post-transform form actually sent on the wire — not a pre-providerbaseRequest. startCaptureSessionis a clean factoring.wrap+resolvekeeps the closure local; concurrent decorator calls don't share state because eachstartCaptureSession()allocates its owncapturedvariable.skipCaptureshort-circuit is correct. WhenisInternal || !this.openaiLogger,wrapskipsrun()entirely; the pipeline'sgetStore()?.()becomes a no-op. No wasted AsyncLocalStorage frames for internal prompts.- Synthetic fallback preserved. Non-OpenAI generators still get the previous best-effort log rather than an empty payload.
- Tests target the actual concerns. The streaming case, the fallback case, and concurrent-isolation case are each exercised;
pipeline.test.tsconfirmsclient.chat.completions.createwas called with the same object reference that the capture observed (expect(captured).toBe,expect(...).toHaveBeenCalledWith(captured, ...)).
Specific suggestions
-
Extract the inline return type of
startCaptureSession. The signatureprivate startCaptureSession(isInternal: boolean): { wrap: <T>(fn: () => Promise<T>) => Promise<T>; resolve: (req: GenerateContentParameters) => Promise<OpenAI.Chat.ChatCompletionCreateParams | undefined>; }
is fine, but a named
CaptureSessiontype would read better at the call sites and document the contract once. -
Defensive: consider gating
resolveonisInternal. Today every caller correctly wrapsawait session.resolve(req)inif (!isInternal). If a future caller forgets,resolvewould fall back tobuildOpenAIRequestForLogging, which only checks foropenaiLogger, not internal-ness — so it would do work that's later thrown away. Cheap to harden by capturingisInternalin the session. -
Add one error-path assertion for capture. The new tests cover success only. A test that asserts the captured request (not the synthetic one) is what gets logged when the wrapped call rejects after
getStore()?.()fired would close the loop on the error branch ingenerateContent/generateContentStream. -
Capture-call timing in the pipeline could use a one-line comment. The position relative to
buildRequest(post-provider, post-disable-reasoning) is load-bearing for what gets logged. A short note next toopenaiRequestCaptureContext.getStore()?.(openaiRequest);would prevent a future refactor from accidentally moving the call before provider enhancement.
Risks
- Retry overwriting (acceptable).
QwenContentGenerator.executeWithCredentialManagementretriessuper.generateContenton auth errors. Each retry re-runs the pipeline and re-fires the capture, so the closure is overwritten with the last attempt's request. That matches what we log on the response/error side, so the request and response stay consistent — but worth noting if anyone debugs from logs and sees a single request line per call. - Mutation of the captured object. The captured object is the same reference handed to the SDK. The OpenAI SDK does not mutate user-supplied params (it serializes to JSON), so this is safe in practice, but it is an implicit contract worth flagging if the SDK ever changes.
- AsyncLocalStorage correctness. The standard concern (await boundaries propagating the store) holds because the capture is invoked synchronously within the awaited chain that originates inside
run(). The concurrency test exercises this. - Scope explicitly carved out. Anthropic / Gemini paths still use the synthetic reconstruction. Documented in the PR; not a regression.
Verdict
The fix is small, surgical, and well-tested. The synthetic fallback makes it strictly additive. LGTM after the minor clean-ups above (or as follow-ups).
Collaborator
Author
|
Picked up the resolve() concerns and the capture-timing note in 0b2fe8d. Wrapped each On the test coverage gaps — leaving them out. On extracting a named On gating |
Collaborator
OverviewThe PR addresses a real correctness gap in The fix introduces an Two functional commits: Strengths
Concerns
Minor / style
Risk / blast radiusLow. The change is purely additive on the OpenAI path and falls back to existing behavior on the non-OpenAI path. The failure mode for the new path (capture never fires) is to use the existing synthetic builder, which is what shipped before this PR — so the worst case is "no regression." The follow-up commit ( RecommendationApprove with optional polish. None of the concerns are blockers. The two I'd most encourage addressing in this PR:
The mutation-safety question (#1) and the streaming load-bearing comment (#5) are fine as follow-ups. |
Collaborator
Author
|
Thanks for the thorough pass. Picked up concern #3 in 4d88d33 — broadened the comment to "if Deferring concern #2: this module has no debug-logging utility wired through it, and writing to stderr unconditionally on a logging-side throw could spam users on transient log-dir permission errors. I'll open a follow-up issue to design proper observability for logging failures. Leaving #1, #4, #5, #6 as-is — all non-blocking polish, happy to revisit in a follow-up. |
Collaborator
OverviewThe PR fixes a long-standing fidelity issue in Surface area: 19 files, but only ~4 are substantive. The other ~15 are prettier-style reformatting unrelated to the fix. Strengths
Issues1. Inconsistent error safety in the streaming path (medium)The new
But not inside // success branch
await this.logOpenAIInteraction(openaiRequest, consolidatedResponse);
// error branch
await this.logOpenAIInteraction(openaiRequest, undefined, error);Result: a stream that completes successfully can still see a logger-side throw escape the generator, and a stream that errored can still have its original error replaced by a logging error. This contradicts the safety invariant the PR explicitly establishes for the non-streaming path. The new test Suggestion: wrap both calls in 2. Silent swallowing has no observability (low)The two Suggestion: at minimum, emit a debug-level message (or a telemetry event) so logging failures are diagnosable. Doesn't need to be loud — even a single 3. PR scope bloat (process)15 of 19 files are prettier-style reformatting unrelated to the fix:
These mask the substantive change (~120 lines of real diff) inside a 632-line patch and make it harder for reviewers to see what's load-bearing. Worth splitting into a separate "chore: prettier formatting" PR. 4.
|
wenshao
reviewed
May 7, 2026
wenshao
left a comment
wenshao
left a comment
Collaborator
There was a problem hiding this comment.
Review found 1 actionable issue.
Collaborator
Author
|
Thanks for the thorough overview, picking up #1, pushing back on the rest. #1 — streaming wrapper safety. Fixed in 5b9b3a3 (replied inline). #2 — silent swallow has no observability. Going to keep these silent. The four #3 — PR scope bloat (15 unrelated files). This is a GitHub diff-display artifact rather than actual scope bloat. Of the 14 files outside the logging set, 13 are byte-identical to current `origin/main`: ``` They show in the PR diff because the merge commit `80f5274b0` had main-at-`2bd4aa1b6` as parent2, which became the merge base. GitHub's three-dot diff against current main therefore surfaces every change that landed on main between `2bd4aa1b6` and now as if it belonged to this PR. The actual contribution is the five logging-related files. Happy to rebase on top of current main to clean up the diff display — that will eliminate the noise; the one real outlier is the 4-line prettier wrap in `get-release-version.js` which I can drop in the rebase. #4 — `{ wrap, resolve }` shape over-built. Going to leave as-is. Both `generateContent` and `generateContentStream` use both methods, and the streaming path needs them at separate `await` points (wrap around the stream-returning call, resolve before the wrapper takes ownership of the captured value). Inlining the closure or returning a `Disposable` would re-duplicate the plumbing across both entry points without simplifying anything. |
The --openai-logging capture was a parallel reconstruction that copied only a small subset of fields, silently dropping anything the provider layer injected — extra_body (so enable_thinking/thinking), DashScope metadata, stream/stream_options, and samplingParams pass-through keys like reasoning_effort. Anyone debugging "what did we actually send?" saw a stripped-down view that disagreed with the wire payload. Surface the fully built request from the pipeline to the logging decorator via an AsyncLocalStorage-scoped capture, so the log file mirrors the SDK call. The synthetic reconstruction stays as a fallback for non-OpenAI generators that don't go through the pipeline.
Wrap each session.resolve() / logOpenAIInteraction call in LoggingContentGenerator with try/catch so a synthesis failure inside the synthetic-fallback path can no longer mask a successful API response or replace the original API error. Also note the load-bearing position of the capture call in the OpenAI pipeline.
Comment said the try/catch protects against resolve() throws, but the same block also catches logOpenAIInteraction throws. Reword to match.
Mirror the non-streaming try/catch around `logOpenAIInteraction` inside `loggingStreamWrapper`, so a logger throw on stream completion cannot turn a fully-yielded stream into an error, and a logger throw in the catch path cannot replace the original stream/API error.
tanzhenxin
force-pushed
the
fix/openai-logging-faithful-capture
branch
from
May 7, 2026 03:10
5b9b3a3 to
1b350f9
Compare
Collaborator
Author
|
Rebased onto current |
wenshao
reviewed
May 7, 2026
wenshao
reviewed
May 7, 2026
wenshao
reviewed
May 7, 2026
wenshao
left a comment
wenshao
left a comment
Collaborator
There was a problem hiding this comment.
No review findings. Downgraded from Approve to Comment: CI has failing check: Test (ubuntu-latest, 24.x). — gpt-5.5 via Qwen Code /review
…ithful-capture # Conflicts: # packages/core/src/core/loggingContentGenerator/loggingContentGenerator.ts
wenshao
reviewed
May 8, 2026
Collaborator
Author
|
CI is now green on the current HEAD ( |
wenshao
approved these changes
May 9, 2026
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
2 participants
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Summary
--openai-loggingdecorator now records the exact request the OpenAI SDK was called with, instead of building a parallel, stripped-down reconstruction.extra_body(and thereforeenable_thinking/thinking), DashScopemetadata,stream/stream_options, and anysamplingParamspass-through keys such asreasoning_effort. Anyone reaching for the logs to answer "what did we actually send?" got a misleading subset that disagreed with the wire traffic, and bug reports built on those logs were partial captures.Validation
Prompts / inputs used: A model configured with
samplingParams.reasoning_effort: "max"andextra_body: { thinking: { type: "enabled" } }, then a streaming model configured withextra_body: { enable_thinking: true }to confirm streaming-specific fields are captured.Expected result: Each captured
requestobject contains every provider-injected field —extra_body,metadata,stream,stream_options,samplingParamspass-through keys — exactly as sent to the SDK.Observed result: All previously absent fields now appear in the log file. Before/after for the deepseek + glm reproductions:
streamtruestream_options{ include_usage: true }reasoning_effort"max"thinking(from extra_body){ type: "enabled" }enable_thinking(from extra_body)trueQuickest reviewer verification path: Configure any model with a non-trivial
extra_body(e.g.{ enable_thinking: true }) undermodelProvidersin~/.qwen/settings.json, run any prompt with--openai-logging --openai-logging-dir /tmp/logs, and confirm the resulting JSON file'srequestobject contains theextra_bodykeys (top-level after spread) and any DashScopemetadatablock.Scope / Risk
.run(). Concurrent calls each have their own store and their own closure, verified by a dedicated test.--openai-loggingoutput. Making those faithful is a separate, larger change because their wire format is not OpenAI to begin with.Testing Matrix
Testing matrix notes:
Linked Issues / Bugs