Issue #3604343 by codeitwisely: Record per-call latency in ai_metering_usage

Jérôme Tchaniarequested to merge
issue/ai_metering-3604343:3604343-record-per-call-latency into 1.0.x

Closes https://www.drupal.org/project/ai_metering/issues/3604343

What changed

  • New nullable latency_ms column on ai_metering_usage (hook_update_9018 + hook_schema), NULL on pre-existing rows so 'not measured' stays distinguishable from a real measurement.
  • New LatencyTracker service using the monotonic hrtime() clock. The pre-generate subscriber starts the clock at priority -100 (as close to the provider call as possible); the post-generate subscriber reads the elapsed time first thing, so metering overhead never inflates the value.
  • The quota-reroute degraded path (raw plugin call) is timed directly.
  • Latency (ms) column added to the AI Usage Log view (shipped config + update hook for existing sites, empty_zero so NULL renders as n/a).
  • Streaming note: the response event fires after stream consumption, so the value is full call duration, not time to first byte.

Per comment #3, tokens/second is derivable from output_tokens and latency_ms; it lands with the aggregation table in #3608701 so the rollup schema carries latency from day one. Time to first byte for streaming is a follow-up.

Testing steps

  1. Run drush updatedb, make any AI call.
  2. Check /admin/reports/ai-metering/log: the new row shows a positive Latency (ms); older rows show n/a.

Verified live (Drupal 11.3.12, PHP 8.4): Ollama chat recorded 3219 ms. Suite green (132 tests, 514 assertions), PHPCS and PHPStan clean.

AI assistance

Implemented with AI assistance (Claude Code), verified end to end on a live site.

Merge request reports