Add providers_used + llm_duration_ms to llm_usage_logs - #8
Conversation
![chatgpt-codex-connector[bot]](https://avatars.githubusercontent.com/in/1144995?s=60&v=4){kind=small}
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: ceb0d3264e
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "@codex review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "@codex address that feedback".
| DROP TABLE IF EXISTS stripe_payment_intents; | ||
| DROP INDEX IF EXISTS idx_admin_oauth_sessions_expires_at; | ||
| DROP TABLE IF EXISTS admin_oauth_sessions; |
There was a problem hiding this comment.
Downgrading from 0020 to its declared down-revision 0019 should restore the schema produced by 0019, where both of these tables already exist. Instead, this drops the tables and all their data while leaving revisions 0018/0019 recorded as applied; downgrading farther also makes 0019's unconditional op.drop_table() fail. Because 0020 only reconciles pre-existing objects across peers, its downgrade must not remove those objects.
Useful? React with 👍 / 👎.
| else: | ||
| # Non-Spock environment (CI, local dev, single-node) — plain DDL. | ||
| bind.execute(sa.text(_ENSURE_DDL)) |
There was a problem hiding this comment.
In a non-Spock environment using the repository's configured postgresql+asyncpg URL, this passes the five statements in _ENSURE_DDL to SQLAlchemy as one prepared statement. The asyncpg dialect rejects multiple commands in a prepared statement, so a fresh local or single-node alembic upgrade head fails at 0020 instead of creating the tables. Execute each DDL statement separately on the fallback path.
Useful? React with 👍 / 👎.
| else: | ||
| # Non-Spock environment (CI, local dev, single-node) — plain DDL. | ||
| bind.execute(sa.text(ddl)) |
There was a problem hiding this comment.
When Spock is absent and the configured asyncpg driver is used, _UPGRADE_DDL and _DOWNGRADE_DDL each contain two commands but are submitted through one SQLAlchemy execution. Asyncpg cannot prepare multiple commands at once, so migration 0021 fails in local, CI-like, or fresh-region databases on both upgrade and downgrade. Split the DDL and execute each ALTER TABLE independently.
Useful? React with 👍 / 👎.
| # Upstream provider(s) that actually served the calls. On OpenRouter one | ||
| # model id maps to ~10 providers with a 7.7x throughput spread, so | ||
| # models_used alone cannot attribute slowness. See migration 0021. | ||
| providers_used: Mapped[list[str]] = mapped_column(ARRAY(String), nullable=False, default=list) |
There was a problem hiding this comment.
Although the new values are persisted, the repository's detailed analytics path, get_interaction_margins, still selects and serializes only models_used and duration_ms; neither providers_used nor llm_duration_ms appears in InteractionMarginResponse. Operators using the admin analytics API therefore cannot perform the provider/latency diagnosis this change is intended to enable without direct database access. Add both columns to that query and response model.
Useful? React with 👍 / 👎.
|
Correction to the warning in this PR's description. I said merging would drop two client ids from production and break OAuth. That was wrong — I checked the wrong source of truth before writing it.
The hardcoding was still real drift, and while fixing it I found something more serious in the same file: the deploy accepted any SSH host key for that IP ( Both are addressed in #9, which should land first. This PR is otherwise unchanged and ready. |
ceb0d32 to
b9be970
Compare
Closes two telemetry blind spots found during a user-visible latency incident on 2026-08-28. providers_used: we record models_used but not which upstream actually served the call. On OpenRouter a single model id is served by ~10 providers whose measured throughput spans 22-170 tok/s (7.7x). Without attribution "the model is slow" cannot be narrowed to "this provider is slow" from data — we had to benchmark all ten by hand out-of-band. llm_duration_ms: the existing duration_ms is interaction wall-clock, start -> finalization, where finalization fires on the stale timeout (5 min) or a call-limit trip rather than when the last LLM call returns. It therefore includes agent-side and idle time. A 24-minute duration_ms row sent us hunting for a violated request_timeout: 120 that was never violated. llm_duration_ms is the summed LLM-call time only, so the two can be compared instead of conflated. Migration 0021 follows the Issue #5 convention: DDL is wrapped in spock.replicate_ddl() so it fans out over the ddl_sql replication set, with a plain-DDL fallback for non-Spock environments, and uses ADD COLUMN IF NOT EXISTS so it is idempotent on a node that already received the DDL via replication. Both columns are nullable/defaulted and both request fields are optional, so old rows stay valid and a proxy that does not yet send them keeps working.
b9be970 to
2c36d03
Compare
|
You have reached your Codex usage limits for code reviews. You can see your limits in the Codex usage dashboard. |
|
1 participant
What
Adds two columns to
llm_usage_logs(migration 0021) plus the model/schema/route wiring:providers_used— which upstream actually served the callsllm_duration_ms— summed LLM-call time, distinct from the existing interaction wall-clockWhy
Both closed blind spots found while diagnosing a user-visible latency incident on 2026-08-28.
Provider attribution. We record
models_usedbut not the serving provider. On OpenRouter one model id (qwen/qwen3.6-35b-a3b) is served by ~10 providers. Measured live that day, identical 192-token output:A 7.7x spread behind one model id. With no attribution, "the model is slow" can't be narrowed to "this provider is slow" from data — the culprit had to be found by benchmarking all ten by hand out-of-band.
True latency.
duration_msis measured start → finalization, and finalization fires on the stale timeout (5 min) or a call-limit trip, not when the last LLM call returns. So it includes agent-side and idle time. A 24-minuteduration_msrow sent us hunting for a violatedrequest_timeout: 120that was never actually violated. The per-call sum already existed in the proxy's accumulator and was discarded at send time; it's now reported separately.Compatibility
Spock
Migration follows the Issue #5 convention: DDL wrapped in
spock.replicate_ddl()to fan out over theddl_sqlreplication set, plain-DDL fallback for non-Spock (CI/local/single-node), andADD COLUMN IF NOT EXISTSso it's idempotent on a node that already received the DDL via replication.Producer side: CIRISProxy
6f2f640.deploy.ymlfirstI deliberately did not push to
main.deploy.ymltriggers on push to main and deploys straight to production with a hardcodedGOOGLE_CLIENT_IDS(line 88) containing 2 client IDs, while production currently runs 4:Merging as-is would drop two client IDs and break OAuth for those apps. That drift is pre-existing and independent of this PR, but it makes any merge to main hazardous until fixed.
🤖 Generated with Claude Code