fix(budget): 墙钟只算 run 真的在跑的时间，不算挂起等人的时间

## 病症：blocked 和墙钟预算互相拆台墙钟按 `now - spent.started_at` 算，而 started_at 是「第一次花钱的绝对时刻」。 blocked 的定义恰恰是**挂起等人工** —— 预算耗尽、节点判罚都会把 run 打到 blocked。于是：人隔夜来处置 → 等待那段被算成「已用」→ 一起跑就报 wallclock_ms 耗尽 → 再 blocked → 再等人。**一条过夜的 run 从此永远醒不过来。** 而且报出来的原因具有误导性：写着 wallclock_ms（跑太久），实际是等人等太久。真事：run_9168bd24f46c（e2e-demo 做官网）08-18 15:48 起跑、16:19 判 blocked，只花了 7/100 次调用、69,961/5,000,000 tokens —— **预算用掉不到 2%，两天没能重跑**。它正是 27-p3c-batch3-handover §五那条「还没解决的原始问题」。 ## 修法 spent 里改记 `active_ms`（累计活跃时长），started_at 退化成「当前这一段的起点」，不在 running 时为 null。已用 = active_ms + 当前段。起止结算挂在 graph-run-sse.afterRunTransition 这个**单一漏斗**上，不去枚举「哪些地方会让 run 停下来」—— 枚举漏一条就是静默少算。 ⚠️ 钩子必须放在那个 early return **之前**：进 running 既不是收敛、也不空坑，两个条件都不满足，放后面就变成「只结算停下来、从不开始计时」，症状是 active_ms 恒 0、墙钟形同虚设，而且照样全绿。守卫里专门有一条钉这个位置（反向验过：把钩子注释掉，那一条立刻红）。 spendBudget 不再兼职锚墙钟 —— 一个事实一处持有者。 ## 存量行 active_ms 缺失的行：旧锚点里混着等待时间，真实活跃时长复原不出来，按 0 起算、一笔勾销。有意为之 —— 另外两维（调用次数 / tokens）是精确的且没受影响，真正兜住花钱的是那两维，墙钟只是跑飞保护。所以那条卡住的 run 不需要动库，重试进 running 时自动重新锚定。 ## ponytail 只认 running 一个态。manual 模式下两次点击之间 run 也停在 running，那段人类思考时间仍会计入 —— 上限已知，比原来跨天累计小几个数量级。要更准得按 agent 调用的起止配对计时，那是另一套账。 ## 顺带 goal-task-acceptance 两条用例原先 deepEqual 整个 budget 对象，现在剥掉 spent 只比申报的额度 —— 它守的是「用户填的额度没被静默换成默认值」，跟运行期账本长什么样无关；账本另有断言（起跑那一刻 agent_calls/tokens 仍是 0）。全量：137 文件 / 1284 测试全绿。 Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>

fix(budget): 墙钟只算 run 真的在跑的时间，不算挂起等人的时间
## 病症：blocked 和墙钟预算互相拆台墙钟按 `now - spent.started_at` 算，而 started_at 是「第一次花钱的绝对时刻」。 blocked 的定义恰恰是**挂起等人工** —— 预算耗尽、节点判罚都会把 run 打到 blocked。于是：人隔夜来处置 → 等待那段被算成「已用」→ 一起跑就报 wallclock_ms 耗尽 → 再 blocked → 再等人。**一条过夜的 run 从此永远醒不过来。** 而且报出来的原因具有误导性：写着 wallclock_ms（跑太久），实际是等人等太久。真事：run_9168bd24f46c（e2e-demo 做官网）08-18 15:48 起跑、16:19 判 blocked，只花了 7/100 次调用、69,961/5,000,000 tokens —— **预算用掉不到 2%，两天没能重跑**。它正是 27-p3c-batch3-handover §五那条「还没解决的原始问题」。 ## 修法 spent 里改记 `active_ms`（累计活跃时长），started_at 退化成「当前这一段的起点」，不在 running 时为 null。已用 = active_ms + 当前段。起止结算挂在 graph-run-sse.afterRunTransition 这个**单一漏斗**上，不去枚举「哪些地方会让 run 停下来」—— 枚举漏一条就是静默少算。 ⚠️ 钩子必须放在那个 early return **之前**：进 running 既不是收敛、也不空坑，两个条件都不满足，放后面就变成「只结算停下来、从不开始计时」，症状是 active_ms 恒 0、墙钟形同虚设，而且照样全绿。守卫里专门有一条钉这个位置（反向验过：把钩子注释掉，那一条立刻红）。 spendBudget 不再兼职锚墙钟 —— 一个事实一处持有者。 ## 存量行 active_ms 缺失的行：旧锚点里混着等待时间，真实活跃时长复原不出来，按 0 起算、一笔勾销。有意为之 —— 另外两维（调用次数 / tokens）是精确的且没受影响，真正兜住花钱的是那两维，墙钟只是跑飞保护。所以那条卡住的 run 不需要动库，重试进 running 时自动重新锚定。 ## ponytail 只认 running 一个态。manual 模式下两次点击之间 run 也停在 running，那段人类思考时间仍会计入 —— 上限已知，比原来跨天累计小几个数量级。要更准得按 agent 调用的起止配对计时，那是另一套账。 ## 顺带 goal-task-acceptance 两条用例原先 deepEqual 整个 budget 对象，现在剥掉 spent 只比申报的额度 —— 它守的是「用户填的额度没被静默换成默认值」，跟运行期账本长什么样无关；账本另有断言（起跑那一刻 agent_calls/tokens 仍是 0）。全量：137 文件 / 1284 测试全绿。 Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
yibo
1 parent 20fed0a5
Showing 4 changed files with 216 additions and 8 deletions
server/services/graph-engine.js
server/services/graph-run-sse.js
server/tests/unit/budget-wallclock-active.test.js
server/tests/unit/goal-task-acceptance.test.js
@@ -2248,6 +2248,64 @@ function readBudget(run) {
 }
 /**
+ * 墙钟已用时长 = **已结算的活跃时长** + 当前这一段还没结算的。
+ *
+ * ── 为什么不是「now - 第一次花钱的时刻」 ──────────────────────────────────
+ * 原来就是那么算的，它和 blocked 的语义直接对撞：预算耗尽 / 节点判罚都会把 run 打到
+ * `blocked`，而 blocked 的定义就是**挂起等人工**。人隔夜再来处置时，墙钟把这段等待
+ * 一并算进了「已用」，于是一起跑就报 `wallclock_ms` 耗尽 → 再 blocked → 再等人。
+ * **一条过夜的 run 从此永远醒不过来**，而报出来的原因是「跑太久」，实际是「等人等太久」。
+ *
+ * 实例：`run_9168bd24f46c`（e2e-demo 做官网）2026-08-18 15:48 起跑，预算 2h，
+ * 只花了 7/100 次调用、69,961/5,000,000 tokens，08-18 16:19 判 blocked 之后就再没能起来。
+ *
+ * ponytail: 只认 `running` 一个态。manual 模式下两次点击之间 run 也停在 running，
+ * 那段人类思考时间仍会计入 —— 上限已知，比原来跨天累计小几个数量级。
+ * 要更准就得按 agent 调用的起止配对计时，那是另一套账。
+ */
+function wallclockElapsedMs(spent = {}) {
+  const settled = spent.active_ms || 0;
+  if (!spent.started_at) return settled;
+  return settled + Math.max(0, Date.now() - Date.parse(spent.started_at));
+}
+
+/**
+ * 墙钟的起止结算。挂在 `graph-run-sse.afterRunTransition` 这个**单一漏斗**上，
+ * 而不是去枚举「哪些地方会让 run 停下来」—— 那种枚举漏一条就是静默少算。
+ *
+ * 进 running：开一段新的计时。离开 running：把这一段并进 active_ms 并断开锚点。
+ *
+ * **存量行**（`active_ms` 缺失）：旧锚点里混着等待时间，真实活跃时长已经复原不出来了。
+ * 这里把它按 0 起算，等于把过去那段一笔勾销 —— 有意为之：另外两维（调用次数 / tokens）
+ * 是精确的、且没受影响，真正兜住花钱的是那两维；墙钟只是跑飞保护。
+ */
+function settleWallclock(runId, to) {
+  const run = getRun(runId);
+  if (!run || run.parent_run_id) return null; // 预算只挂在 root run 那一行
+  const held = readBudget(run);
+  if (!held || held.budget.wallclock_ms == null) return null;
+
+  const b = held.budget;
+  if (!b.spent) b.spent = {};
+  const s = b.spent;
+
+  if (to === 'running') {
+    s.active_ms = s.active_ms || 0;
+    s.started_at = now(); // 无条件重锚：进 running 就是新一段的开始
+  } else {
+    if (s.started_at) {
+      s.active_ms = (s.active_ms || 0) + Math.max(0, Date.now() - Date.parse(s.started_at));
+    }
+    s.active_ms = s.active_ms || 0;
+    s.started_at = null;
+  }
+  getDb()
+    .prepare(`UPDATE graph_runs SET budget_json = ?, updated_at = ? WHERE id = ?`)
+    .run(JSON.stringify(b), now(), held.rootRunId);
+  return s;
+}
+
+/**
  * 余额检查。任何一层发起 agent 调用前都要过这一关（advanceOne 拾取节点之后立刻查）。
  * @returns {{ok: boolean, exhausted: string[], rootRunId?: string, budget?: object}}
  */
@@ -2262,10 +2320,7 @@ function checkBudget(run) {
     exhausted.push('total_agent_calls');
   }
   if (b.total_tokens != null && (spent.tokens || 0) >= b.total_tokens) exhausted.push('total_tokens');
-  if (
-    b.wallclock_ms != null && spent.started_at &&
-    Date.now() - Date.parse(spent.started_at) >= b.wallclock_ms
-  ) {
+  if (b.wallclock_ms != null && wallclockElapsedMs(spent) >= b.wallclock_ms) {
     exhausted.push('wallclock_ms');
   }
   return { ok: exhausted.length === 0, exhausted, rootRunId: held.rootRunId, budget: b };
@@ -2284,7 +2339,7 @@ function spendBudget(run, { agentCalls = 0, tokens = 0 } = {}) {
   if (!b.spent) b.spent = {};
   b.spent.agent_calls = (b.spent.agent_calls || 0) + agentCalls;
   b.spent.tokens = (b.spent.tokens || 0) + tokens;
-  if (!b.spent.started_at) b.spent.started_at = now(); // 墙钟从第一次真花钱开始算
+  // 墙钟不在这里锚 —— 它按「run 处于 running 的时长」累计，起止都归 settleWallclock 管。
   getDb()
     .prepare(`UPDATE graph_runs SET budget_json = ?, updated_at = ? WHERE id = ?`)
     .run(JSON.stringify(b), now(), held.rootRunId);
@@ -3842,6 +3897,8 @@ module.exports = {
   // 任务级总预算（§四.A.3）
   checkBudget,
   spendBudget,
+  settleWallclock,
+  wallclockElapsedMs,
   suspendRunTree,
   // 重试级联判据（§四.C 末段）
@@ -343,6 +343,15 @@ const { ACTIVE_ROOT_RUN_STATUS } = workGraphDb;
  * 两件事各自 try/catch：settle 炸了不能连累调度，否则一次回写异常就把整个队列冻住。
  */
 function afterRunTransition(runId, to) {
+  // 墙钟起止结算 —— 必须在下面那个 early return **之前**：进 `running` 既不是收敛、
+  // 也不空坑，两个条件都不满足，放在后面等于「只结算停下来、从不开始计时」。
+  try {
+    // 惰性 require：graph-engine → 本模块，顶层 require 必成环（与下面两处同理）
+    require('./graph-engine').settleWallclock(runId, to);
+  } catch (err) {
+    console.error(`[graphRunSse] 墙钟结算异常 run=${runId} → ${to}: ${err.message}`);
+  }
+
   const settled = ROOT_RUN_SETTLED_STATUS.has(to);
   const freedSlot = !ACTIVE_ROOT_RUN_STATUS.includes(to);
   if (!settled && !freedSlot) return;
+/**
+ * Unit Tests — 墙钟预算只算「真的在跑」的时间，不算挂起等人的时间
+ *
+ * ── 挡的是什么 ─────────────────────────────────────────────────────────
+ * 原实现按 `now - spent.started_at` 算，而 started_at 是「第一次花钱的绝对时刻」。
+ * 这与 blocked 的语义直接对撞：预算耗尽、节点判罚都会把 run 打到 blocked，
+ * 而 blocked 的定义就是**挂起等人工**。人隔夜再来处置 →「等待」被算成「已用」→
+ * 一起跑就报 wallclock_ms 耗尽 → 再 blocked → 再等人。**过夜的 run 永远醒不过来。**
+ *
+ * 而且报出来的原因具有误导性：写着 `wallclock_ms`（跑太久），实际是等人等太久。
+ *
+ * 真事：run_9168bd24f46c（e2e-demo 做官网）2026-08-18 15:48 起跑、16:19 判 blocked，
+ * 只花了 7/100 次调用、69,961/5,000,000 tokens，两天后仍卡死 —— 用掉的预算不到 2%。
+ */
+import { describe, it, expect, beforeAll, afterAll, beforeEach } from 'vitest';
+import fs from 'fs';
+import os from 'os';
+import path from 'path';
+
+const TMP = fs.mkdtempSync(path.join(os.tmpdir(), 'lemonboss-wallclock-'));
+process.env.GRAPH_DB_PATH = path.join(TMP, 'graph.sqlite');
+
+const engine = require('../../services/graph-engine');
+const wdb = require('../../services/work-graph-db');
+
+const HOUR = 3600_000;
+const budget = (spent) => JSON.stringify({ wallclock_ms: 2 * HOUR, total_agent_calls: 100, spent });
+
+/** 直接落一行 root run，只为拿一个带 budget_json 的载体（不走图定义那一整套） */
+function seedRun(id, spentObj, status = 'running') {
+  const db = wdb.getDb();
+  const t = '2026-08-18T15:48:00.000Z';
+  db.prepare(`INSERT INTO graph_runs
+      (id, graph_kind, graph_id, company_id, root_run_id, execution_mode, run_status, budget_json, created_at, updated_at)
+      VALUES (?, 'org', 'g1', 'co1', ?, 'manual', ?, ?, ?, ?)`)
+    .run(id, id, status, budget(spentObj), t, t);
+  return wdb.getRun(id);
+}
+
+describe('预算 · 墙钟只算活跃时长', () => {
+  afterAll(() => fs.rmSync(TMP, { recursive: true, force: true }));
+  beforeEach(() => wdb.getDb().prepare('DELETE FROM graph_runs').run());
+
+  it('挂起期间墙钟不走：两天前 blocked 的 run，余额照旧', () => {
+    // 这一条就是 run_9168bd24f46c 的形态：active_ms 只有 31 分钟，started_at 已断开
+    const run = seedRun('r_old', { agent_calls: 7, tokens: 69961, active_ms: 31 * 60_000, started_at: null }, 'blocked');
+    const gate = engine.checkBudget(run);
+    expect(gate.exhausted).toEqual([]);
+    expect(gate.ok).toBe(true);
+  });
+
+  it('旧算法下这条 run 必然耗尽 —— 证明这个测试真的在量东西', () => {
+    // 反例对照：起点是两天前的绝对时刻、没有 active_ms（存量行的原始形态）
+    const spent = { agent_calls: 7, tokens: 69961, started_at: '2026-08-18T15:48:17.630Z' };
+    const legacyElapsed = Date.now() - Date.parse(spent.started_at);
+    expect(legacyElapsed).toBeGreaterThan(2 * HOUR); // 旧判据：早就超了
+    // 新判据看的是 active_ms，started_at 断开后就不再累加
+    expect(engine.wallclockElapsedMs({ ...spent, started_at: null, active_ms: 31 * 60_000 })).toBeLessThan(2 * HOUR);
+  });
+
+  it('活跃段分次累加：三段各 40 分钟 → 第三段跑到一半就该耗尽', () => {
+    expect(engine.wallclockElapsedMs({ active_ms: 80 * 60_000, started_at: null })).toBe(80 * 60_000);
+    const run = seedRun('r_acc', { active_ms: 119 * 60_000, started_at: null }, 'blocked');
+    expect(engine.checkBudget(run).ok).toBe(true);
+    wdb.getDb().prepare('UPDATE graph_runs SET budget_json = ? WHERE id = ?')
+      .run(budget({ active_ms: 121 * 60_000, started_at: null }), 'r_acc');
+    expect(engine.checkBudget(wdb.getRun('r_acc')).exhausted).toEqual(['wallclock_ms']);
+  });
+
+  it('settleWallclock：进 running 开始计时，离开 running 把这一段并进 active_ms', () => {
+    seedRun('r_settle', { active_ms: 5 * 60_000, started_at: null }, 'running');
+    const started = engine.settleWallclock('r_settle', 'running');
+    expect(started.started_at).toBeTruthy();
+    expect(started.active_ms).toBe(5 * 60_000);
+
+    const stopped = engine.settleWallclock('r_settle', 'blocked');
+    expect(stopped.started_at).toBeNull();
+    expect(stopped.active_ms).toBeGreaterThanOrEqual(5 * 60_000);   // 只增不减
+    expect(stopped.active_ms).toBeLessThan(6 * 60_000);             // 这一段是毫秒级，不该凭空多出一分钟
+  });
+
+  it('存量行（没有 active_ms）进 running 时按 0 起算，不把旧锚点当活跃时长', () => {
+    // 旧锚点里混着等待时间、复原不出来 —— 一笔勾销是有意的：真正兜住花钱的是调用次数与 tokens
+    seedRun('r_legacy', { agent_calls: 7, started_at: '2026-08-18T15:48:17.630Z' }, 'running');
+    const s = engine.settleWallclock('r_legacy', 'running');
+    expect(s.active_ms).toBe(0);
+    expect(Date.parse(s.started_at)).toBeGreaterThan(Date.parse('2026-08-19T00:00:00Z'));
+    expect(engine.checkBudget(wdb.getRun('r_legacy')).ok).toBe(true);
+  });
+
+  it('子 run 不动预算：结算只写 root 那一行', () => {
+    seedRun('r_root', { active_ms: 0, started_at: null }, 'running');
+    const db = wdb.getDb();
+    db.prepare(`INSERT INTO graph_runs
+        (id, graph_kind, graph_id, company_id, root_run_id, parent_run_id, execution_mode, run_status, budget_json, created_at, updated_at)
+        VALUES ('r_child','work','wg1','co1','r_root','r_root','manual','running', NULL, ?, ?)`)
+      .run('2026-08-18T15:49:00.000Z', '2026-08-18T15:49:00.000Z');
+    expect(engine.settleWallclock('r_child', 'blocked')).toBeNull();
+    const root = JSON.parse(wdb.getRun('r_root').budget_json);
+    expect(root.spent.started_at).toBeNull();  // 没被子 run 的转换改动
+  });
+
+  it('挂在漏斗上：走 sse.transitionRun 就会结算，不需要调用方记得调', () => {
+    // 这一条守的是钩子的**位置**：进 running 既不是收敛、也不空坑，
+    // 放在 afterRunTransition 那个 early return 后面就变成「只结算停下来、从不开始计时」——
+    // 症状是 active_ms 永远 0，墙钟形同虚设，而且照样全绿。
+    const sse = require('../../services/graph-run-sse');
+    seedRun('r_funnel', { active_ms: 0, started_at: null }, 'ready');
+
+    expect(sse.transitionRun('r_funnel', 'ready', 'running')).toBeTruthy();
+    expect(JSON.parse(wdb.getRun('r_funnel').budget_json).spent.started_at).toBeTruthy();
+
+    expect(sse.transitionRun('r_funnel', 'running', 'blocked')).toBeTruthy();
+    const spent = JSON.parse(wdb.getRun('r_funnel').budget_json).spent;
+    expect(spent.started_at).toBeNull();
+    expect(spent.active_ms).toBeGreaterThanOrEqual(0);
+  });
+
+  it('没配 wallclock_ms 的 run：结算是 no-op，不许凭空造出 active_ms 字段', () => {
+    const db = wdb.getDb();
+    db.prepare(`INSERT INTO graph_runs
+        (id, graph_kind, graph_id, company_id, root_run_id, execution_mode, run_status, budget_json, created_at, updated_at)
+        VALUES ('r_nowc','org','g1','co1','r_nowc','manual','running', ?, ?, ?)`)
+      .run(JSON.stringify({ total_agent_calls: 10, spent: { agent_calls: 1 } }), '2026-08-18T15:48:00.000Z', '2026-08-18T15:48:00.000Z');
+    expect(engine.settleWallclock('r_nowc', 'blocked')).toBeNull();
+    expect(JSON.parse(wdb.getRun('r_nowc').budget_json).spent).toEqual({ agent_calls: 1 });
+  });
+});
@@ -1251,6 +1251,17 @@ describe(&#39;27-P3C 批 1 验收（§八 4 / 5 / 6 / 10 / 11 / 12b）&#39;, () =&gt; {
   // 缺陷 F3 / F6 · dispatch 那条路上被丢掉和被违反的两个约定
   // ──────────────────────────────────────────────────────────────
+  /**
+   * 只比「申报的额度」，剥掉 spent。
+   *
+   * spent 是**运行期账本**：run 一进 running，墙钟就往里写 active_ms / started_at
+   * （见 budget-wallclock-active.test.js）。整个对象 deepEqual 会让这条用例在账本
+   * 新增字段时红，而它守的是「用户填的额度没被静默换成默认值」—— 跟账本长什么样无关。
+   * 账本本身另有断言：起跑那一刻还没花钱，agent_calls / tokens 必须仍是 0。
+   */
+  const limitsOf = (o) => { const { spent, ...limits } = typeof o === 'string' ? JSON.parse(o) : o; return limits; };
+  const spentOf = (o) => (typeof o === 'string' ? JSON.parse(o) : o).spent || {};
+
   it('草稿上申报的 budget 能活到 dispatch，run 拿到的不是默认额度（缺陷 F3）', async () => {
     const cid = newCompany();
     const budget = { total_agent_calls: 3, total_tokens: 5000000, wallclock_ms: 60000, spent: { agent_calls: 0, tokens: 0 } };
@@ -1265,7 +1276,9 @@ describe(&#39;27-P3C 批 1 验收（§八 4 / 5 / 6 / 10 / 11 / 12b）&#39;, () =&gt; {
     expect(s2).toBe(201);
     // 修之前这里是 DEFAULT_TASK_BUDGET（100 次调用）：用户填的 3 次被静默丢弃，
     // 他只会看到任务跑到一半 blocked，而没有任何地方说过预算被换掉了
-    expect(JSON.parse(wdb.getRun(dispatched.started.runId).budget_json)).toEqual(budget);
+    const dispatchedBudget = wdb.getRun(dispatched.started.runId).budget_json;
+    expect(limitsOf(dispatchedBudget)).toEqual(limitsOf(budget));
+    expect(spentOf(dispatchedBudget)).toMatchObject({ agent_calls: 0, tokens: 0 }); // 起跑那一刻还没花钱
     // 本次 dispatch 的 body 仍然覆盖草稿上的申报值（优先级：body > 草稿 > 默认）
     const cid2 = newCompany();
@@ -1273,7 +1286,7 @@ describe(&#39;27-P3C 批 1 验收（§八 4 / 5 / 6 / 10 / 11 / 12b）&#39;, () =&gt; {
     const override = { total_agent_calls: 9, spent: { agent_calls: 0, tokens: 0 } };
     const [s3, d2] = await call('POST', `/api/company/${cid2}/goals/${goal2.goalId}/dispatch`, { budget: override });
     expect(s3).toBe(201);
-    expect(JSON.parse(wdb.getRun(d2.started.runId).budget_json)).toEqual(override);
+    expect(limitsOf(wdb.getRun(d2.started.runId).budget_json)).toEqual(limitsOf(override));
   });
   it('坑被占着时 POST /tasks 不再 409 而是入队，申报的 budget 一路带到出队（批 3 · 缺陷 F3 的现场）', async () => {
@@ -1311,7 +1324,8 @@ describe(&#39;27-P3C 批 1 验收（§八 4 / 5 / 6 / 10 / 11 / 12b）&#39;, () =&gt; {
     expect(ok).toBe(201);
     expect(started.started.runId).toBe(body.runId); // 不是新起一条，是把排着的那条拉起来
     const runBudget = JSON.parse(wdb.getRun(body.runId).budget_json);
-    expect(runBudget).toEqual(budget);
+    expect(limitsOf(runBudget)).toEqual(limitsOf(budget));
+    expect(spentOf(runBudget)).toMatchObject({ agent_calls: 0, tokens: 0 });
     expect(runBudget.total_agent_calls).not.toBe(100); // DEFAULT_TASK_BUDGET 的值，钉住「不是默认额度」
   });