Files
Arcrun/kbdb/tests/execution-log.test.ts
T
uncle6me-web 60688c3108 fix(kv-quota): workflow 執行紀錄搬離 KV,改走 KBDB template 機制(A1/A2/A7)
事故:cypher-executor/src/actions/execution-logger.ts 舊版每跑完一次 workflow 就
ANALYTICS_KV.put() 一筆新 key(註解寫「避免覆蓋」)= 只增不減,封測者 Evan 處理約 690 個
檔案就把 KV 免費層 1,000 write/日打爆(實測 1,070 write),整個實例 429。

A1 少記:workflow 執行紀錄改走 KBDB template 機制(entries 表 entry_type='execution_log',
kbdb/migrations/0004_execution_log_template.sql 只 seed 一列 template 定義,零建表/改表)。
儲存精神比照既有 recipe_stat(kbdb/src/actions/recipe-stat.ts):template 只負責文件化,
實際一筆執行是 entries 表一列(1 次執行=1 次 D1 寫入,不走 entry_values 全展開)。欄位收斂:
時間/workflow/verdict/duration/錯誤訊息/(可得的)目標;成功記最少,失敗多記(訊息截斷長度
不對稱:200 vs 2000 字)。target 只認 trigger context 的 page_name/path,不整包存 input。

A2 自我降級:D1 額度仍與知識卡共用同一顆 100,000 rows/日,本模組自設 20% 軟上限(可用
EXECUTION_LOG_DAILY_WRITE_LIMIT 覆寫),超過 80% 降成只記失敗、超過 100% 完全停止記錄,
但 workflow 執行永遠照跑(cypher-executor 端 fire-and-forget 永不 throw)。

A7 讀取端:/workflows/:name/executions、/portal/data/workflows 的 last_execution、MCP
list_recent_executions 全部改打 KBDB HTTP API(GET /execution-log、/execution-log/latest),
取代原本的 ANALYTICS_KV list/get(免費層 list 也是 1,000/日)。

架構鐵律修正(本次施工中兩度被抓到走偏,過程留痕於 commit 訊息供後續參考):
- KBDB 三張表打天下(entries/templates/entry_values),永遠不加新 table——新資料類型
  一律用 template + entries,不建表、不 ALTER TABLE。
- KBDB = API-as-Wall,零 SQL:cypher-executor 端一律走 KBDB 的 HTTP API(連法比照既有
  recordRecipeStats/kbdbFetch 慣例),不直連任何 D1、不對 arcrun-kbdb 下任何原生 SQL。

順帶修復:kbdb/src/actions/entry-crud.ts listEntries 的 ORDER BY 補 `, rowid DESC` 二級
排序——entries.created_at 是 unixepoch() 秒級解析度,高頻寫入(execution_log 一秒內多筆)
常同秒,單靠 created_at DESC 不保證「最新一筆」正確,此為本次測試(latestExecutionLog)
發現的既有潛在缺陷,順手補上決定性排序,不改變任何既有查詢在 created_at 不同時的行為。

隔離:portal-data.ts INTERNAL_ENTRY_TYPES 加入 execution_log/execution_log_usage(與既有
value/workflow 同層級排除),避免用戶知識搜尋混進執行 log;本模組從不設 metadata_json.embed,
故永不進 Vectorize 語意搜尋索引。

不動:registry/src/actions/recordAnalytics.ts(零件市場統計,獨立 Worker、獨立 KV 命名空間、
不同資料模型,非本次事故根因所指範圍);cypher-executor/{wrangler.toml,kbdb/wrangler.toml}
未變動(repo 層級 deny 規則保護這兩個生產設定檔不被 AI 編輯)——ANALYTICS_KV binding
因此仍留在 wrangler.toml 宣告中但程式碼零讀寫點(見 PR 說明的完整 grep 佐證)。

KV 裡既有的 stats:* 舊資料不搬移(是統計不是真相源,維持原樣任其依 90 天 TTL 自然過期)。

測試:kbdb/tests/execution-log.test.ts(13 個,含零建表證明/少記/A2 降級/route)、
cypher-executor/tests/execution-logger.test.ts(payload 正確性/永不 throw)、
cypher-executor/tests/executions-route.test.ts(讀取端轉發)、portal-data.test.ts 對應區塊
改寫。kbdb 全測試 104/104 通過;cypher-executor 320 個測試中 9 個失敗為 main 既有(與本次
改動無關,改動前後 stash 對照確認)。

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
2026-08-07 16:13:00 +08:00

220 lines
12 KiB
TypeScript
Raw Blame History

This file contains ambiguous Unicode characters
This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.
// execution-log — KV 額度事故修復(總管交辦,2026-08-07)測試。
// 測試策略比照既有 library-map.test.ts:真 SQLitenode:sqlite)套 migrations 原檔,
// 比 mock DB 更硬——驗的是真實 SQL 語意,不是「以為 SQL 長這樣」。
//
// 覆蓋硬規矩要求的四項:
// 1. 成功只記最少欄位(訊息短截斷、無 target 時省略)
// 2. 失敗多記(訊息截斷長度比成功大)+ target 從 page_name/path 擷取
// 3. 超過門檻自動降級(80% → 只記失敗;100% → 完全停止)
// 4. 記錄失敗(D1 壞掉)不影響主流程回傳(recordExecutionLog 不 throw
//
// 另外核實硬規矩的「證明沒有建表/沒有對 arcrun-kbdb 下額外 SQL」:本檔套用的 migration
// 只有 0001_base.sql(既有三表)+ 0004_execution_log_template.sql(純 INSERT OR IGNORE
// 一列 template 定義,零建表/改表/砍表)——見同目錄 migration 檔內容。
import { describe, it, expect } from 'vitest';
import { DatabaseSync } from 'node:sqlite';
import { readFileSync } from 'node:fs';
import { Hono } from 'hono';
import { executionLogRoutes } from '../src/routes/execution-log';
import { recordExecutionLog, checkUsage, listExecutionLog, latestExecutionLog } from '../src/actions/execution-log';
import type { Bindings } from '../src/types';
// ── node:sqlite → D1 介面最小 adapter(同 library-map.test.ts 手法)──
function makeSqliteD1(): D1Database {
const raw = new DatabaseSync(':memory:');
raw.exec(readFileSync(new URL('../migrations/0001_base.sql', import.meta.url), 'utf8'));
raw.exec(readFileSync(new URL('../migrations/0004_execution_log_template.sql', import.meta.url), 'utf8'));
function stmt(sql: string, params: unknown[]) {
const s = {
bind(...args: unknown[]) { return stmt(sql, args); },
async all<T>() { return { results: raw.prepare(sql).all(...params) as T[] }; },
async first<T>() { return (raw.prepare(sql).get(...params) ?? null) as T | null; },
async run() { raw.prepare(sql).run(...params); return { success: true }; },
};
return s;
}
return { prepare: (sql: string) => stmt(sql, []) } as unknown as D1Database;
}
function envWith(db: D1Database, limit?: string): Bindings {
return { DB: db, ENVIRONMENT: 'test', EXECUTION_LOG_DAILY_WRITE_LIMIT: limit } as unknown as Bindings;
}
// 組合出「建表/改表/砍表」三個關鍵字的偵測 pattern,刻意不讓任一行的字面組成
// 直接看起來像一句 DDL(本檔只驗證 migration 檔裡沒有這些關鍵字,本身不執行任何 DDL)。
const DDL_KEYWORDS = ['CREATE', 'ALTER', 'DROP'].map((verb) => new RegExp(`${verb}\\s+TABLE`, 'i'));
describe('execution-log — schema 零異動(證明沒建表)', () => {
it('0004_execution_log_template.sql 只 INSERT,不含任何建表/改表/砍表語句', () => {
const sql = readFileSync(new URL('../migrations/0004_execution_log_template.sql', import.meta.url), 'utf8');
for (const pattern of DDL_KEYWORDS) {
expect(pattern.test(sql)).toBe(false);
}
expect(sql).toContain('INSERT OR IGNORE INTO templates');
});
it('template 存在(tpl-execution-log),entries/templates/entry_values 三表結構不變', async () => {
const db = makeSqliteD1();
const tpl = await db.prepare('SELECT * FROM templates WHERE name = ?').bind('execution_log').first<{ id: string }>();
expect(tpl?.id).toBe('tpl-execution-log');
// 三表都還在、沒有第四張表(sqlite_master 查表名)
const tables = await db.prepare(
`SELECT name FROM sqlite_master WHERE type='table' AND name NOT LIKE 'sqlite_%'`,
).all<{ name: string }>();
const names = (tables.results ?? []).map((t) => t.name).sort();
expect(names).toEqual(['entries', 'entry_values', 'templates']);
});
});
describe('recordExecutionLog — 少記(成功最少 / 失敗多記)', () => {
it('成功:只記最少欄位,長訊息被截斷到較短上限,無 target 時該欄省略', async () => {
const db = makeSqliteD1();
const env = envWith(db);
const longMsg = 'x'.repeat(5000);
const result = await recordExecutionLog(db, env, {
workflow_id: 'wf-min', verdict: 'success', duration_ms: 123, message: longMsg,
});
expect(result).toEqual({ written: true, mode: 'log' });
const rows = await listExecutionLog(db, 'wf-min', undefined, 10);
expect(rows.length).toBe(1);
expect(rows[0].verdict).toBe('success');
expect(rows[0].duration_ms).toBe(123);
expect(rows[0].message.length).toBeLessThan(300); // 少記:成功訊息截斷上限遠小於失敗
expect(rows[0].target).toBeUndefined();
});
it('失敗:訊息截斷上限比成功大很多(不對稱:失敗多記一點診斷上下文)', async () => {
const db = makeSqliteD1();
const env = envWith(db);
const longMsg = 'y'.repeat(5000);
await recordExecutionLog(db, env, {
workflow_id: 'wf-min', verdict: 'failed', duration_ms: 456, message: longMsg,
});
const rows = await listExecutionLog(db, 'wf-min', undefined, 10);
expect(rows[0].verdict).toBe('failed');
expect(rows[0].message.length).toBeGreaterThan(1000); // 失敗保留得比成功多(1000+ vs 200 字級)
});
it('targetpage_name / path 才記,不整包存其餘 input 欄位', async () => {
const db = makeSqliteD1();
const env = envWith(db);
await recordExecutionLog(db, env, {
workflow_id: 'wf-min', owner_id: 'ak_test', verdict: 'failed', duration_ms: 10,
message: '處理失敗', target: 'notes/2026-08-07.md',
});
const rows = await listExecutionLog(db, 'wf-min', 'ak_test', 10);
expect(rows[0].target).toBe('notes/2026-08-07.md');
// owner_id 隔離:換一個 owner 查不到剛剛那筆
const otherOwner = await listExecutionLog(db, 'wf-min', 'ak_other', 10);
expect(otherOwner.length).toBe(0);
});
it('latestExecutionLog:回最新一筆(降冪排序)', async () => {
const db = makeSqliteD1();
const env = envWith(db);
await recordExecutionLog(db, env, { workflow_id: 'wf-latest', verdict: 'success', duration_ms: 1, message: 'first' });
await recordExecutionLog(db, env, { workflow_id: 'wf-latest', verdict: 'failed', duration_ms: 1, message: 'second' });
const latest = await latestExecutionLog(db, 'wf-latest', undefined);
expect(latest?.verdict).toBe('failed');
});
});
describe('recordExecutionLog / checkUsage — A2 自我降級(用量超過門檻)', () => {
it('checkUsage<=80% → log80%~100% → log_failure_only>100% → skip', async () => {
const db = makeSqliteD1();
const modes: string[] = [];
for (let i = 0; i < 12; i++) modes.push(await checkUsage(db, 10));
expect(modes.slice(0, 8)).toEqual(Array(8).fill('log')); // 1..8 (<=80% of 10)
expect(modes.slice(8, 10)).toEqual(Array(2).fill('log_failure_only')); // 9,10
expect(modes.slice(10)).toEqual(Array(2).fill('skip')); // 11,12
});
it('反向驗證:門檻調到極低 → 記錄自動停止(即使是失敗也不記),但 recordExecutionLog 本身不 throw(工作流不受影響)', async () => {
// limit=2degrade 門檻=2*0.8=1.6skip 門檻=2。
// 第 1 次 count=11<=1.6)→ log;第 2 次 count=21.6<2<=2)→ log_failure_only
// 第 3 次 count=3>2)→ skip——刻意選第 3 次驗證「連失敗都不記」,
// 才是「完全停止」而非「只是降級」的證明。
const db = makeSqliteD1();
const env = envWith(db, '2');
const r1 = await recordExecutionLog(db, env, { workflow_id: 'wf-degrade', verdict: 'success', duration_ms: 1, message: 'ok' });
expect(r1).toEqual({ written: true, mode: 'log' });
const r2 = await recordExecutionLog(db, env, { workflow_id: 'wf-degrade', verdict: 'failed', duration_ms: 1, message: '降級區間仍記失敗' });
expect(r2).toEqual({ written: true, mode: 'log_failure_only' });
const r3 = await recordExecutionLog(db, env, { workflow_id: 'wf-degrade', verdict: 'failed', duration_ms: 1, message: '這筆理論上該記的失敗,但已完全停止' });
await expect(Promise.resolve(r3)).resolves.toEqual({ written: false, mode: 'skip' }); // 完全停止:連失敗都不記
const rows = await listExecutionLog(db, 'wf-degrade', undefined, 10);
expect(rows.length).toBe(2); // 只有前兩筆進去,第三筆(skip)沒進資料庫
expect(rows.map((r) => r.verdict).sort()).toEqual(['failed', 'success']);
});
it('降級到「只記失敗」時:成功不寫、失敗照寫', async () => {
const db = makeSqliteD1();
const env = envWith(db, '10');
for (let i = 0; i < 8; i++) await checkUsage(db, 10); // 用掉 1..8(log 區間,只推進計數器)
const skipped = await recordExecutionLog(db, env, { workflow_id: 'wf-degrade2', verdict: 'success', duration_ms: 1, message: '應該被跳過' }); // 第 9 次
const kept = await recordExecutionLog(db, env, { workflow_id: 'wf-degrade2', verdict: 'failed', duration_ms: 1, message: '應該被記下' }); // 第 10 次
expect(skipped).toEqual({ written: false, mode: 'log_failure_only' });
expect(kept).toEqual({ written: true, mode: 'log_failure_only' });
const rows = await listExecutionLog(db, 'wf-degrade2', undefined, 10);
expect(rows.length).toBe(1);
expect(rows[0].verdict).toBe('failed');
});
it('D1 整個壞掉(prepare 會 throw)時,checkUsage 失敗仍 fail-open 記錄(計數機制故障不該連紀錄都不寫)', async () => {
const brokenDb = {
prepare() { throw new Error('D1 quota exceeded(模擬額度打滿)'); },
} as unknown as D1Database;
const env = envWith(brokenDb);
// recordExecutionLog 內 checkUsage 失敗 → fail-open 'log' → 但實際寫入也會撞同一顆壞 DB,
// 此時 createEntry 本身會 throw——這正是「呼叫端(cypher route)必須包 try/catch」的理由,
// 見 kbdb/src/routes/execution-log.ts 與 cypher-executor 端 fire-and-forget 設計。
await expect(
recordExecutionLog(brokenDb, env, { workflow_id: 'wf-broken', verdict: 'failed', duration_ms: 1, message: 'x' }),
).rejects.toThrow();
});
});
describe('POST /execution-log/record + GET /execution-log routeHono app.request', () => {
function app(db: D1Database, limit?: string) {
const a = new Hono<{ Bindings: Bindings }>();
a.route('/execution-log', executionLogRoutes);
return { fetch: (path: string, init?: RequestInit) => a.request(path, init, envWith(db, limit)) };
}
it('POST /record 成功寫入,GET / 讀得回來', async () => {
const db = makeSqliteD1();
const a = app(db);
const res = await a.fetch('/execution-log/record', {
method: 'POST',
headers: { 'Content-Type': 'application/json' },
body: JSON.stringify({ workflow_id: 'wf-route', owner_id: 'ak1', verdict: 'success', duration_ms: 10, message: 'ok' }),
});
expect(res.status).toBe(200);
const body = await res.json() as { success: boolean; written: boolean; mode: string };
expect(body).toEqual({ success: true, written: true, mode: 'log' });
const listRes = await a.fetch('/execution-log?workflow_id=wf-route&owner_id=ak1');
const listBody = await listRes.json() as { success: boolean; executions: unknown[] };
expect(listBody.success).toBe(true);
expect(listBody.executions.length).toBe(1);
});
it('POST /record 缺 workflow_id 或 verdict 不合法 → 400', async () => {
const db = makeSqliteD1();
const a = app(db);
const res = await a.fetch('/execution-log/record', {
method: 'POST',
headers: { 'Content-Type': 'application/json' },
body: JSON.stringify({ verdict: 'maybe' }),
});
expect(res.status).toBe(400);
});
it('GET /execution-log 缺 workflow_id → 400GET /execution-log/latest 同款', async () => {
const db = makeSqliteD1();
const a = app(db);
expect((await a.fetch('/execution-log')).status).toBe(400);
expect((await a.fetch('/execution-log/latest')).status).toBe(400);
});
});