feat(run): STRIX_RUN_RECORD_TIMINGS records every LLM request's and tool call's timing in run.json

docs/advanced/configuration.mdx

@@ -141,6 +141,10 @@ affecting the agents that do the actual testing.
   Telemetry toggle. Set to `0`, `false`, `no`, or `off` to disable telemetry (PostHog, Scarf, OTEL).
 </ParamField>
 
+<ParamField path="STRIX_RUN_RECORD_TIMINGS" default="false" type="boolean">
+  Record every LLM request's and tool call's timing in `run.json`, under `llm_requests` and `tool_calls`. Adds about 0.5 MB to a typical scan's `run.json`.
+</ParamField>
+
 <ParamField path="TRACELOOP_BASE_URL" type="string">
   OTLP/Traceloop base URL for remote OpenTelemetry export. If unset, Strix keeps traces local only.
 </ParamField>

strix/config/models.py

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

strix/config/settings.py

@@ -163,6 +163,7 @@ class TelemetrySettings(BaseSettings):
     model_config = _BASE_CONFIG
 
     enabled: bool = Field(default=True, alias="STRIX_TELEMETRY")
+    run_record_timings: bool = Field(default=False, alias="STRIX_RUN_RECORD_TIMINGS")
 
 
 WebSearchProvider = Literal["auto", "perplexity", "exa"]

strix/core/hooks.py

@@ -4,18 +4,21 @@
 
 import logging
 import math
+import time
+from datetime import UTC, datetime
 from typing import TYPE_CHECKING, Any
 
 from agents.lifecycle import RunHooks
 
 from strix.core.agents import BudgetPolicy, coordinator_from_context
-from strix.report.state import get_global_report_state
+from strix.report.state import get_global_report_state, record_tool_call
 
 
 if TYPE_CHECKING:
     from agents import RunContextWrapper
     from agents.agent import Agent
     from agents.items import ModelResponse, TResponseInputItem
+    from agents.tool import Tool
 
 
 logger = logging.getLogger(__name__)
@@ -163,6 +166,7 @@ def __init__(
         max_turns: int | None = None,
         interactive: bool = False,
         budget_policy: BudgetPolicy = "stop",
+        record_tool_timings: bool = False,
     ) -> None:
         _validate_budget(max_budget_usd)
         if max_turns is not None and max_turns <= 0:
@@ -175,6 +179,8 @@ def __init__(
         self._max_turns = max_turns
         self._interactive = interactive
         self._budget_policy: BudgetPolicy = budget_policy
+        self._record_tool_timings = record_tool_timings
+        self._tool_starts: dict[str, tuple[datetime, float]] = {}
 
     @property
     def max_budget_usd(self) -> float | None:
@@ -315,6 +321,37 @@ def _maybe_warn_budget(
             )
         input_items.append({"role": "user", "content": content})
 
+    async def on_tool_start(
+        self,
+        context: RunContextWrapper[dict[str, Any]],
+        agent: Agent[dict[str, Any]],  # noqa: ARG002
+        tool: Tool,  # noqa: ARG002
+    ) -> None:
+        call_id = getattr(context, "tool_call_id", None)
+        if self._record_tool_timings and isinstance(call_id, str):
+            self._tool_starts[call_id] = (datetime.now(UTC), time.monotonic())
+
+    async def on_tool_end(
+        self,
+        context: RunContextWrapper[dict[str, Any]],
+        agent: Agent[dict[str, Any]],  # noqa: ARG002
+        tool: Tool,
+        result: object,  # noqa: ARG002
+    ) -> None:
+        call_id = getattr(context, "tool_call_id", None)
+        start = self._tool_starts.pop(call_id, None) if isinstance(call_id, str) else None
+        if start is None:
+            return
+        started_at, started = start
+        ctx = context.context if isinstance(context.context, dict) else {}
+        agent_id = ctx.get("agent_id")
+        record_tool_call(
+            started_at=started_at,
+            agent_id=agent_id if isinstance(agent_id, str) else None,
+            tool=tool.name,
+            duration_ms=round((time.monotonic() - started) * 1000),
+        )
+
     async def on_llm_end(
         self,
         context: RunContextWrapper[dict[str, Any]],

strix/core/runner.py

@@ -419,6 +419,7 @@ async def _spill_to_workspace(output_id: str, text: str) -> str | None:
             max_turns=max_turns,
             interactive=interactive,
             budget_policy=budget_policy,
+            record_tool_timings=settings.telemetry.run_record_timings,
         )
         coordinator.set_budget_limit_setter(hooks.set_max_budget_usd)
         if interactive and budget_policy != "pause":

strix/report/state.py

@@ -28,6 +28,8 @@
 if TYPE_CHECKING:
     from agents.usage import Usage
 
+    from strix.llm.request_log import LlmRequestEvent
+
 
 logger = logging.getLogger(__name__)
 
@@ -1019,6 +1021,47 @@ def clear(self) -> None:
 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_tool_call(
+    *, started_at: datetime, agent_id: str | None, tool: str, duration_ms: int
+) -> None:
+    """Each tool call's timing, kept in run.json's ``tool_calls``."""
+    report_state = get_global_report_state()
+    if report_state is None:
+        return
+    report_state.run_record.setdefault("tool_calls", []).append(
+        {
+            "started_at": started_at.isoformat(),
+            "agent_id": agent_id,
+            "tool": tool,
+            "duration_ms": duration_ms,
+        }
+    )
+
+
 def record_openrouter_provider(provider: Any, usage: Any) -> None:
     """Tally which upstream provider served a stream, from its final usage chunk.
 

tests/test_cost_tracking.py

@@ -4,6 +4,7 @@
 
 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
@@ -18,11 +19,13 @@
     _configure_litellm_compatibility,
     _install_openrouter_stream_cost_capture,
 )
+from strix.core.hooks import ReportUsageHooks
 from strix.llm import request_log
 from strix.report.state import (
     ReportState,
     litellm_cost_callback,
     openrouter_stream_cost,
+    record_llm_request,
     set_global_report_state,
     streamed_openrouter_costs,
 )
@@ -455,3 +458,73 @@ 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,
+        }
+    ]
+
+
+async def test_tool_call_timings_land_in_run_record() -> None:
+    hooks = ReportUsageHooks(model="m", record_tool_timings=True)
+    context = SimpleNamespace(tool_call_id="call-1", context={"agent_id": "agent-1"})
+    tool = SimpleNamespace(name="terminal_execute")
+    state = ReportState.__new__(ReportState)
+    state.run_record = {}
+    try:
+        set_global_report_state(state)
+        await hooks.on_tool_start(context, MagicMock(), tool)  # type: ignore[arg-type]
+        await hooks.on_tool_end(context, MagicMock(), tool, "ok")  # type: ignore[arg-type]
+    finally:
+        set_global_report_state(None)
+
+    [entry] = state.run_record["tool_calls"]
+    assert entry["agent_id"] == "agent-1"
+    assert entry["tool"] == "terminal_execute"
+    assert entry["duration_ms"] >= 0