Added LLM request duration

docs/TRIAGE.md

@@ -332,18 +332,22 @@ With `[triage].dump_io = true` (default `false`) each triage writes a self-conta
 file under `troubleshoot/triage/YYYY-MM-DD/HHMMSS-mmm.json` — local time with millisecond precision, the
 same naming scheme as the audio files (`<session_dir>/<id>/audio/HHMMSS-mmm-<reason>.wav`). A file
 holds the Laya request, the Laya response, the LLM request (endpoint URL plus the full
-chat-completion body), and the LLM response (raw envelope), keyed by the `ts` carried on the
-triage events:
+chat-completion body), the LLM response (raw envelope), and the LLM round-trip time, keyed by
+the `ts` carried on the triage events:
 
 ```json
 {
   "ts": 1759073916.19,
   "iso": "2026-09-28T09:38:36.412000-06:00",
   "laya": {"request": {...}, "response": {...}, "error": null},
-  "llm": {"request": {"url": "...", "body": {...}}, "response": {...}, "error": null}
+  "llm": {"request": {"url": "...", "body": {...}}, "response": {...}, "error": null, "duration_ms": 812.4}
 }
 ```
 
+`llm.duration_ms` is the wall-clock time spent in the LLM transport call (monotonic clock,
+millisecond precision), recorded on both success and failure. It measures only the request
+round-trip, not prompt building or reply parsing.
+
 A turn whose brief is coalesced (the previous `brief-update` was still in flight, so the turn
 was refused and its deltas were flushed later) produces **two** files, not one. The turn's
 own record carries only the `laya` half (`llm` is `null`); the later flush dispatch writes a

src/stt_daemon/assistant/llm.py

@@ -8,6 +8,7 @@ import json
 import logging
 import os
 import threading
+import time
 import urllib.error
 import urllib.request
 from dataclasses import dataclass, field
@@ -157,6 +158,7 @@ class LlmClient:
                 on_io, {"phase": "request", "url": self.cfg.endpoint, "body": body}
             )
 
+        started = time.monotonic()
         try:
             payload = self._opener(
                 {
@@ -168,11 +170,28 @@ class LlmClient:
             )
         except (urllib.error.URLError, OSError, json.JSONDecodeError) as e:
             if on_io is not None:
-                _safe_io(on_io, {"phase": "response", "payload": None, "error": str(e)})
+                _safe_io(
+                    on_io,
+                    {
+                        "phase": "response",
+                        "payload": None,
+                        "error": str(e),
+                        "duration_ms": round((time.monotonic() - started) * 1000.0, 1),
+                    },
+                )
             raise LlmError(str(e)) from e
 
+        duration_ms = round((time.monotonic() - started) * 1000.0, 1)
         if on_io is not None:
-            _safe_io(on_io, {"phase": "response", "payload": payload, "error": None})
+            _safe_io(
+                on_io,
+                {
+                    "phase": "response",
+                    "payload": payload,
+                    "error": None,
+                    "duration_ms": duration_ms,
+                },
+            )
 
         choices = payload.get("choices") or []
         if not choices:

src/stt_daemon/assistant/service.py

@@ -1135,6 +1135,7 @@ class AssistantService:
                                 "request": None,
                                 "response": part.get("payload"),
                                 "error": part.get("error"),
+                                "duration_ms": part.get("duration_ms"),
                             },
                         )
                 io_hook = _record_io

tests/test_assistant_service.py

@@ -2215,7 +2215,14 @@ def _dump_brief(prompt, on_io=None, finalize=None):
     """Brief fake that mimics LlmClient.chat's on_io phases."""
     if on_io is not None:
         on_io({"phase": "request", "url": "http://llm/v1", "body": {"prompt": prompt}})
-        on_io({"phase": "response", "payload": {"content": "parsed"}, "error": None})
+        on_io(
+            {
+                "phase": "response",
+                "payload": {"content": "parsed"},
+                "error": None,
+                "duration_ms": 250.0,
+            }
+        )
     return _brief_reply("BRIEF")
 
 
@@ -2262,6 +2269,7 @@ def test_dump_writes_full_laya_and_llm_io(tmp_path):
     }
     assert data["llm"]["response"] == {"content": "parsed"}
     assert data["llm"]["error"] is None
+    assert data["llm"]["duration_ms"] == 250.0
     assert service._triage_dump._pending == {}
 
 

tests/test_llm.py

@@ -757,6 +757,18 @@ def test_on_io_receives_request_then_response():
     assert seen[1]["error"] is None
 
 
+def test_on_io_response_phase_reports_duration_ms():
+    """The response phase carries a non-negative float duration_ms."""
+    client, _ = _make_client(lambda _p: _reply(content="ok"))
+    seen: list[dict] = []
+
+    client.chat([{"role": "user", "content": "hi"}], on_io=seen.append)
+
+    assert "duration_ms" not in seen[0]  # request phase carries no timing
+    assert isinstance(seen[1]["duration_ms"], float)
+    assert seen[1]["duration_ms"] >= 0.0
+
+
 def test_on_io_response_phase_reports_opener_error():
     """An opener raising still yields a response phase with the error set."""
     import urllib.error
@@ -773,6 +785,8 @@ def test_on_io_response_phase_reports_opener_error():
     assert [event["phase"] for event in seen] == ["request", "response"]
     assert seen[1]["payload"] is None
     assert "down" in seen[1]["error"]
+    assert isinstance(seen[1]["duration_ms"], float)
+    assert seen[1]["duration_ms"] >= 0.0
 
 
 def test_raising_on_io_does_not_break_chat():

tests/test_triage_dump.py

@@ -107,6 +107,29 @@ def test_llm_response_phase_keeps_request(tmp_path):
     assert data["llm"]["error"] is None
 
 
+def test_llm_duration_ms_survives_response_merge(tmp_path):
+    """The response-phase record carries duration_ms alongside the payload."""
+    dumper = TriageDumper(True, directory=str(tmp_path))
+    dumper.begin(TS, laya={"request": {}, "response": {}, "error": None})
+    dumper.record(
+        TS, llm={"request": {"url": "u"}, "response": None, "error": None}
+    )
+    dumper.record(
+        TS,
+        llm={
+            "request": None,
+            "response": {"c": 1},
+            "error": None,
+            "duration_ms": 812.4,
+        },
+    )
+    dumper.finalize(TS)
+
+    data = json.loads(_only_file(tmp_path).read_text(encoding="utf-8"))
+    assert data["llm"]["duration_ms"] == 812.4
+    assert data["llm"]["request"] == {"url": "u"}
+
+
 def test_finalize_unknown_ts_is_noop(tmp_path):
     dumper = TriageDumper(True, directory=str(tmp_path))
     dumper.finalize(1234567890.0)