From 5d9cd9029926c813c79239e583460c784f63ffe1 Mon Sep 17 00:00:00 2001 From: Sebastian Jeong Date: Sun, 16 Aug 2026 16:36:24 +0900 Subject: [PATCH] fix: use clean VM reset and resilient agent listener --- src/ferrolang_vm/cli.py | 64 +++++++++++++++++++++++++------------ src/ferrolang_vm/daemon.py | 15 +++++---- tools/README.md | 14 +++++--- tools/tcpagent/tcpagent.cpp | 3 +- 4 files changed, 63 insertions(+), 33 deletions(-) diff --git a/src/ferrolang_vm/cli.py b/src/ferrolang_vm/cli.py index e749203..f268a64 100644 --- a/src/ferrolang_vm/cli.py +++ b/src/ferrolang_vm/cli.py @@ -3,6 +3,7 @@ from __future__ import annotations import argparse import json +import shutil import subprocess import sys import time @@ -37,15 +38,41 @@ def rpc(payload: dict[str, object], start_daemon: bool = False) -> object: return response["result"] +def wait_ready(timeout: int) -> bool: + """Wait quietly; do not turn an expected boot gap into error-log spam.""" + deadline = time.monotonic() + timeout + while time.monotonic() < deadline: + try: + status = rpc({"op": "status"}) + if status["agent_connected"] and str(rpc({"op": "ping"})["response"]).startswith("OK 504F4E47"): + return True + except RuntimeError: + pass + time.sleep(.5) + return False + + +def follow_logs() -> int: + log_path = ROOT / ".qemu" / "ferro-vm.log" + lnav = shutil.which("lnav.exe") or shutil.which("lnav") + if lnav: + return subprocess.run([lnav, str(log_path)]).returncode + print("lnav was not found; following the log with PowerShell.", file=sys.stderr) + return subprocess.run([ + "powershell", "-NoProfile", "-Command", + f"Get-Content -LiteralPath '{log_path}' -Wait", + ]).returncode + + def main() -> int: parser = argparse.ArgumentParser(description="Windows-only QEMU/FreeDOS automation") commands = parser.add_subparsers(dest="op", required=True) - for name in ("start", "stop", "status", "ping", "screenshot", "ocr"): + for name in ("start", "stop", "status", "ping", "screenshot", "ocr", "logs"): commands.add_parser(name) + wait = commands.add_parser("wait-ready") + wait.add_argument("--timeout", type=int, default=45) reset = commands.add_parser("reset") reset.add_argument("--timeout", type=int, default=45) - soft_reset = commands.add_parser("soft-reset") - soft_reset.add_argument("--timeout", type=int, default=45) execute = commands.add_parser("exec") execute.add_argument("command") put = commands.add_parser("put") @@ -57,6 +84,13 @@ def main() -> int: args = parser.parse_args() try: + if args.op == "logs": + return follow_logs() + if args.op == "wait-ready": + if wait_ready(args.timeout): + print(json.dumps({"agent": "PONG"})) + return 0 + raise RuntimeError("TCPAGENT did not become ready") if args.op == "ocr": result = rpc({"op": "screenshot"}) import logging @@ -65,25 +99,15 @@ def main() -> int: recognized = RapidOCR()(result["path"]) print("\n".join(recognized.txts or ())) return 0 - if args.op in ("reset", "soft-reset"): - if args.op == "reset": - rpc({"op": "stop"}, start_daemon=True) - time.sleep(.5) - rpc({"op": "start"}, start_daemon=True) - else: - rpc({"op": "soft-reset"}) - # FreeDOS displays its default boot menu before FDAUTO.BAT starts - # TCPAGENT. This is input, not a readiness delay. + if args.op == "reset": + rpc({"op": "stop"}, start_daemon=True) + time.sleep(.5) + rpc({"op": "start"}, start_daemon=True) time.sleep(2) rpc({"op": "monitor", "command": "sendkey ret"}) - deadline = time.monotonic() + args.timeout - while time.monotonic() < deadline: - try: - if str(rpc({"op": "ping"})["response"]).startswith("OK 504F4E47"): - print(json.dumps({"reset": args.op, "agent": "PONG"})) - return 0 - except RuntimeError: - time.sleep(.5) + if wait_ready(args.timeout): + print(json.dumps({"reset": "complete", "agent": "PONG"})) + return 0 raise RuntimeError("TCPAGENT did not become ready") payload: dict[str, object] = {"op": args.op} if args.op == "exec": payload["command"] = args.command diff --git a/src/ferrolang_vm/daemon.py b/src/ferrolang_vm/daemon.py index 8c55bcb..03e9abf 100644 --- a/src/ferrolang_vm/daemon.py +++ b/src/ferrolang_vm/daemon.py @@ -62,10 +62,12 @@ class Host: log_event(logging.WARNING, "agent rejected", peer=str(peer), reason="already connected") continue self.agent = sock - self.agent_ready.set() try: banner = self._read_line(sock).decode("ascii", "replace") - log_event(logging.INFO, "agent connected", peer=f"{peer[0]}:{peer[1]}", banner=banner) + if banner != "TCPAGENT READY": + raise ConnectionError(f"invalid TCPAGENT banner: {banner!r}") + self.agent_ready.set() + log_event(logging.INFO, "agent connected", peer=f"{peer[0]}:{peer[1]}") # Request() owns protocol reads. Between requests, peek only # for EOF so TCPAGENT can reconnect without being rejected. while self.agent is sock: @@ -78,6 +80,11 @@ class Host: self.agent_lock.release() else: time.sleep(.05) + except (ConnectionError, OSError) as exc: + # Reset can close a connection during its banner. This is a + # per-connection event, never a reason to kill the listener. + log_event(logging.WARNING, "agent handshake/connection failed", + peer=f"{peer[0]}:{peer[1]}", error=str(exc)) finally: with self.agent_lock: if self.agent is sock: @@ -232,10 +239,6 @@ class Host: return {"agent_connected": self.agent_ready.is_set(), "qemu_running": running, "log": str(LOG_PATH)} if op == "start": return self.start() if op == "stop": return self.stop() - if op == "soft-reset": - self.monitor("system_reset") - log_event(logging.INFO, "qemu soft reset requested") - return {"reset": "requested"} if op == "ping": return self.ping() if op == "exec": return self.exec(str(request["command"])) if op == "put": return self.put(str(request["source"]), str(request["destination"])) diff --git a/tools/README.md b/tools/README.md index 810ebea..dd535d7 100644 --- a/tools/README.md +++ b/tools/README.md @@ -20,14 +20,14 @@ Windows named pipe `\\.\pipe\ferrolang-vm`; there is no controller or observer TCP port. Monitor the append-only structured log in another terminal: ```powershell -lnav .qemu/ferro-vm.log +uv run ferro-vm logs ``` Commands: ```powershell uv run ferro-vm reset # clean QEMU quit and restart -uv run ferro-vm soft-reset # QEMU system_reset +uv run ferro-vm wait-ready --timeout 45 uv run ferro-vm ping uv run ferro-vm exec 'dir C:\FEC' uv run ferro-vm put fec/src/check.c 'C:\FEC\SRC\CHECK.C' @@ -37,9 +37,13 @@ uv run ferro-vm ocr uv run ferro-vm stop ``` -Both reset modes wait for FreeDOS to boot, submit the default boot-menu Enter, -and require TCPAGENT `PING`/`PONG` before succeeding. The daemon logs command -metadata, DOS output, exit status, transfers, and agent lifecycle events as UTF-8 lines. It deliberately never logs raw binary +`reset` cleanly quits and restarts QEMU, waits for FreeDOS to boot, submits +the default boot-menu Enter, and requires TCPAGENT `PING`/`PONG`. QEMU +`system_reset` is intentionally unsupported because repeated soft resets leave +the FreeDOS NE2000 packet driver stuck during initialization. `logs` starts +`lnav` when installed and otherwise falls back to PowerShell `Get-Content +-Wait`. The daemon logs command metadata, DOS output, exit status, transfers, +and agent lifecycle events as UTF-8 lines. It deliberately never logs raw binary payloads or protocol hex. ## Standalone OCR diff --git a/tools/tcpagent/tcpagent.cpp b/tools/tcpagent/tcpagent.cpp index 7e5db7e..f15af39 100644 --- a/tools/tcpagent/tcpagent.cpp +++ b/tools/tcpagent/tcpagent.cpp @@ -176,10 +176,9 @@ int main(void) { int used,rc; uint16_t key; if(Utils::parseEnv()!=0)return 2; if(Utils::initStack(1,TCP_SOCKET_RING_SIZE,ctrl_break,ctrl_c))return 3; - cprintf("[TCPAGENT] Connecting to 10.0.2.2:%u\r\n",SERVER_PORT); while(!stop_requested) { if(connect_host()!=0){unsigned long spins=0;while(spins++<60000UL&&!stop_requested)drive();continue;} - cprintf("[TCPAGENT] Connected. Alt-X stops.\r\n"); write_text("TCPAGENT READY\r\n"); used=0; + write_text("TCPAGENT READY\r\n"); used=0; while(!stop_requested&&!socketp->isRemoteClosed()) { drive(); rc=socketp->recv((uint8_t *)data,CHUNK_SIZE); if(rc<0)break;