[eric] browser: record per-tool latency, tokens, and per-task completion metrics

backend/apps/agents/browser/browser_agent.py

@@ -33,6 +33,7 @@ from backend.apps.agents.browser.browser_loop import (
     stagnation_exhausted,
 )
 from backend.apps.agents.browser.browser_validator import adjudicate_stuck
+from backend.apps.agents.browser import browser_metrics
 from backend.apps.agents.browser.browser_schema import (
     _ACTION_TOOLS_REQUIRING_REPORT,
     ACTION_MAP,
@@ -269,6 +270,7 @@ async def run_browser_agent(
     messages: list[dict] = list(prior_messages) + [{"role": "user", "content": task}]
     action_log: list[dict] = []
     final_screenshot: str | None = None
+    metrics_started_at = time.time()  # wall-clock start for per-task timing
 
     # Loop detection state; sliding window of recent state-mutating tool calls
     recent_tool_calls: list[tuple[str, str, str]] = []
@@ -713,6 +715,14 @@ async def run_browser_agent(
                                 {"type": "text", "text": f"\n\n💡 Suggested next step: {guidance}"}
                                 ]
 
+                _ok = "error" not in result
+                browser_metrics.record_tool(
+                    session_id, browser_id, turn, tu.name, elapsed_ms,
+                    ok=_ok, error=result.get("error", ""),
+                    is_loop=is_loop, stagnation_streak=stagnation_streak,
+                    result_len=len(str(result.get("text") or result.get("error") or "")),
+                )
+
                 tool_results.append({
                     "type": "tool_result",
                     "tool_use_id": tu.id,
@@ -748,6 +758,8 @@ async def run_browser_agent(
 
         if cancel_event.is_set():
             session.status = "stopped"
+            browser_metrics.record_task(session_id, browser_id, task, "stopped",
+                                        metrics_started_at, turn + 1, action_log, session.tokens)
             await ws_manager.send_to_session(session_id, "agent:status", {
                 "session_id": session_id,
                 "status": "stopped",
@@ -785,6 +797,8 @@ async def run_browser_agent(
         )
 
         session.status = "completed"
+        browser_metrics.record_task(session_id, browser_id, task, "completed",
+                                    metrics_started_at, turn + 1, action_log, session.tokens)
         agent_manager._sync_session_close(session)
         await ws_manager.send_to_session(session_id, "agent:status", {
             "session_id": session_id,
@@ -803,6 +817,9 @@ async def run_browser_agent(
     except Exception as e:
         logger.exception(f"Browser agent {session_id} error: {e}")
         session.status = "error"
+        browser_metrics.record_task(session_id, browser_id, task, "error",
+                                    metrics_started_at, locals().get("turn", -1) + 1,
+                                    action_log, session.tokens)
         error_msg = Message(role="system", content=f"Error: {str(e)}")
         session.messages.append(error_msg)
         await ws_manager.send_to_session(session_id, "agent:message", {

backend/apps/agents/browser/browser_metrics.py

@@ -0,0 +1,144 @@
+"""
+Granular, persisted metrics for the browser sub-agent.
+
+Records one JSONL line per tool call and one summary line per task so we can
+answer, after the fact: did the task complete, how long did each tool take,
+how many tokens (cost) it burned, which tier did the work, and what errors
+recurred. Pure best-effort: every call is wrapped so a metrics failure can
+never break the agent loop.
+
+Files (under DATA_ROOT/browser_metrics/, env-overridable):
+  events.jsonl    one line per tool call
+  tasks.jsonl     one line per finished task (with a recurring-error rollup)
+"""
+
+import json
+import logging
+import os
+import time
+from collections import Counter
+
+logger = logging.getLogger(__name__)
+
+# Map each tool to the waterfall tier it represents, so per-tier speed/cost
+# rolls up cleanly. Control/meta tools are their own bucket.
+_TIER = {
+    "BrowserDetectWebMCP": "t1_webmcp",
+    "BrowserListRoutes": "t2_route_list",
+    "BrowserReplayRoute": "t2_route_replay",
+    "BrowserListInteractives": "t3_action_surface",
+    "BrowserClickIndex": "t3_action_surface",
+    "BrowserGetText": "t4_content",
+    "BrowserGetElements": "t4_content",
+    "BrowserScreenshot": "t5_vision",
+    "BrowserNavigate": "nav",
+    "BrowserClick": "ui_click",
+    "BrowserType": "ui_type",
+    "BrowserPressKey": "ui_key",
+    "BrowserScroll": "ui_scroll",
+    "BrowserBatch": "ui_batch",
+    "BrowserEvaluate": "ui_eval",
+    "BrowserWait": "wait",
+    "ReportProgress": "meta",
+    "RequestHumanIntervention": "meta_hitl",
+}
+
+
+def tier_for(tool_name: str) -> str:
+    return _TIER.get(tool_name, "other")
+
+
+def _metrics_dir() -> str:
+    override = os.environ.get("OPENSWARM_BROWSER_METRICS_DIR")
+    if override:
+        base = override
+    else:
+        try:
+            from backend.config.paths import DATA_ROOT
+            base = os.path.join(DATA_ROOT, "browser_metrics")
+        except Exception:
+            import tempfile
+            base = os.path.join(tempfile.gettempdir(), "openswarm_browser_metrics")
+    try:
+        os.makedirs(base, exist_ok=True)
+    except Exception:
+        pass
+    return base
+
+
+def _append(filename: str, obj: dict) -> None:
+    try:
+        path = os.path.join(_metrics_dir(), filename)
+        with open(path, "a", encoding="utf-8") as f:
+            f.write(json.dumps(obj, default=str) + "\n")
+    except Exception as e:
+        logger.debug(f"[browser-metrics] write failed: {e}")
+
+
+def record_tool(session_id, browser_id, turn, tool, elapsed_ms, ok, error,
+                is_loop, stagnation_streak, result_len) -> None:
+    """One line per executed tool call. Best-effort."""
+    _append("events.jsonl", {
+        "ts": time.time(),
+        "session_id": session_id,
+        "browser_id": browser_id,
+        "turn": turn,
+        "tool": tool,
+        "tier": tier_for(tool),
+        "elapsed_ms": elapsed_ms,
+        "ok": bool(ok),
+        "error": (error or "")[:160] if not ok else "",
+        "is_loop": bool(is_loop),
+        "stagnation_streak": stagnation_streak,
+        "result_len": result_len,
+    })
+    # Human-greppable one-liner too, so it shows in the [backend] terminal pane.
+    status = "OK" if ok else "ERR"
+    logger.info(
+        f"[browser-metrics] {tool} tier={tier_for(tool)} {elapsed_ms}ms {status} "
+        f"turn={turn}{' LOOP' if is_loop else ''}"
+        f"{f' STAGN={stagnation_streak}' if stagnation_streak else ''}"
+    )
+
+
+def record_task(session_id, browser_id, task, status, started_at, turns,
+                action_log, tokens) -> dict:
+    """One summary line per finished task: completion, total time, per-tier
+    latency, token cost, and the recurring-error rollup. Returns the summary."""
+    total_ms = int((time.time() - started_at) * 1000)
+    by_tier = {}
+    err_counter = Counter()
+    for a in action_log:
+        tool = a.get("tool", "?")
+        tier = tier_for(tool)
+        slot = by_tier.setdefault(tier, {"calls": 0, "total_ms": 0, "errors": 0})
+        slot["calls"] += 1
+        slot["total_ms"] += int(a.get("elapsed_ms", 0) or 0)
+        rs = str(a.get("result_summary", ""))
+        if rs.lower().startswith("error") or "not found" in rs.lower() or "no longer valid" in rs.lower():
+            slot["errors"] += 1
+            err_counter[rs[:80]] += 1
+    for slot in by_tier.values():
+        slot["avg_ms"] = round(slot["total_ms"] / slot["calls"], 1) if slot["calls"] else 0
+    summary = {
+        "ts": time.time(),
+        "session_id": session_id,
+        "browser_id": browser_id,
+        "task": (task or "")[:200],
+        "status": status,
+        "completed": status == "completed",
+        "total_ms": total_ms,
+        "turns": turns,
+        "tool_calls": len(action_log),
+        "tokens_in": (tokens or {}).get("input", 0),
+        "tokens_out": (tokens or {}).get("output", 0),
+        "by_tier": by_tier,
+        "recurring_errors": err_counter.most_common(5),
+    }
+    _append("tasks.jsonl", summary)
+    logger.info(
+        f"[browser-metrics] TASK {status} total={total_ms}ms turns={turns} "
+        f"tools={len(action_log)} tok_in={summary['tokens_in']} tok_out={summary['tokens_out']} "
+        f"recurring_errs={summary['recurring_errors'][:2]}"
+    )
+    return summary

backend/tests/test_browser_metrics.py

@@ -0,0 +1,85 @@
+"""Persisted browser metrics: tier mapping, event + task recording, rollups."""
+
+import json
+import os
+import tempfile
+
+import pytest
+
+
+@pytest.fixture()
+def metrics(monkeypatch):
+    d = tempfile.mkdtemp(prefix="bm_test_")
+    monkeypatch.setenv("OPENSWARM_BROWSER_METRICS_DIR", d)
+    from backend.apps.agents.browser import browser_metrics as bm
+    return bm, d
+
+
+def _read(d, name):
+    p = os.path.join(d, name)
+    if not os.path.exists(p):
+        return []
+    with open(p) as f:
+        return [json.loads(line) for line in f if line.strip()]
+
+
+def test_tier_mapping(metrics):
+    bm, _ = metrics
+    assert bm.tier_for("BrowserListInteractives") == "t3_action_surface"
+    assert bm.tier_for("BrowserClickIndex") == "t3_action_surface"
+    assert bm.tier_for("BrowserScreenshot") == "t5_vision"
+    assert bm.tier_for("BrowserReplayRoute") == "t2_route_replay"
+    assert bm.tier_for("BrowserDetectWebMCP") == "t1_webmcp"
+    assert bm.tier_for("BrowserGetText") == "t4_content"
+    assert bm.tier_for("SomethingNew") == "other"
+
+
+def test_record_tool_writes_event(metrics):
+    bm, d = metrics
+    bm.record_tool("s1", "b1", 2, "BrowserListInteractives", 18,
+                   ok=True, error="", is_loop=False, stagnation_streak=0, result_len=120)
+    events = _read(d, "events.jsonl")
+    assert len(events) == 1
+    e = events[0]
+    assert e["tool"] == "BrowserListInteractives" and e["tier"] == "t3_action_surface"
+    assert e["elapsed_ms"] == 18 and e["ok"] is True and e["error"] == ""
+
+
+def test_record_tool_captures_error(metrics):
+    bm, d = metrics
+    bm.record_tool("s1", "b1", 3, "BrowserClickIndex", 9,
+                   ok=False, error="Index 4 is no longer valid", is_loop=True,
+                   stagnation_streak=2, result_len=40)
+    e = _read(d, "events.jsonl")[0]
+    assert e["ok"] is False and "no longer valid" in e["error"]
+    assert e["is_loop"] is True and e["stagnation_streak"] == 2
+
+
+def test_record_task_summary_and_rollups(metrics):
+    bm, d = metrics
+    action_log = [
+        {"tool": "BrowserListInteractives", "elapsed_ms": 20, "result_summary": "5 interactive elements"},
+        {"tool": "BrowserClickIndex", "elapsed_ms": 10, "result_summary": "Clicked index 1"},
+        {"tool": "BrowserClickIndex", "elapsed_ms": 8, "result_summary": "Error: Index 2 not found"},
+        {"tool": "BrowserScreenshot", "elapsed_ms": 40, "result_summary": "Screenshot captured"},
+    ]
+    summary = bm.record_task("s1", "b1", "do a thing", "completed", __import__("time").time() - 1.2,
+                             6, action_log, {"input": 1500, "output": 300})
+    assert summary["completed"] is True and summary["status"] == "completed"
+    assert summary["tool_calls"] == 4 and summary["tokens_in"] == 1500
+    t3 = summary["by_tier"]["t3_action_surface"]
+    assert t3["calls"] == 3 and t3["errors"] == 1 and t3["avg_ms"] > 0
+    assert summary["by_tier"]["t5_vision"]["calls"] == 1
+    assert summary["total_ms"] >= 1000  # ~1.2s elapsed
+    assert any("not found" in err[0].lower() for err in summary["recurring_errors"])
+    tasks = _read(d, "tasks.jsonl")
+    assert len(tasks) == 1 and tasks[0]["status"] == "completed"
+
+
+def test_metrics_never_raises_on_bad_dir(monkeypatch):
+    # An unwritable dir must not throw into the agent loop.
+    monkeypatch.setenv("OPENSWARM_BROWSER_METRICS_DIR", "/proc/cannot/write/here")
+    from backend.apps.agents.browser import browser_metrics as bm
+    bm.record_tool("s", "b", 1, "BrowserScreenshot", 5, ok=True, error="",
+                   is_loop=False, stagnation_streak=0, result_len=1)  # must not raise
+    bm.record_task("s", "b", "t", "error", __import__("time").time(), 1, [], {})