box/bin/host_evidence.py

#!/usr/bin/env python3
"""Host-side fleet evidence for network/PID-blind shells.

`box fleet status` probes each node live (pgrep for the chromium process,
HTTP to the CDP relay on the peer IP). Both probes assume the caller's
network + PID namespace is the bl host's. From a sandboxed shell (own PID
and net namespaces, no sudo, no route to 10.201.x.x) both probes always
fail, so every node misreports as STOPPED even with a healthy fleet.

This module provides the fallback signal: evidence written by the
host-side watchdogs that run on bl unsandboxed via systemd timers:

  - cdp-relay-watchdog (every 5 min, all active registry nodes):
    log ``cdp-relay-watchdog.log`` + journal unit
    ``cdp-relay-watchdog.service``. Proves the CDP relay path end to end.
  - chromebox-watchdog (every 2 min, same nodes, one timer per node):
    log ``chromebox-watchdog.log`` + journal units
    ``chromebox-watchdog@<node>.service``. Curls CDP inside the node netns,
    so it proves browser + in-netns CDP.
  - ``chromebox-<node>.log`` mtime: chromium's own stdout. Fresh output
    proves the browser process is alive. Used only for nodes outside
    watchdog coverage — and only to conclude "alive", never "dead".

Both watchdogs are silent-when-healthy: a failure is ALWAYS logged, so a
recent timer run (journal "Starting" line) with no newer failure line for
the node means that run found the node healthy.

Verdicts: "healthy" | "degraded" | "down" | "unknown".
"""

import json
import os
import re
import subprocess
import time
from datetime import datetime, timezone
from pathlib import Path

NETVM_ROOT = Path("/home/super/Projects/NetVM")
RELAY_LOG = NETVM_ROOT / "cdp-relay-watchdog.log"
CHROMEBOX_LOG = NETVM_ROOT / "chromebox-watchdog.log"

ALL_NODES = ("muse", "pip", "646", "opm", "def", "dev")


def _covered_nodes():
    """Nodes with watchdog coverage, from the fleet registry.

    Both watchdogs supervise every active registry node. Falls back to
    ALL_NODES when the registry is unreadable, so a broken registry can
    never silently narrow fleet status to a subset of the fleet.
    """
    try:
        import importlib.util
        spec = importlib.util.spec_from_file_location(
            "netvm_registry", NETVM_ROOT / "bin" / "netvm-registry.py")
        mod = importlib.util.module_from_spec(spec)
        spec.loader.exec_module(mod)
        return tuple(sorted(mod.active_nodes()))
    except Exception:
        return ALL_NODES


RELAY_NODES = _covered_nodes()
CHROMEBOX_NODES = _covered_nodes()

RELAY_UNIT = "cdp-relay-watchdog.service"
CHROMEBOX_UNIT_TMPL = "chromebox-watchdog@{node}.service"

# A watchdog run older than this proves nothing (timer may be dead).
RELAY_STALE_MIN = 15
CHROMEBOX_STALE_MIN = 8
# Chromium stdout older than this proves nothing (idle browsers go quiet).
CHROME_LOG_FRESH_MIN = 20

_LOG_TS_RE = re.compile(r"^\[(\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2})Z\]")


def _utcnow():
    return datetime.now(timezone.utc)


def parse_log_ts(line):
    """Parse a ``[YYYY-MM-DDTHH:MM:SSZ]`` log prefix. None if absent."""
    m = _LOG_TS_RE.match(line)
    if not m:
        return None
    try:
        return datetime.strptime(m.group(1), "%Y-%m-%dT%H:%M:%S").replace(
            tzinfo=timezone.utc)
    except ValueError:
        return None


def classify_chromebox_line(line):
    """Classify one chromebox-watchdog log line.

    Returns "healthy" | "degraded" | "down", or None when the line
    carries no verdict (rotation markers, relay stdout passthrough).
    """
    if "log rotated" in line:
        return None
    if "relaunch FAILED" in line:
        return "down"
    if "relaunch OK" in line:
        return "healthy"
    if "recovered" in line and "relaunch not needed" in line:
        return "healthy"
    if "not healthy yet" in line:
        return "degraded"
    if "proceeding with chrome relaunch" in line:
        return "degraded"
    if "relaunching chromebox" in line:
        return "degraded"
    if "warp partition detected" in line:
        return "degraded"
    if "skipping relaunch (probably still starting)" in line:
        return "degraded"
    return None


def classify_relay_line(line):
    """Classify one cdp-relay-watchdog log line (None = no verdict)."""
    if "relay restart FAILED" in line:
        return "down"
    if "FAIL_LOUD" in line:
        return "down"
    if "relay restarted OK" in line:
        return "healthy"
    if "relay unhealthy" in line and "restarting" in line:
        # Always followed by an OK/FAILED line; a trailing one means the
        # restart crashed mid-flight.
        return "down"
    return None


def last_verdict(lines, node, classify):
    """Newest (verdict, ts, line) for ``[node]``. None if no verdict line."""
    tag = "[%s]" % node
    best = None
    for line in lines:
        if tag not in line:
            continue
        verdict = classify(line)
        if verdict is None:
            continue
        ts = parse_log_ts(line)
        if ts is None:
            continue
        if best is None or ts >= best[1]:
            best = (verdict, ts, line.strip()[:160])
    return best


def _tail_lines(path, max_bytes=65536):
    try:
        size = os.path.getsize(path)
        with open(path, "rb") as f:
            if size > max_bytes:
                f.seek(size - max_bytes)
                f.readline()  # drop partial first line
            return f.read().decode("utf-8", errors="replace").splitlines()
    except OSError:
        return []


def query_journal_starts(units, since_min=25, timeout=20):
    """Map each unit -> newest run-start (aware UTC). Missing on failure.

    Uses ``-o json``: the short-format "Starting" line carries the unit
    description, not the unit name, so exact per-unit matching needs the
    structured UNIT field.
    """
    cmd = ["journalctl", "--no-pager", "-o", "json",
           "--since", "%d min ago" % since_min]
    for u in units:
        cmd.extend(["-u", u])
    try:
        r = subprocess.run(cmd, capture_output=True, text=True, timeout=timeout)
    except (OSError, subprocess.TimeoutExpired):
        return {}
    if r.returncode != 0:
        return {}
    want = set(units)
    starts = {}
    for line in (r.stdout or "").splitlines():
        try:
            e = json.loads(line)
        except ValueError:
            continue
        if e.get("UNIT") not in want:
            continue
        if not (e.get("MESSAGE") or "").startswith("Starting"):
            continue
        try:
            ts = datetime.fromtimestamp(
                int(e["__REALTIME_TIMESTAMP"]) / 1e6, tz=timezone.utc)
        except (KeyError, ValueError, TypeError, OverflowError):
            continue
        u = e["UNIT"]
        if u not in starts or ts > starts[u]:
            starts[u] = ts
    return starts


def _verdict_since_run(verdict_row, run_ts):
    """True when the verdict line is newer than (or from) the last run."""
    if verdict_row is None or run_ts is None:
        return False
    return verdict_row[1] >= run_ts


def browser_verdict(node, chromebox_lines, run_ts, chrome_log_mtime=None,
                    now=None):
    """(verdict, detail) for the node's browser process."""
    now = now or _utcnow()
    row = last_verdict(chromebox_lines, node, classify_chromebox_line)
    if node in CHROMEBOX_NODES:
        if run_ts is None:
            return ("unknown", "no chromebox-watchdog run in journal window")
        if (now - run_ts).total_seconds() > CHROMEBOX_STALE_MIN * 60:
            return ("unknown", "chromebox-watchdog run is stale")
        if _verdict_since_run(row, run_ts):
            return (row[0], "watchdog: %s" % row[2])
        return ("healthy", "watchdog run silent (silent-when-healthy)")
    # Nodes outside watchdog coverage: chromium stdout proves alive only.
    if chrome_log_mtime is not None and (
            now - chrome_log_mtime).total_seconds() < CHROME_LOG_FRESH_MIN * 60:
        return ("healthy", "chromebox-%s.log fresh" % node)
    return ("unknown", "no watchdog coverage for %s" % node)


def cdp_verdict(node, relay_lines, run_ts, now=None):
    """(verdict, detail) for the node's host-reachable CDP relay path."""
    now = now or _utcnow()
    if node not in RELAY_NODES:
        return ("unknown", "no relay-monitor coverage for %s" % node)
    if run_ts is None:
        return ("unknown", "no cdp-relay-watchdog run in journal window")
    if (now - run_ts).total_seconds() > RELAY_STALE_MIN * 60:
        return ("unknown", "cdp-relay-watchdog run is stale")
    row = last_verdict(relay_lines, node, classify_relay_line)
    if _verdict_since_run(row, run_ts):
        return (row[0], "relay watchdog: %s" % row[2])
    return ("healthy", "relay watchdog run silent (silent-when-healthy)")


def chrome_log_mtime(node):
    """Mtime of chromium's stdout log as aware UTC. None if missing."""
    try:
        return datetime.fromtimestamp(
            os.path.getmtime(NETVM_ROOT / ("chromebox-%s.log" % node)),
            tz=timezone.utc)
    except OSError:
        return None


_CACHE = {"at": 0.0, "nodes": frozenset(), "data": {}}
_CACHE_TTL_S = 60


def collect(nodes=None, _journal_starts=None, _relay_lines=None,
            _chromebox_lines=None, _chrome_mtimes=None, _now=None):
    """Per-node host evidence. Underscore args are seams for tests."""
    nodes = list(nodes or ALL_NODES)
    live = (_journal_starts is None and _relay_lines is None
            and _chromebox_lines is None and _chrome_mtimes is None
            and _now is None)
    if live:
        key = frozenset(nodes)
        if (key <= _CACHE["nodes"]
                and time.monotonic() - _CACHE["at"] < _CACHE_TTL_S):
            return {n: _CACHE["data"][n] for n in nodes if n in _CACHE["data"]}
    now = _now or _utcnow()
    if _journal_starts is None:
        units = [RELAY_UNIT] + [CHROMEBOX_UNIT_TMPL.format(node=n)
                                for n in nodes if n in CHROMEBOX_NODES]
        _journal_starts = query_journal_starts(units)
    if _relay_lines is None:
        _relay_lines = _tail_lines(RELAY_LOG)
    if _chromebox_lines is None:
        _chromebox_lines = _tail_lines(CHROMEBOX_LOG)
    out = {}
    for node in nodes:
        if _chrome_mtimes is not None and node in _chrome_mtimes:
            mtime = _chrome_mtimes[node]
        else:
            mtime = chrome_log_mtime(node) if node not in CHROMEBOX_NODES else None
        b_verd, b_det = browser_verdict(
            node, _chromebox_lines,
            _journal_starts.get(CHROMEBOX_UNIT_TMPL.format(node=node)),
            chrome_log_mtime=mtime, now=now)
        c_verd, c_det = cdp_verdict(
            node, _relay_lines, _journal_starts.get(RELAY_UNIT), now=now)
        out[node] = {
            "browser": b_verd,
            "browser_detail": b_det,
            "cdp": c_verd,
            "cdp_detail": c_det,
        }
    if live:
        _CACHE["at"] = time.monotonic()
        _CACHE["nodes"] = frozenset(nodes)
        _CACHE["data"] = out
    return out


def effective_status(local_proc, local_cdp, browser_v, cdp_v):
    """Map (local probes, host verdicts) -> (status, source).

    Host evidence only ever overrides the fully-blind pattern (both
    local probes negative — the sandbox signature). It never overrides
    a live local signal, so a fresh outage on the host always wins.
    """
    if local_cdp:
        # CDP answers: the browser is definitionally alive.
        return ("ACTIVE", "local")
    if local_proc:
        return ("CDP_DOWN", "local")
    # Both local probes negative: consult host evidence.
    if browser_v == "down":
        return ("STOPPED", "host-evidence")
    if browser_v == "unknown":
        return ("UNKNOWN", "host-evidence")
    if cdp_v == "healthy":
        return ("ACTIVE", "host-evidence")
    if cdp_v == "down":
        return ("CDP_DOWN", "host-evidence")
    return ("UNKNOWN", "host-evidence")


def main(argv=None):
    import argparse
    ap = argparse.ArgumentParser(description="Show host-side fleet evidence")
    ap.add_argument("--json", action="store_true")
    args = ap.parse_args(argv)
    data = collect()
    if args.json:
        print(json.dumps({"ok": True, "evidence": data}, indent=2))
        return
    for node, ev in data.items():
        print("%-6s browser=%-8s cdp=%-8s" % (node, ev["browser"], ev["cdp"]))
        print("       browser: %s" % ev["browser_detail"])
        print("       cdp:     %s" % ev["cdp_detail"])


if __name__ == "__main__":
    main()