fix(logging): capture generations that bypass the SDK HTTP transporter

[i-anubhav-anand]

What?

Closes #732

Adds a provider-agnostic logging fallback so the AI Request Logging experiment captures successful generations from providers that don't route through the SDK's HTTP transporter (e.g. a provider that proxies to a localhost sidecar).

Why?

Today logging is installed purely by decorating the SDK HTTP transporter (Logging_Http_Transporter), and Logging_Http_Transporter::send() is the only place that calls AI_Request_Log_Manager::log(). A request is logged iff it flows through that transporter. Any first-class provider reachable via wp_ai_client_prompt() that uses a custom transport is therefore silently absent from Tools → AI Request Log, even though the log presents itself as a record of every AI request. The concrete case in #732 is a codex provider that brokers requests through a localhost sidecar.

How?

WordPress core registers a PSR-14 dispatcher in wp-settings.php (WordPress\AiClient\AiClient::setEventDispatcher( new WP_AI_Client_Event_Dispatcher() )) that bridges the SDK's BeforeGenerateResultEvent / AfterGenerateResultEvent to the action hooks wp_ai_client_before_generate_result / wp_ai_client_after_generate_result. These fire from PromptBuilder::generateResult(), through which all generate*() calls funnel — for every provider, regardless of transport.

This PR adds Logging_Event_Listener, wired up in Logging_Integration::init(), which:

• On wp_ai_client_after_generate_result, writes a log row using the event:
  • provider = getModel()->providerMetadata()->getId()
  • model = getModel()->metadata()->getId()
  • tokens = getResult()->getTokenUsage() (prompt/completion)
  • duration = before-event → after-event
• Avoids double-logging transporter-based providers (which fire the event and pass through the decorator) with a per-generation flag: reset on the before-event, set by Logging_Http_Transporter::send(). When the transporter already logged the current generation, the after-event listener skips it.

Known limitation (documented in the code): the SDK's after-event fires on success only — there is no error event — so failed custom-transport generations remain uncaptured. Transporter-based providers still log errors as before. Closing the failure case for custom transports would require an SDK-level error event and is out of scope here.

The diff is surgical: +8 lines across the two existing files, plus one new listener class and one new test file.

Use of AI Tools

AI assistance: Yes
Tool(s): AI coding assistant (agentic CLI)
Used for: investigating the SDK event/dispatcher flow in wp-includes/php-ai-client and wp-includes/ai-client, drafting the listener + tests, and writing this description. All code was written test-first, executed, and reviewed by me; I take responsibility for it.

Testing Instructions

Automated (PHPUnit, via wp-env):

npm run wp-env:test start
npm run test:php -- --filter Logging

• New tests: tests/Integration/Includes/Logging/Logging_Event_ListenerTest.php
  • test_logs_generation_that_bypasses_the_transporter — a generation that never touches Logging_Http_Transporter produces one row with the right provider/model/tokens.
  • test_does_not_double_log_transporter_based_generations — a transporter-logged generation yields exactly one row (no event-based duplicate).
• Full Logging suite (--filter Logging) is green (120 tests); the full integration suite is green (838 tests, 34 pre-existing skips).

Fail-before / pass-after (source stashed, test kept):

# before (unmodified source):
1) ...Logging_Event_ListenerTest::test_logs_generation_that_bypasses_the_transporter
Expected the sidecar generation to produce one log row.
Failed asserting that 0 is identical to 1.

# after (with fix):
OK (2 tests, 7 assertions)

Manual: enable AI Request Logging, run a generation through a provider with a custom transport (localhost sidecar), and confirm a row now appears in Tools → AI Request Log.

Changelog Entry

Fixed - AI Request Logging now captures successful generations from providers that use a custom transport (e.g. localhost sidecars), not only those routed through the SDK HTTP transporter.

[github-actions]

The following accounts have interacted with this PR and/or linked issues. I will continue to update these lists as activity occurs. You can also manually ask me to refresh this list by adding the props-bot label.

If you're merging code through a pull request on GitHub, copy and paste the following into the bottom of the merge commit message.

Co-authored-by: i-anubhav-anand <anubhav24@git.wordpress.org>
Co-authored-by: dkotter <dkotter@git.wordpress.org>
Co-authored-by: jeffpaul <jeffpaul@git.wordpress.org>
Co-authored-by: henryperkins <htperkins@git.wordpress.org>

To understand the WordPress project's expectations around crediting contributors, please review the Contributor Attribution page in the Core Handbook.

[codecov]

Codecov Report

❌ Patch coverage is 94.73684% with 2 lines in your changes missing coverage. Please review.
✅ Project coverage is 78.49%. Comparing base (77f116e) to head (92ddff8).
⚠️ Report is 122 commits behind head on develop.

Files with missing lines	Patch %	Lines
includes/Logging/Logging_Event_Listener.php	97.22%	1 Missing ⚠️
includes/Logging/Logging_Http_Transporter.php	0.00%	1 Missing ⚠️

Additional details and impacted files

@@              Coverage Diff              @@
##             develop     #757      +/-   ##
=============================================
+ Coverage      74.45%   78.49%   +4.04%     
- Complexity      1740     2464     +724     
=============================================
  Files             85      105      +20     
  Lines           7521     9958    +2437     
=============================================
+ Hits            5600     7817    +2217     
- Misses          1921     2141     +220     

Flag	Coverage Δ
unit	78.49% <94.73%> (+4.04%)	⬆️

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Harness.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:

• ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.
• 📦 JS Bundle Analysis: Save yourself from yourself by tracking and limiting bundle sizes in JS merges.

[dkotter]

I think this is different than what we log in our transporter. Ideally this matches for filtering.

[dkotter]

@henryperkins I know you reported the original issue, do you by chance have some time to verify if this PR fixes things for your use case? Thanks!

[jeffpaul]

@i-anubhav-anand are you able to make updates based on code review?

[henryperkins]

@dkotter Sorry for the delayed response here, and thanks for the ping — I tested this against ai-provider-for-codex v2.1 at 2827bb5, using WordPress 7.0.1, PHP 8.3.31, AI Client 1.3.1, and this PR at bb6a7a7.

I invoked the actual wp_ai_client_prompt()->using_model(...)->generate_text_result() path with a seeded user connection/model catalog. I intercepted only the loopback /v1/responses/text response to keep the test deterministic, so this did not use a live authenticated Codex account.

Results:

• At the PR base, with the provider’s own logging bridge disabled: 0 log rows.
• At this PR’s head, with that bridge disabled: exactly 1 row, with provider codex, model gpt-5-codex, tokens 7/3, status success, and logged_via=generation_event.
• At this PR’s head with the current provider unchanged: 2 success rows:
  • codex:responses/text, written by the provider’s existing RequestLogWriter
  • codex:text_generation, written by this PR’s event listener

The duplicate occurs because the provider already works around #732 by writing directly to the request log. This PR’s suppression flag only detects Logging_Http_Transporter, so it cannot tell that a custom provider has already logged the request.

I also tested a failed runtime response. The after-generation event did not fire, so this PR added no failure row. The current provider’s existing bridge did record one error row, consistent with the known limitation described in the PR.

So the event fallback does fix the original zero-log gap once the provider-side workaround is disabled or removed. With the current provider unchanged, however, successful requests are logged twice. The two paths also produce different operation values, which appears relevant to the existing filtering review comment.

[i-anubhav-anand]

Thanks both — and thanks especially for the thorough live test @henryperkins, that's really useful.

To summarise where this leaves the PR:

• The core fix works. As Henry confirmed, with the provider's own logging bridge disabled the event listener takes the log from 0 rows → exactly 1 correct row (provider: codex, model: gpt-5-codex, tokens, logged_via: generation_event). That closes the original gap in AI Request Logging only captures providers that use the SDK HTTP transporter; sidecar/custom-transport providers are invisible #732 for any custom-transport provider.
• But it double-logs when a provider's own bridge is still active. With the codex provider unchanged, a successful generation produces two rows: codex:responses/text (the provider's own RequestLogWriter) and codex:text_generation (this listener). The suppression flag only detects Logging_Http_Transporter, so it has no way to know a custom provider already logged the request.
• The two paths also produce different operation values (provider:capability here vs provider:basename(url_path) in the transporter path via Log_Data_Extractor). That's the same inconsistency @dkotter flagged in review — Henry's repro just makes it concrete.

Plan for the follow-up commit:

1. @since tags → x.x.x per the contributor guide.
2. Add a null/empty guard before getTokenUsage()->getPromptTokens()/getCompletionTokens() (re: @dkotter's question — the SDK's after-event should always carry token usage on success, but I'll fail safe rather than rely on it).
3. Align the operation string format between the transporter path and the event-listener path so filtering is consistent regardless of which path wrote the row.
4. Generalise the suppression signal: rename Logging_Event_Listener::mark_transporter_logged() into a transport-neutral public API (e.g. "mark this generation as already logged") that any logger — not just the SDK transporter — can call.

On the duplicate specifically: this PR alone can't fully de-dupe a provider that logs through its own path, so item 4 is the hook that lets it. @henryperkins — since the codex bridge already gates on class_exists() for the AI plugin and resolves its sink through the codex_provider_request_log_sink filter, would you prefer to (a) call the new marker before the bridge's success-path write (keeping its error-path write, which this listener structurally can't capture since the SDK fires no error event), or (b) drop the bridge's success path entirely once this lands? Happy to shape the marker API around whichever you'd rather. I'll also note the residual duplicate risk explicitly in the PR description as a known limitation for providers that don't adopt it.

(Separately, minor: the bridge writes type => 'text', but the REST type filter enum only accepts '', 'ai_client', 'mcp_tool', 'ability', so codex rows aren't filterable by type — not a blocker for this PR, just flagging it as further motivation to make the event listener the canonical path.)

Will push the follow-up shortly.

[i-anubhav-anand]

Pushed a follow-up commit addressing the review. Summary of what changed and one open question for @dkotter:

1. @since tags — all @since statements in the new files are now x.x.x per the contributor guide.

2. Possible null token usage (@dkotter's question) — I dug into the SDK's type declarations rather than add a guard, and the chain is non-nullable end to end:

• AfterGenerateResultEvent::getResult(): GenerativeAiResult
• GenerativeAiResult::getTokenUsage(): TokenUsage
• TokenUsage::getPromptTokens(): int / getCompletionTokens(): int (typed properties set in the constructor)

So getTokenUsage() can't return null on this path — and if the SDK ever violated its own contract, PHP would raise the TypeError inside the SDK before this listener ran. I've therefore left the direct calls in place rather than adding an unreachable guard; happy to add one anyway if you'd prefer belt-and-suspenders.

3. De-duplication across custom loggers (re: @henryperkins's double-log finding) — the suppression signal was transporter-specific (mark_transporter_logged(), keyed off Logging_Http_Transporter). I've renamed it to a transport-neutral public marker, Logging_Event_Listener::mark_generation_logged(), so any logger — not just the SDK transporter — can mark a generation as already recorded and have the after-event skip it. @henryperkins, since the codex bridge already gates on class_exists() for the AI plugin, it can call this marker right before its success-path write (keeping its error-path write, which this listener structurally can't capture), and the duplicate row goes away.

Open question on the operation value (@dkotter) — your review flagged that the event path's operation differs from the transporter's, and that's real, but the two are built from different data and can't be made identical: the transporter derives provider:basename(url_path) (the endpoint, e.g. openai:chat/completions) via Log_Data_Extractor, while the event listener only has the capability enum, giving provider:capability (e.g. openai:text_generation). The listener never sees the URL, so it can't reproduce the endpoint form. Which taxonomy would you like as the canonical one for the filter — endpoint-based or capability-based? Happy to normalise both paths to whichever you prefer; I left the current behaviour in place pending your call rather than guess.

I'll also expand the "known limitation" note in the description to cover the success-case duplicate for providers that don't adopt the marker.

[henryperkins]

Thanks — and one clarification for the record: this was a deterministic WordPress/provider integration-path test with the loopback sidecar response mocked, not a live authenticated Codex generation.

My preference is (b), with a backward-compatible feature check:

• When the event-listener fallback is available and active, skip the provider’s success-path write and let the AI plugin provide the canonical success row.
• Keep the provider’s error-path write because the SDK currently emits no corresponding error event.
• On older AI plugin versions without the event listener, retain the existing success-path bridge.

That avoids coupling the provider’s normal success path to another logging marker and gives the request log consistent type, operation, and filtering behavior. A transport-neutral marker could still be useful for custom providers that intentionally retain their own success logger.

One caveat if the marker-based approach is retained: it should be called only after RequestLogWriter::record() returns true, not before the write. record() is best-effort and can fail; marking first could suppress the event listener even though the provider’s write failed, returning the request to zero log rows.

Once the follow-up commit is available, I’m happy to rerun the same matrix against it and then update the provider around the final API.

[dkotter]

The listener never sees the URL, so it can't reproduce the endpoint form. Which taxonomy would you like as the canonical one for the filter — endpoint-based or capability-based? Happy to normalise both paths to whichever you prefer; I left the current behaviour in place pending your call rather than guess.

We definitely want to standardize and if this new approach of logging only has access to the capability, that seems like a pretty easy answer to make that the standard for filtering. But let me know if I'm missing something there.