From 6e0cf079bcae2527fcb7399267459e58e6c5af1c Mon Sep 17 00:00:00 2001 From: AmberCXX Date: Thu, 3 Sep 2026 19:32:43 +0800 Subject: [PATCH] =?UTF-8?q?feat(engine):=20=E8=BF=90=E8=A1=8C=E6=97=A5?= =?UTF-8?q?=E5=BF=97=E8=90=BD=E7=9B=98=20+=20=E5=B4=A9=E6=BA=83=E5=8F=AF?= =?UTF-8?q?=E8=A7=81=E6=80=A7?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit engine 的 log() 此前只写 stderr，而 MCP 宿主通常只在连接建立那一刻捕获 stderr——启动之后打印的任何东西都不再被记录。进程一旦异常退出，线索为零。 实测（2026-09-03）：engine 在 00:00-03:00 之间消失，宿主日志无断开记录、 系统无崩溃报告、无内存压力事件，调度静默停摆 10 小时 31 分、漏跑 12 个任务， 事后无从判断死因。 改动： - log()/logError() 同时追加到 /engine.log，超 2MB 转存 .log.1 - 新增 logFatal()，带完整堆栈落盘 - 注册 uncaughtException / unhandledRejection：记录后 stopScheduler() 释放 PID 锁并 exit(1) 两处取舍写在注释里： - 抓到异常后退出而非续跑——状态可能已损坏，错误的推送比没有推送更坏 - 不做自动重起——多实例 + 自动重起 + 抢 PID 锁是本项目已踩过的坑； 恢复由外部检测触发人工重连，engine 自己不做进程管理 验证：tsc --noEmit 通过 · bun test 19 pass · 临时 DATA_DIR 实测日志落盘、 FATAL 带堆栈、2MB 轮转生效 Co-Authored-By: Claude Opus 5 (1M context) Claude-Session: https://claude.ai/code/session_01EWhZ8wD8Ne5yiYaCdL6cjf --- forge-engine/README.md | 14 +++++++++++ forge-engine/config.ts | 45 +++++++++++++++++++++++++++++++++- forge-engine/engine-channel.ts | 26 +++++++++++++++++++- 3 files changed, 83 insertions(+), 2 deletions(-) diff --git a/forge-engine/README.md b/forge-engine/README.md index d4cd448..a0c8522 100644 --- a/forge-engine/README.md +++ b/forge-engine/README.md @@ -7,6 +7,20 @@ > [!IMPORTANT] > Forge Engine 目前是 **experimental / manual setup**。源码、MCP server 和 CLI 都在仓库里，但 **`forge-hub install` 默认不会部署或注册它**。想用的话，按下面步骤单独配置。 +## 运行日志与崩溃可见性 + +`log()` / `logError()` 除了写 stderr，**同时追加到 `/engine.log`**，超过 2MB 转存 `engine.log.1`（只留一份）。 + +**为什么需要文件日志**：stderr 是给 MCP 宿主看的，但宿主通常只在**连接建立那一刻**捕获 stderr —— engine 启动之后打印的任何东西都不再被记录。一旦进程异常退出，什么线索都不剩。 + +实测案例（2026-09-03）：engine 在 00:00–03:00 之间消失，宿主日志无断开记录、系统无崩溃报告、无内存压力事件，调度静默停摆 **10 小时 31 分**、漏跑 12 个任务。事后无从判断死因。 + +**崩溃捕获**：`uncaughtException` 与 `unhandledRejection` 会把完整堆栈写进 `engine.log`，随后 `stopScheduler()` 释放 PID 锁并退出（exit 1）。 + +**为什么退出而不是继续跑**：调度器状态可能已损坏，而一个状态损坏的调度器发出的推送比不推送更坏。 + +**为什么不自动重起**：多实例 + 自动重起 + 抢 PID 锁是本项目已经踩过的坑（`cleanOrphans` + 一次性 `acquirePidLock` 的组合）。恢复由**外部**检测触发人工重连，engine 自己不做进程管理。 + ## 架构 ``` diff --git a/forge-engine/config.ts b/forge-engine/config.ts index eeb7906..26d3400 100644 --- a/forge-engine/config.ts +++ b/forge-engine/config.ts @@ -2,6 +2,7 @@ * Forge Engine 路径常量与日志 */ +import fs from "node:fs"; import path from "node:path"; // ── Channel Identity ──────────────────────────────────────────────────────── @@ -25,13 +26,55 @@ export const HANDLERS_DIR = path.resolve(CODE_DIR, "handlers"); export const SCHEDULE_FILE = path.join(DATA_DIR, "engine-schedule.json"); export const ACTION_LOG_FILE = path.join(DATA_DIR, "engine-trigger-log.md"); export const PID_FILE = path.join(DATA_DIR, "engine.pid"); +export const RUNTIME_LOG_FILE = path.join(DATA_DIR, "engine.log"); -// ── Logging (stderr — stdout is MCP stdio) ────────────────────────────────── +// ── Logging ───────────────────────────────────────────────────────────────── +// +// stderr 是给宿主看的（stdout 被 MCP stdio 占用）。但宿主只在**连接建立那一刻** +// 捕获 stderr —— engine 启动之后打印的任何东西都掉进黑洞。 +// +// 后果实测（2026-09-03）：engine 在 00:00–03:00 之间死亡，无崩溃报告、无内存压力、 +// 宿主日志里一条断开记录都没有，调度静默停摆 10 小时 31 分、漏跑 12 个任务。 +// 它死之前很可能打印过原因，只是没人听见。 +// +// 所以 log/logError 同时落盘。文件是唯一能在进程死后还留下痕迹的地方。 + +const MAX_LOG_BYTES = 2 * 1024 * 1024; // 2MB 转存一次，只留一份 .1 + +function appendToFile(line: string): void { + try { + fs.mkdirSync(DATA_DIR, { recursive: true }); + // 轮转：日志本身不能变成下一个「不停长大且没人敢删」的文件 + try { + if (fs.statSync(RUNTIME_LOG_FILE).size > MAX_LOG_BYTES) { + fs.renameSync(RUNTIME_LOG_FILE, RUNTIME_LOG_FILE + ".1"); + } + } catch { /* 文件还不存在 —— 首次写入，正常 */ } + fs.appendFileSync(RUNTIME_LOG_FILE, line); + } catch { /* 日志写不进去不能反过来把进程搞死 */ } +} + +function stamp(): string { + return new Date().toISOString().replace("T", " ").slice(0, 19); +} export function log(msg: string) { process.stderr.write(`[engine] ${msg}\n`); + appendToFile(`${stamp()} [engine] ${msg}\n`); } export function logError(msg: string) { process.stderr.write(`[engine] ERROR: ${msg}\n`); + appendToFile(`${stamp()} [engine] ERROR: ${msg}\n`); +} + +/** 致命错误：带完整堆栈落盘。进程即将退出时用。 */ +export function logFatal(kind: string, err: unknown): void { + // err.stack 本身已含 "Name: message" 首行，不要再拼一次 + const detail = err instanceof Error + ? (err.stack ?? `${err.name}: ${err.message}\n(无堆栈)`) + : String(err); + const block = `${stamp()} [engine] FATAL ${kind} · PID ${process.pid}\n${detail}\n`; + process.stderr.write(block); + appendToFile(block); } diff --git a/forge-engine/engine-channel.ts b/forge-engine/engine-channel.ts index 32dab75..66d6844 100644 --- a/forge-engine/engine-channel.ts +++ b/forge-engine/engine-channel.ts @@ -23,6 +23,7 @@ import { SCHEDULE_DIR, log, logError, + logFatal, } from "./config.js"; import { startScheduler, stopScheduler } from "./scheduler.js"; import { resolveTaskTiming } from "./task-timing.js"; @@ -299,7 +300,30 @@ async function main() { process.on("SIGTERM", () => shutdown("SIGTERM")); process.on("SIGINT", () => shutdown("SIGINT")); - log("engine started"); + // ── Crash Visibility ───────────────────────────────────────────────────── + // + // 2026-09-03：engine 在 00:00–03:00 之间消失，宿主日志里没有任何断开记录、 + // 没有崩溃报告、没有内存压力事件，调度静默停摆 10h31m、漏跑 12 个任务。 + // + // 定时器回调里的未捕获异常在 Bun 下会直接带走进程，而 log() 当时只写 stderr， + // 宿主又只在连接建立那一刻捕获 stderr —— **它死之前很可能喊过，只是没人听见。** + // + // 取舍：抓到之后**退出，不带病续跑**。scheduler 的状态可能已经坏了， + // 而一个状态损坏的调度器推送出去的东西，比不推送更坏。 + // 退出后由外部检测（宿主侧的存活检查）发现并提示人工重连 —— 不做自动重起： + // 多实例 + 自动重起 + 抢 PID 锁，正是本项目已经踩过的坑。 + process.on("uncaughtException", (err) => { + logFatal("uncaughtException", err); + stopScheduler(); // 释放 PID 锁，别留一个 stale 锁给下一个实例 + process.exit(1); + }); + process.on("unhandledRejection", (reason) => { + logFatal("unhandledRejection", reason); + stopScheduler(); + process.exit(1); + }); + + log(`engine started · PID ${process.pid}`); } if (import.meta.main) {