60688c3108
事故: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>
220 lines
12 KiB
TypeScript
220 lines
12 KiB
TypeScript
// execution-log — KV 額度事故修復(總管交辦,2026-08-07)測試。
|
||
// 測試策略比照既有 library-map.test.ts:真 SQLite(node: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('target:page_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% → log;80%~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=2:degrade 門檻=2*0.8=1.6,skip 門檻=2。
|
||
// 第 1 次 count=1(1<=1.6)→ log;第 2 次 count=2(1.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 route(Hono 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 → 400;GET /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);
|
||
});
|
||
});
|