Files
DocsGPT/tests/test_usage_latency.py
arc53-machine 25c82003d7 fix(admin): second review pass
Correctness
- /api/remote never recorded source.created, so URL, GitHub and connector
  sources had a source.deleted with no matching creation. All three creation
  paths now go through one _audit_source_created helper.
- The prompt-cache rate divided cached tokens by a whole bucket's prompt
  tokens. A bucket is a day and mixes calls whose provider reports a cache
  breakdown with calls whose provider does not, so filtering buckets in the
  client could not separate them and the rate was understated by however much
  traffic ran on a non-reporting provider. The denominator is now computed in
  SQL over the reporting rows.
- The outcome pill matched values nothing writes. Guardrails emit triggered /
  not_evaluated and the device feed emits dispatched; the map had blocked /
  denied / allowed, so a guardrail that fired rendered neutral grey -- the one
  signal the merged feed exists to surface. Fixtures were seeding the
  fictional values, so the tests passed on it too.
- Stream duration_ms timed the consumer. stream_token_usage is a generator,
  so start-to-exhaustion includes the agent loop's tool handling and the SSE
  client's pace; a slow browser recorded ~30s for a sub-second call. It now
  accumulates only the time spent inside next().

Safety
- Activity filters failed open: an unknown facet or unparseable timestamp was
  dropped, and no filter means every row, so a typo widened an audit view and
  on the export streamed the full history. Both are now a 400.
- The search term was interpolated into an ILIKE pattern, so "100%" matched
  everything and "q1_report" matched more than it should. Escaped.
- 0034 set actor_id NOT NULL with no default. A previous-release process
  inserting mid-rollout would raise, and in admin/routes.py that insert shares
  the request transaction, so a role grant beside it would roll back too.

Noise and dead code
- The per-user panel is a security panel: data-plane events file under the
  actor, so an active account's routine deletes pushed a denied login out of
  the 20-row window. It now excludes them; the Activity tab shows everything.
- device_audit_log had no created_at-leading index, so the merged feed
  sequentially scanned that branch every page (migration 0036).
- conversation.deleted_all no longer records when nothing was deleted, and
  agent.updated no longer records an empty field list.
- Dropped by_model from /admin/usage (no consumer; an extra aggregate per page
  load), the duplicate filter surface on AuthEventsRepository that nothing
  called, and the unreachable FLOW_LABELS.schedule entry.
- Type hints on record_event's conn and the remaining unannotated helpers.
2026-09-22 12:47:40 +01:00

114 lines
3.8 KiB
Python

"""Latency is measured by the usage wrappers and persisted with the call.
``duration_ms`` and ``ttft_ms`` were already computed for the finish log lines
and then discarded; these pin that they now reach ``token_usage``.
"""
from __future__ import annotations
from unittest.mock import patch
import pytest
from docsgpt.usage import gen_token_usage, stream_token_usage
class _LLM:
"""Minimal stand-in for an LLM instance the wrappers decorate."""
def __init__(self):
self.token_usage = {"prompt_tokens": 0, "generated_tokens": 0}
self.decoded_token = {"sub": "u1"}
self.user_api_key = None
self.agent_id = None
@pytest.fixture
def persisted():
calls: list[dict] = []
def _capture(llm, call_usage, *, duration_ms=None, ttft_ms=None):
calls.append({"duration_ms": duration_ms, "ttft_ms": ttft_ms})
with patch("docsgpt.usage._persist_call_usage", _capture):
yield calls
@pytest.mark.unit
class TestNonStreaming:
def test_records_a_duration_and_no_first_token(self, persisted):
@gen_token_usage
def _gen(self, model, messages, stream, tools, **kwargs):
return "hello"
assert _gen(_LLM(), "m", [], False, None) == "hello"
assert persisted[0]["duration_ms"] >= 0
# A non-streaming call has no first-token moment.
assert persisted[0]["ttft_ms"] is None
def test_a_failed_call_still_records_its_duration(self, persisted):
@gen_token_usage
def _gen(self, model, messages, stream, tools, **kwargs):
raise RuntimeError("upstream down")
with pytest.raises(RuntimeError):
_gen(_LLM(), "m", [], False, None)
assert persisted[0]["duration_ms"] >= 0
@pytest.mark.unit
class TestStreaming:
def test_records_time_to_first_chunk(self, persisted):
@stream_token_usage
def _stream(self, model, messages, stream, tools, **kwargs):
yield "a"
yield "b"
assert list(_stream(_LLM(), "m", [], True, None)) == ["a", "b"]
row = persisted[0]
assert row["ttft_ms"] is not None
# First token cannot land after the call finished.
assert row["ttft_ms"] <= row["duration_ms"]
def test_a_stream_that_never_yields_has_no_first_token(self, persisted):
"""NULL, not 0 — an instant p50 would be a lie."""
@stream_token_usage
def _stream(self, model, messages, stream, tools, **kwargs):
raise RuntimeError("refused")
yield # pragma: no cover - unreachable, makes this a generator
with pytest.raises(RuntimeError):
list(_stream(_LLM(), "m", [], True, None))
assert persisted[0]["ttft_ms"] is None
assert persisted[0]["duration_ms"] >= 0
def test_duration_excludes_consumer_backpressure(self, persisted):
"""The clock must measure the provider, not a slow reader.
``stream_token_usage`` is a generator, so every yield suspends until
the consumer comes back. Timing start-to-exhaustion would bill the
agent loop's tool handling and the SSE client's pace to the model.
"""
import time as _time
@stream_token_usage
def _stream(self, model, messages, stream, tools, **kwargs):
yield "a"
yield "b"
for _ in _stream(_LLM(), "m", [], True, None):
# A consumer that takes far longer than the provider did.
_time.sleep(0.05)
assert persisted[0]["duration_ms"] < 50
def test_a_stream_cut_short_keeps_the_first_token_it_saw(self, persisted):
@stream_token_usage
def _stream(self, model, messages, stream, tools, **kwargs):
yield "a"
raise RuntimeError("dropped")
with pytest.raises(RuntimeError):
list(_stream(_LLM(), "m", [], True, None))
assert persisted[0]["ttft_ms"] is not None