feat(llm): run.json records every provider request's timing, provider and tokens in llm_requests

This commit is contained in:
Ian 2026-10-19 13:07:49 -04:00
parent a0f8ea2cd3
commit 157e480817
3 changed files with 82 additions and 1 deletions

View file

@ -705,7 +705,9 @@ def configure_sdk_model_defaults(settings: Settings) -> None:
"""Apply Strix config to SDK-native defaults."""
llm = settings.llm
set_tracing_disabled(True)
request_log.install()
from strix.report.state import record_llm_request
request_log.register_sink(record_llm_request)
if codex.subscription_model(llm.model):
return
_configure_litellm_compatibility()

View file

@ -28,6 +28,8 @@ from strix.telemetry import posthog, scarf
if TYPE_CHECKING:
from agents.usage import Usage
from strix.llm.request_log import LlmRequestEvent
logger = logging.getLogger(__name__)
@ -1019,6 +1021,30 @@ class StreamedOpenRouterCosts:
streamed_openrouter_costs = StreamedOpenRouterCosts()
def record_llm_request(event: "LlmRequestEvent") -> None:
"""Request-log sink: each provider attempt's timing, kept in run.json's ``llm_requests``."""
report_state = get_global_report_state()
if report_state is None:
return
details = event.details or {}
report_state.run_record.setdefault("llm_requests", []).append(
{
"started_at": event.started_at.isoformat(),
"agent_id": event.agent_id,
"model": event.model,
"provider": details.get("upstream_provider") or event.provider,
"outcome": event.outcome,
"status": event.status_code,
"duration_ms": event.duration_ms,
"ttft_ms": event.time_to_first_token_ms,
"input_tokens": event.input_tokens,
"cached_tokens": event.cached_input_tokens,
"output_tokens": event.output_tokens,
"retry_attempt": event.retry_attempt,
}
)
def record_openrouter_provider(provider: Any, usage: Any) -> None:
"""Tally which upstream provider served a stream, from its final usage chunk.

View file

@ -4,6 +4,7 @@ from __future__ import annotations
import json
import uuid
from datetime import UTC, datetime, timedelta
from types import SimpleNamespace
from typing import TYPE_CHECKING, Any
from unittest.mock import MagicMock, call, patch
@ -23,6 +24,7 @@ from strix.report.state import (
ReportState,
litellm_cost_callback,
openrouter_stream_cost,
record_llm_request,
set_global_report_state,
streamed_openrouter_costs,
)
@ -455,3 +457,54 @@ def test_openrouter_records_upstream_of_pre_stream_error() -> None:
request_log._http_reply.reset(token)
assert reply.upstream_provider == "InferenceNet"
assert reply.upstream_error_type is None
def test_request_timings_land_in_run_record() -> None:
started = datetime(2026, 10, 19, 12, 0, tzinfo=UTC)
event = request_log.LlmRequestEvent(
call_id="call-1",
route="litellm",
provider="openrouter",
model="openrouter/deepseek/deepseek-v4.1-flash",
api_host="openrouter.ai",
streaming=True,
outcome="success",
status_code=200,
provider_request_id=None,
response_id="gen-1",
error_type=None,
error_message=None,
started_at=started,
finished_at=started + timedelta(milliseconds=4200),
duration_ms=4200,
input_tokens=90_000,
output_tokens=600,
cached_input_tokens=85_000,
agent_id="agent-1",
time_to_first_token_ms=900,
details={"upstream_provider": "Together"},
)
state = ReportState.__new__(ReportState)
state.run_record = {}
try:
set_global_report_state(state)
record_llm_request(event)
finally:
set_global_report_state(None)
assert state.run_record["llm_requests"] == [
{
"started_at": "2026-10-19T12:00:00+00:00",
"agent_id": "agent-1",
"model": "openrouter/deepseek/deepseek-v4.1-flash",
"provider": "Together",
"outcome": "success",
"status": 200,
"duration_ms": 4200,
"ttft_ms": 900,
"input_tokens": 90_000,
"cached_tokens": 85_000,
"output_tokens": 600,
"retry_attempt": 0,
}
]