"""Dona CLI streaming and timing bridge (Python standard library only). Does not access Hermes sessions or modify MCP config. Retains the terminal JSONL result envelope for the existing _parse_jsonl implementation. """ from __future__ import annotations import json import logging import os import signal import subprocess import threading import time import uuid _LOG = logging.getLogger("dona.hermes.performance") _EMITTER = None _EMITTER_LOCK = threading.Lock() _FALSE = {"0", "false", "no", "off", "disabled"} def configure_emitter(emitter): """Register Flask-SocketIO event emitter once, after socketio is created.""" global _EMITTER with _EMITTER_LOCK: _EMITTER = emitter def _enabled(name: str, default: str = "on") -> bool: return os.environ.get(name, default).strip().lower() not in _FALSE def _publish(msg): if not _enabled("DONA_HERMES_STREAM_UI", "on"): return with _EMITTER_LOCK: fn = _EMITTER if fn is not None: try: fn(msg) except Exception: # A browser disconnect must never corrupt an Hermes turn/session. _LOG.debug("Dona UI emitter failed", exc_info=True) def run_jsonl_command(cmd, prompt, timeout): """Compatibility replacement for subprocess.run used only by _call_hermes. Publishes deltas/tool names while keeping exact final JSONL parsing behavior. Fallback to the historical subprocess.run with DONA_HERMES_STREAM_CLI=off. """ if not _enabled("DONA_HERMES_STREAM_CLI", "on"): return subprocess.run( cmd, input=prompt, capture_output=True, text=True, timeout=timeout, check=False, ) request_id = uuid.uuid4().hex[:12] start = time.monotonic() first_text_ms = None first_event_ms = None first_tool_ms = None last_tool_done_ms = None active_tools = [] finished_tools = 0 # Report only name/timing/outcome. Never log MCP arguments, outputs or prompts. tool_count = 0 text_fragments = 0 emitted_characters = 0 pending_text = "" last_emit = start final_seen = False # Keep only records the existing parser consumes, rather than potentially # huge tool inputs/outputs and all intermediate assistant deltas. output_records = [] stderr_records = [] deadline_hit = threading.Event() proc = None timer = None _publish({"type": "start", "id": request_id}) def expire(): deadline_hit.set() if proc is not None and proc.poll() is None: try: # subprocess in its own session: children of this CLI turn # cannot linger after an actual timeout. os.killpg(proc.pid, signal.SIGKILL) except (ProcessLookupError, PermissionError, OSError): try: proc.kill() except OSError: pass def collect_stderr(): try: data = proc.stderr.read() if data: stderr_records.append(data) except Exception: pass try: proc = subprocess.Popen( cmd, stdin=subprocess.PIPE, stdout=subprocess.PIPE, stderr=subprocess.PIPE, text=True, bufsize=1, start_new_session=True, ) timer = threading.Timer(float(timeout), expire) timer.daemon = True timer.start() stderr_thread = threading.Thread(target=collect_stderr, daemon=True) stderr_thread.start() try: proc.stdin.write(prompt) except BrokenPipeError: pass finally: try: proc.stdin.close() except OSError: pass for line in proc.stdout: try: event = json.loads(line) except (ValueError, TypeError): # Preserve unrecognized lines to aid existing error diagnostics. continue if not isinstance(event, dict): continue kind = event.get("type") now = time.monotonic() if first_event_ms is None: first_event_ms = round((now - start) * 1000, 1) if kind == "system" and event.get("subtype") == "init": output_records.append(line) elif kind == "text": delta = event.get("text") if isinstance(delta, str) and delta: text_fragments += 1 if first_text_ms is None: first_text_ms = round((now - start) * 1000, 1) _publish({"type": "first_text", "id": request_id, "first_text_ms": first_text_ms}) # Emit batched, rather than one websocket event/token. pending_text += delta if (now - last_emit) >= .12 or len(pending_text) >= 240: _publish({"type": "delta", "id": request_id, "text": pending_text}) emitted_characters += len(pending_text) pending_text = "" last_emit = now elif kind == "tool_use": tool_count += 1 if first_tool_ms is None: first_tool_ms = round((now - start) * 1000, 1) name = str(event.get("name") or "outil")[:90] # Events may use either a tool_call_id, id or no ID at all. tool_id = event.get("tool_call_id") or event.get("id") active_tools.append({"name": name, "id": tool_id, "start": now, "sequence": tool_count}) _LOG.warning("[DONA-TOOL] id=%s index=%s name=%s phase=start at_ms=%.1f", request_id, tool_count, name, (now-start)*1000) # Do not send tool arguments, user tokens, or raw tool outputs. _publish({"type": "tool", "id": request_id, "name": name}) elif kind == "tool_result": name = str(event.get("name") or "outil")[:90] tool_id = event.get("tool_call_id") or event.get("tool_use_id") or event.get("id") matched = None # Prefer a matching tool ID; fallback to matching name, then oldest. if tool_id is not None: matched = next((i for i, t in enumerate(active_tools) if t["id"] == tool_id), None) if matched is None: matched = next((i for i, t in enumerate(active_tools) if t["name"] == name), None) if matched is None and active_tools: matched = 0 record = active_tools.pop(matched) if matched is not None else None if name == "outil" and record is not None: name = record["name"] measured_ms = round((now-record["start"])*1000, 1) if record else None reported_ms = event.get("duration_ms") if isinstance(reported_ms, bool) or not isinstance(reported_ms, (float, int)): reported_ms = None failed = bool(event.get("is_error")) last_tool_done_ms = round((now-start)*1000, 1) finished_tools += 1 _LOG.warning("[DONA-TOOL] id=%s index=%s name=%s phase=end at_ms=%.1f elapsed_ms=%s server_ms=%s error=%s", request_id, record["sequence"] if record else "?", name, last_tool_done_ms, measured_ms, reported_ms, failed) _publish({"type": "tool_done", "id": request_id, "name": name, "duration_ms": reported_ms if reported_ms is not None else measured_ms, "error": failed}) elif kind == "result": final_seen = True output_records.append(line) rc = proc.wait() stderr_thread.join(timeout=1.0) total_ms = round((time.monotonic() - start) * 1000, 1) if deadline_hit.is_set(): _publish({"type": "error", "id": request_id, "reason": "timeout"}) raise subprocess.TimeoutExpired(cmd, timeout, output="".join(output_records), stderr="".join(stderr_records)) if pending_text: _publish({"type": "delta", "id": request_id, "text": pending_text}) emitted_characters += len(pending_text) _publish({"type": "end", "id": request_id, "total_ms": total_ms, "first_text_ms": first_text_ms, "ok": rc == 0 and final_seen}) _LOG.warning( "[DONA-PERF] hermes_cli id=%s total_ms=%s first_event_ms=%s " "first_tool_ms=%s last_tool_done_ms=%s first_text_ms=%s " "tools=%s tool_results=%s unfinished_tools=%s " "fragments=%s ui_chars=%s exit=%s final=%s", request_id, total_ms, first_event_ms, first_tool_ms, last_tool_done_ms, first_text_ms, tool_count, finished_tools, len(active_tools), text_fragments, emitted_characters, rc, final_seen, ) # Keep final result + init events exactly as _parse_jsonl expects. return subprocess.CompletedProcess( cmd, rc, "".join(output_records), "".join(stderr_records) ) except Exception: if not deadline_hit.is_set(): _publish({"type": "error", "id": request_id, "reason": "process_error"}) raise finally: if timer: timer.cancel() if proc is not None: if proc.poll() is None: try: os.killpg(proc.pid, signal.SIGKILL) except (ProcessLookupError, PermissionError, OSError): try: proc.kill() except OSError: pass for pipe in (proc.stdin, proc.stdout, proc.stderr): try: pipe.close() except (OSError, ValueError): pass