diff --git a/Agent.md b/Agent.md index 3fd67ace..730c0fd8 100644 --- a/Agent.md +++ b/Agent.md @@ -118,7 +118,7 @@ Community needs voiced in HN agent-UI discussions map directly to EMRG's design: pkill -f "emrg.server"; rm -f ~/.emrg/emrgd.port; python -m emrg ``` -Python: `uv run pytest tests/ -v` (974) — import check: `uv run python -c "from emrg.client.app import run_client"` +Python: `uv run pytest tests/ -v` (979) — import check: `uv run python -c "from emrg.client.app import run_client"` GUI: `cd emrg/gui && npm test` (260: 45 daemon_client + 19 conn-manager + 22 app-commands + 131 renderer smoke + 16 i18n + 7 integration + 3 commands + 8 build-config + 7 gui-state + 2 tool-group) — syntax: `node --check main.js preload.js daemon_client.js renderer/js/*.js` CI: `uv run pytest` (ubuntu + **windows-2025 matrix** — Windows pytest 回归在 PR CI 即失败,v0.2.29 教训 #725) + GUI tests + **actionlint workflow lint** (`rhysd/actionlint@v1.7.12` gate, #444 — workflow 解析错误在 PR CI 即失败,如 `if:` secrets 上下文) Re-trigger: `scripts/re-trigger-ci.sh [branch]` (workflow_dispatch, #527 — 替代空 commit 重触发:Actions outage 会整段丢弃 push 事件,dispatch 走 API 路径不受影响) diff --git a/emrg/__main__.py b/emrg/__main__.py index 66890cba..6d80b507 100644 --- a/emrg/__main__.py +++ b/emrg/__main__.py @@ -157,7 +157,7 @@ async def _send_shutdown() -> bool: return False try: - await ws.send(json.dumps({"type": "shutdown"}, ensure_ascii=False)) + await ws.send(json.dumps({"type": "shutdown", "source": "emrg server stop"}, ensure_ascii=False)) frame = await asyncio.wait_for(ws.recv(), timeout=3) try: await ws.close() diff --git a/emrg/_stop_all.py b/emrg/_stop_all.py index f2e9f06e..34c24a9c 100644 --- a/emrg/_stop_all.py +++ b/emrg/_stop_all.py @@ -307,7 +307,7 @@ def ws_graceful_shutdown(port: int, token: str, timeout: float = 3.0) -> bool: except json.JSONDecodeError: return False # shutdown → shutdown_ack - _ws_send_text(sock, json.dumps({"type": "shutdown"})) + _ws_send_text(sock, json.dumps({"type": "shutdown", "source": "stop_all"})) ack = _ws_recv_text(sock, timeout) if not ack: return False diff --git a/emrg/server/daemon.py b/emrg/server/daemon.py index bbcd4460..26c702f5 100644 --- a/emrg/server/daemon.py +++ b/emrg/server/daemon.py @@ -224,6 +224,7 @@ def __init__(self, llm_config: LlmConfig) -> None: self.evolutions: list[EvolutionLog] = [] self.llm = LlmClient(llm_config) self._running = False + self._stop_reason: str = "unknown" # shutdown_msg|cancel|sigint|bind_exit|crash (rant 2026-08-19T14:02:37) self._scheduler: Optional[TaskScheduler] = None self._max_tool_rounds = llm_config.max_tool_rounds self._projects_log = runtime_dir / "projects.yml" @@ -289,6 +290,7 @@ async def serve(self) -> None: EMRGD_PORT, ) self._running = False + self._stop_reason = "bind_exit" return # No listener behind the port → TIME_WAIT remnant. Retry the bind # for a bounded window so a crashed daemon restarts without a @@ -314,6 +316,7 @@ async def serve(self) -> None: EMRGD_PORT, ) self._running = False + self._stop_reason = "bind_exit" return else: logger.error( @@ -322,6 +325,7 @@ async def serve(self) -> None: EMRGD_PORT, _TIME_WAIT_RETRIES, ) self._running = False + self._stop_reason = "bind_exit" return # ── PID file: diagnostics only (rant 08-05:21 — no longer an @@ -391,30 +395,95 @@ async def serve(self) -> None: try: await self._server.serve_forever() except asyncio.CancelledError: - pass + self._stop_reason = "cancel" + logger.info("daemon serve cancelled (asyncio.CancelledError) — cleanup started") + except Exception: + self._stop_reason = "crash" + logger.error("daemon serve crashed — cleanup started", exc_info=True) finally: - self._skills_ttl_task.cancel() - self._update_check_task.cancel() - try: - await self._skills_ttl_task - except (asyncio.CancelledError, Exception): - pass - self._port_keepalive_task.cancel() + await self._shutdown_all(pid_file) + + async def _shutdown_all(self, pid_file: Path) -> None: + """Best-effort teardown with per-step logging (rant 2026-08-19T14:02:37). + + Every daemon stop path funnels through here: shutdown message, + asyncio cancel (Ctrl+C / parent kill), crash. Logs the stop reason + + each cleanup step's success/failure so a post-mortem can answer + "why did the daemon stop / what was cleaned up" from emrgd.log + alone. Never raises. + """ + try: + n_handlers = ( + len(self._scheduler._handlers) + if self._scheduler is not None + and isinstance(getattr(self._scheduler, "_handlers", None), list) + else 0 + ) + except Exception: + n_handlers = 0 + logger.info( + "daemon stopping (reason=%s, handlers=%d) — cleaning up", + self._stop_reason, n_handlers, + ) + + steps: list[tuple[str, bool]] = [] + # 1. Background task loops (skills TTL, update check, port keepalive) + for task, name in ( + (self._skills_ttl_task, "skills-ttl loop"), + (self._update_check_task, "update-check loop"), + (self._port_keepalive_task, "port-keepalive loop"), + ): try: - await self._port_keepalive_task - except (asyncio.CancelledError, Exception): - pass - self._scheduler.stop_all() - await self._scheduler.wait_all() + if task is not None: + task.cancel() + try: + await task + except (asyncio.CancelledError, Exception): + pass + steps.append((f"cancelled {name}", True)) + except Exception: + steps.append((f"cancelled {name}", False)) + # 2. Scheduler + try: + if self._scheduler is not None: + self._scheduler.stop_all() + await self._scheduler.wait_all() + steps.append(("stopped scheduler", True)) + else: + steps.append(("stopped scheduler (none)", True)) + except Exception: + logger.warning("scheduler stop failed", exc_info=True) + steps.append(("stopped scheduler", False)) + # 3. LLM client + try: await self.llm.close() + steps.append(("closed llm client", True)) + except Exception: + steps.append(("closed llm client", False)) + # 4. Port file + try: cleanup_server() - # Remove PID file - try: - if pid_file.exists() and pid_file.read_text(encoding="utf-8").strip() == str(os.getpid()): - pid_file.unlink() - logger.debug("pid file removed: %s", pid_file) - except OSError: - pass + steps.append(("removed port file", True)) + except Exception: + steps.append(("removed port file", False)) + # 5. PID file (diagnostic) + try: + if pid_file.exists() and pid_file.read_text(encoding="utf-8").strip() == str(os.getpid()): + pid_file.unlink() + logger.debug("pid file removed: %s", pid_file) + steps.append(("removed pid file", True)) + else: + steps.append(("removed pid file (absent)", True)) + except OSError: + steps.append(("removed pid file", False)) + + uptime = max(0, int((datetime.now() - self.start_time).total_seconds())) + all_ok = all(ok for _, ok in steps) + logger.info( + "daemon stopped (reason=%s, uptime=%ds, steps=%s, all_ok=%s)", + self._stop_reason, uptime, + ", ".join(s for s, _ in steps), all_ok, + ) async def _port_keepalive_loop(self) -> None: """Re-assert the port file if it was deleted or overwritten. @@ -2027,12 +2096,18 @@ async def _process_message( # Rant 2026-08-19T13:11:34 — every daemon kill must be attributable: # log the requesting peer (loopback client) alongside the action so # "谁杀 daemon" can be traced from emrgd.log alone. + # Rant 2026-08-19T14:02:37 — loopback peers are indistinguishable + # (all 127.0.0.1:*), so senders tag the message with a `source` + # (emrg server stop / stop_all) to tell emrg stop / GUI / + # installer apart; missing source degrades to "unknown". peer = "" try: peer = str(ws.remote_address) except Exception: peer = "unknown peer" - logger.info("shutdown requested by client (%s)", peer) + source = str(msg.get("source") or "unknown") + self._stop_reason = "shutdown_msg" + logger.info("shutdown requested by client (peer=%s, source=%s)", peer, source) await self._send(ws, {"type": "shutdown_ack"}) try: await ws.close() @@ -3766,4 +3841,7 @@ async def run_server(llm_config: LlmConfig) -> None: try: await server.serve() except KeyboardInterrupt: - logger.info("shutdown signal received") + # Rant 2026-08-19T14:02:37 — attribute the stop: serve()'s teardown + # already logged the full cleanup; this line identifies the trigger. + server._stop_reason = "sigint" + logger.info("shutdown signal received (SIGINT), cleanup started") diff --git a/tests/test_daemon.py b/tests/test_daemon.py index 566e4201..9d373533 100644 --- a/tests/test_daemon.py +++ b/tests/test_daemon.py @@ -1641,3 +1641,120 @@ def test_assert_port_file_writes_fixed_port(tmp_path): lines = port_file.read_text(encoding="utf-8").split() assert lines[0] == "56031" assert lines[1] == "tok-123" + + +# ── Daemon stop-path logging (rant 2026-08-19T14:02:37) ────────────── +# Any reason / any path the daemon stops must leave a detailed emrgd.log: +# when, why, who triggered, what was cleaned up. These are PURE-MOCK tests +# (mock the scheduler/llm/background tasks, never boot or stop a real +# daemon) — the highest principle forbids stop/restart server tests. + +def _make_shutdown_server(tmp_path) -> EmrgServer: + """EmrgServer with all teardown dependencies mocked for _shutdown_all.""" + from unittest.mock import AsyncMock, MagicMock + + server = _make_server() + server._stop_reason = "cancel" + server._skills_ttl_task = None + server._update_check_task = None + server._port_keepalive_task = None + server._scheduler = AsyncMock() # stop_all + wait_all, no real handlers + server._scheduler.stop_all = MagicMock() # real API is sync + server._scheduler.wait_all = AsyncMock() + server.llm = AsyncMock() # close() awaitable + server._server = _ShutdownFakeServer() # sync .close(), no unawaited coroutine + return server + + +class _ShutdownFakeServer: + """Minimal stand-in for the websockets Server in shutdown-message tests.""" + + def close(self) -> None: + pass + + +def test_shutdown_all_logs_reason_and_cleanup_steps(tmp_path, caplog): + """_shutdown_all logs the stop reason + every cleanup step + final line.""" + import logging + + server = _make_shutdown_server(tmp_path) + pid_file = tmp_path / "emrgd.pid" + pid_file.write_text(str(os.getpid()), encoding="utf-8") + + caplog.set_level(logging.INFO, logger="emrg.server.daemon") + asyncio.run(server._shutdown_all(pid_file)) + + text = caplog.text + assert "daemon stopping (reason=cancel, handlers=0) — cleaning up" in text + assert "cancelled skills-ttl loop" in text + assert "cancelled update-check loop" in text + assert "cancelled port-keepalive loop" in text + assert "stopped scheduler" in text + assert "closed llm client" in text + assert "removed port file" in text + assert "removed pid file" in text + assert "daemon stopped (reason=cancel, uptime=" in text + assert "all_ok=True" in text + assert not pid_file.exists() # our own pid → unlinked + + +def test_shutdown_all_handles_failing_cleanup(tmp_path, caplog): + """A failing cleanup step is recorded (all_ok=False), never raises.""" + import logging + from unittest.mock import AsyncMock + + server = _make_shutdown_server(tmp_path) + server.llm.close = AsyncMock(side_effect=RuntimeError("boom")) + + caplog.set_level(logging.INFO, logger="emrg.server.daemon") + asyncio.run(server._shutdown_all(tmp_path / "missing.pid")) + + text = caplog.text + assert "daemon stopping (reason=cancel" in text + assert "closed llm client" in text # step listed even on failure + assert "daemon stopped (reason=cancel" in text + assert "all_ok=False" in text + + +def test_shutdown_all_reason_crash_and_sigint(tmp_path, caplog): + """_stop_reason is echoed in both the start and final log lines.""" + import logging + + for reason in ("crash", "sigint", "shutdown_msg"): + server = _make_shutdown_server(tmp_path) + server._stop_reason = reason + caplog.set_level(logging.INFO, logger="emrg.server.daemon") + asyncio.run(server._shutdown_all(tmp_path / "missing.pid")) + assert f"daemon stopping (reason={reason}" in caplog.text + assert f"daemon stopped (reason={reason}" in caplog.text + caplog.clear() + + +def test_shutdown_message_logs_peer_and_source(tmp_path, caplog): + """shutdown msg logs peer + source and sets _stop_reason=shutdown_msg.""" + import logging + + server = _make_shutdown_server(tmp_path) + writer = _FakeWriter() + + caplog.set_level(logging.INFO, logger="emrg.server.daemon") + asyncio.run(server._process_message({"type": "shutdown", "source": "stop_all"}, writer)) + + assert "shutdown requested by client (peer=unknown peer, source=stop_all)" in caplog.text + assert server._stop_reason == "shutdown_msg" + # shutdown_ack is sent back + assert _last_frame(writer) == {"type": "shutdown_ack"} + + +def test_shutdown_message_missing_source_degrades(tmp_path, caplog): + """Legacy shutdown msg without source logs source=unknown (backward compat).""" + import logging + + server = _make_shutdown_server(tmp_path) + writer = _FakeWriter() + + caplog.set_level(logging.INFO, logger="emrg.server.daemon") + asyncio.run(server._process_message({"type": "shutdown"}, writer)) + + assert "shutdown requested by client (peer=unknown peer, source=unknown)" in caplog.text + assert server._stop_reason == "shutdown_msg"