From a8964830ace3e63f14d82f4feda384043af2bd58 Mon Sep 17 00:00:00 2001 From: ciregenz Date: Tue, 2 Jun 2026 12:12:41 -0700 Subject: [PATCH] [eric] browser: record per-tool latency, tokens, and per-task completion metrics --- backend/apps/agents/browser/browser_agent.py | 17 +++ .../apps/agents/browser/browser_metrics.py | 144 ++++++++++++++++++ backend/tests/test_browser_metrics.py | 85 +++++++++++ 3 files changed, 246 insertions(+) create mode 100644 backend/apps/agents/browser/browser_metrics.py create mode 100644 backend/tests/test_browser_metrics.py diff --git a/backend/apps/agents/browser/browser_agent.py b/backend/apps/agents/browser/browser_agent.py index 8cbdb7f3..1248daa1 100644 --- a/backend/apps/agents/browser/browser_agent.py +++ b/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", { diff --git a/backend/apps/agents/browser/browser_metrics.py b/backend/apps/agents/browser/browser_metrics.py new file mode 100644 index 00000000..3402cc14 --- /dev/null +++ b/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 diff --git a/backend/tests/test_browser_metrics.py b/backend/tests/test_browser_metrics.py new file mode 100644 index 00000000..456519a4 --- /dev/null +++ b/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, [], {})