Add /api/timeline: compact per-turn latency/sync summary (last 10 turns, ?full=1 for every line) so results can be copied without scraping the Space log viewer

app.py

@@ -4,7 +4,7 @@ Avatar profile system: each avatar has ref.png, persona.txt, idlevideos/
 Chunked pipeline: LLM (once) → split sentences → TTS+FLOAT per chunk → stream to frontend
 """
 from fastapi import FastAPI, HTTPException, Request, WebSocket, WebSocketDisconnect
-from fastapi.responses import HTMLResponse, StreamingResponse, JSONResponse
+from fastapi.responses import HTMLResponse, StreamingResponse, JSONResponse, PlainTextResponse
 from pathlib import Path
 import mimetypes
 import os
@@ -901,6 +901,14 @@ async def interrupt():
     return JSONResponse({"status": "ok"})
 
 
+@app.get("/api/timeline")
+async def get_timeline(full: int = 0):
+    """Compact per-turn latency/sync summary for the last 10 turns — open in a
+    browser tab and copy, instead of scraping the Space's log viewer.
+    ?full=1 adds every timeline line under each turn."""
+    return PlainTextResponse(timeline.summary(full=bool(full)))
+
+
 @app.post("/api/timing")
 async def client_timing(request: Request):
     """Client-side playback milestones, logged into the same turn timeline so
@@ -916,6 +924,7 @@ async def client_timing(request: Request):
             f"(waited {b.get('queued_ms', 0):.0f}ms for previous clip + {b.get('load_ms', 0):.0f}ms loading"
             f"{', preloaded' if b.get('preloaded') else ', NOT preloaded'}) "
             f"= how far audio lags its video", turn)
+        timeline.stat("lags", (b.get("since_start_ms", 0), bool(b.get("preloaded"))), turn)
     elif ev == "audio_end":
         timeline.mark(f"{tag} CLIENT audio ended (played {b.get('played_ms', 0)/1000:.2f}s)", turn)
     return JSONResponse({"status": "ok"})
@@ -964,6 +973,8 @@ async def ws_video(websocket: WebSocket):
                 await websocket.send_json(item)
                 if item.get("type") == "speech_start":
                     timeline.mark(f"{item.get('tag')} speech_start sent to client — its video frames follow now", item.get("turn"))
+                    if str(item.get("tag", "")).startswith("c1/"):
+                        timeline.stat("video_start", timeline.elapsed(), item.get("turn"))
                 elif item.get("type") == "speech_end":
                     timeline.mark("speech_end sent to client", item.get("turn"))
                 continue
@@ -1084,6 +1095,9 @@ async def _chat_stream_process_chunk(idx: int, total: int, sentence: str, stream
     timeline.mark(
         f"{tag} TTS done in {t_b-t_a:.2f}s ({audio_duration:.1f}s audio)" if audio_path
         else f"{tag} TTS FAILED after {t_b-t_a:.2f}s", turn)
+    if idx == 0:
+        timeline.stat("c1_tts", t_b - t_a, turn)
+        timeline.stat("c1_audio", audio_duration, turn)
 
     if gen_id != _generation_id:
         timeline.mark(f"{tag} stale (interrupted mid-flight) — discarding", turn)
@@ -1158,6 +1172,7 @@ async def chat_stream(request: Request):
     clean_text = llm_result.get('clean_text', reply_text)
     t2 = _time.time()
     timeline.mark(f"LLM done in {t2-t1:.2f}s: \"{clean_text[:80]}...\"", turn)
+    timeline.stat("llm", t2 - t1, turn)
 
     # 2. Split into short chunks (~12 words each) so the first chunk's TTS
     # call is small and fast instead of synthesizing the entire reply.
@@ -1166,6 +1181,7 @@ async def chat_stream(request: Request):
         sentences = [reply_text]
     total = len(sentences)
     timeline.mark(f"reply split into {total} chunk(s)", turn)
+    timeline.stat("chunks", total, turn)
 
     from float_streamer import get_streamer
     streamer = get_streamer()

float_streamer.py

@@ -398,6 +398,8 @@ class FloatStreamer:
             # rendering is AHEAD of playback, not behind it.
             took = t_dec_done - t0 - t_wait
             slow = f" ⚠ SLOWER THAN REAL TIME ({took/video_s:.2f}x)" if video_s and took > video_s else ""
+            if slow:
+                timeline.stat("slow_renders", 1, turn)
             timeline.mark(
                 f"{tag} rendered {frames_pushed} frames ({video_s:.2f}s video) in {took:.2f}s "
                 f"[ode {t_ode:.2f}s, decode {t_dec_done-t_dec-t_wait:.2f}s, waited {t_wait:.2f}s for buffer space]{slow}", turn)

timeline.py

@@ -8,7 +8,12 @@ where T3 is the turn number and +1.42s is time since the user's message
 arrived, so a copied log reads top-to-bottom as an ordered breakdown of where
 the time went. Shared by app.py (request side) and float_streamer.py
 (render thread), hence its own module.
+
+The last few turns are also kept in memory (lines + key stats) so /api/timeline
+can serve a compact per-turn summary — the Space's log viewer is too long to
+copy/paste whole.
 """
+import collections
 import logging
 import time
 
@@ -16,6 +21,19 @@ logger = logging.getLogger("timeline")
 
 _turn = 0
 _t0 = time.time()
+_history = collections.deque(maxlen=10)  # recent turns: {turn, label, lines, stats}
+_by_turn = {}
+
+
+def _entry(turn):
+    e = _by_turn.get(turn)
+    if e is None:
+        e = {"turn": turn, "label": "", "lines": [], "stats": {"lags": []}}
+        if len(_history) == _history.maxlen:
+            _by_turn.pop(_history[0]["turn"], None)
+        _history.append(e)
+        _by_turn[turn] = e
+    return e
 
 
 def begin(label: str) -> int:
@@ -23,7 +41,10 @@ def begin(label: str) -> int:
     global _turn, _t0
     _turn += 1
     _t0 = time.time()
-    logger.info(f"[T{_turn} +  0.00s] ===== TURN START: {label}")
+    _entry(_turn)["label"] = label
+    line = f"[T{_turn} +  0.00s] ===== TURN START: {label}"
+    _entry(_turn)["lines"].append(line)
+    logger.info(line)
     return _turn
 
 
@@ -31,11 +52,57 @@ def current() -> int:
     return _turn
 
 
+def elapsed() -> float:
+    return time.time() - _t0
+
+
 def mark(msg: str, turn: int = None):
     """Log one stage of the current turn. A mark tagged with an older turn
     (e.g. a late client report after barge-in) is labelled as such, since its
     offset is measured against the newer turn's start."""
     if turn is not None and turn != _turn:
-        logger.info(f"[T{turn} (late, now T{_turn})] {msg}")
+        line = f"[T{turn} (late, now T{_turn})] {msg}"
+        target = turn
+    else:
+        line = f"[T{_turn} +{elapsed():6.2f}s] {msg}"
+        target = _turn
+    _entry(target)["lines"].append(line)
+    logger.info(line)
+
+
+def stat(key: str, value, turn: int = None):
+    """Record a summary number for a turn (ignored for stale turns)."""
+    if turn is not None and turn != _turn:
         return
-    logger.info(f"[T{_turn} +{time.time() - _t0:6.2f}s] {msg}")
+    stats = _entry(_turn)["stats"]
+    if key == "lags":
+        stats["lags"].append(value)
+    elif key == "slow_renders":
+        stats["slow_renders"] = stats.get("slow_renders", 0) + 1
+    else:
+        stats.setdefault(key, value)  # first occurrence wins
+
+
+def summary(full: bool = False) -> str:
+    out = []
+    for e in list(_history):
+        if e["turn"] == 0 and not e["lines"]:
+            continue
+        s = e["stats"]
+        parts = [f"T{e['turn']} {e['label'][:60] or '(startup / greeting)'}"]
+        if "llm" in s: parts.append(f"LLM {s['llm']:.2f}s")
+        if "chunks" in s: parts.append(f"{s['chunks']} chunks")
+        if "c1_tts" in s: parts.append(f"c1 TTS {s['c1_tts']:.2f}s ({s.get('c1_audio', 0):.1f}s audio)")
+        if "video_start" in s: parts.append(f"video starts +{s['video_start']:.2f}s")
+        if "video_start" in s and s["lags"]:
+            # c1's lag is measured client-side, so this avoids the report's own network delay
+            parts.append(f"audio starts +{s['video_start'] + s['lags'][0][0] / 1000:.2f}s")
+        if s["lags"]:
+            parts.append("A/V lag per chunk: " + " ".join(
+                f"{ms:.0f}ms{'' if pre else '(not preloaded)'}" for ms, pre in s["lags"]))
+        parts.append(f"slow renders: {s.get('slow_renders', 0)}")
+        out.append(" | ".join(parts))
+        if full:
+            out += ["    " + l for l in e["lines"]]
+            out.append("")
+    return "\n".join(out) or "(no turns yet)"