From 2905194d238938861ef47e9316e73547ef3ad99e Mon Sep 17 00:00:00 2001 From: Claude Date: Tue, 4 Aug 2026 12:25:19 +0000 Subject: [PATCH] fix(runtime,tooling): add saveMetaItem to the durability vocabulary and stop the publish visibility flip losing writes silently (#4754) #4632's gate only knows the callees in DURABILITY_CRITICAL_CALLEES, so it cannot discover a new persistence seam. saveMetaItem was one of the seams it could not see -- the #4669 shape exactly. Adding the entry surfaced 8 catches. Judged one by one, 4 were real reports of the gate's own imprecision and 1 was a genuine silent loss: * packages/runtime/src/domains/packages.ts -- ADR-0045's visibility flip is a metadata WRITE riding on a publish that already succeeded, so the route answers 200 either way and the failure only left an unhideError nobody reads. Now reported at `error` naming the consequence (apps stay stored hidden:true and invisible while the publish reports success) and the fix (re-run publish-drafts, idempotent; or PUT /meta/app/ hidden:false), per the service-automation start() exemplar. Response contract unchanged. Two precision defects in the checker, both fixed with bidirectional self-test cases (the pnpm script runs --self-test, so CI enforces them): * A same-file concise-arrow reporter was invisible. The catch side is documented to follow same-file helpers, but the walker only visited children and `const logError = (...a) => console.error(...a)` IS the call expression, so rest-server.ts's two loudest /meta PUT handlers read as silent-swallow. * One seam was accused once per level of nesting. A call already consumed by an inner recovering catch was still attributed to every enclosing catch -- which are generic route-level handlers that are correct as written. Only an inner catch that propagates on every path now leaves the outer catch a real guard. The 3 remaining sites propagate the failure to the caller (meta.ts returns a field-anchored 4xx/422; protocol.ts's two batch paths write it into their per-item outcome report and flip the aggregate). Those are not degradations, so they are baselined with reasons and a closing condition rather than being raised to `error` -- which on the meta.ts path would emit a durability error per off-spec body, the mirror-image failure AGENTS.md warns about. The gate cannot yet express "reported to the caller"; filed as #5241. Co-Authored-By: Claude Fable 5 Claude-Session: https://claude.ai/code/session_01Pbu27iNUfQCHeuS551Rqo7 --- .changeset/durability-gate-savemetaitem.md | 35 +++ packages/runtime/src/domains/packages.ts | 18 ++ packages/runtime/src/http-dispatcher.test.ts | 47 ++++ ...check-durability-degradation-log-level.mjs | 201 ++++++++++++++++-- scripts/durability-degradation.baseline.json | 51 ++++- 5 files changed, 330 insertions(+), 22 deletions(-) create mode 100644 .changeset/durability-gate-savemetaitem.md diff --git a/.changeset/durability-gate-savemetaitem.md b/.changeset/durability-gate-savemetaitem.md new file mode 100644 index 0000000000..30500d4806 --- /dev/null +++ b/.changeset/durability-gate-savemetaitem.md @@ -0,0 +1,35 @@ +--- +"@objectstack/runtime": patch +--- + +fix(runtime,tooling): `saveMetaItem` 进入持久性词表,包发布的可见性翻转不再静默丢写 (#4754) + +#4632 立的「Degradation log levels」规则由 `pnpm check:durability-log-level` 机械执行, +但它只认 `DURABILITY_CRITICAL_CALLEES` 这张显式词表 —— 词表以外的持久性接缝它发现不了。 +#4669 的事故正是这一类:`protocol.saveMetaItem()` 失败被吞掉,整条投影路径停摆却一个红灯 +都没有,跨了一个发布周期才被偶然看见。本次把 `saveMetaItem` 加进词表,并把它照出来的 +每一处逐个判过。 + +**真丢失的那一处已修好。** `POST /packages/:id/publish-drafts` 的 ADR-0045 可见性翻转 +(`packages/runtime/src/domains/packages.ts`)是一次搭别人便车的元数据**写入**:草稿已经 +发布,所以这个路由无论如何都答 200,而写失败只会在响应体里留下一个没人读的 `unhideError`。 +症状因此是「我明明发布了,应用却没出现」,而且要很久以后才有人把它和这里联系起来 —— +正是 #4669 的形状。现在它按范本在 `error` 级别报告:点名是哪个包、其 app 仍然以 +`hidden: true` 存着因而在启动器里不可见、发布却报告了成功,并给出修复动作(重跑 +publish-drafts,幂等;或直接 `PUT /meta/app/` 置 `hidden: false`),同时带上原始 +错因。响应契约不变 —— 仍然是 200,仍然带 `unhideError`。 + +**闸门自身的两个精度缺陷一并修掉**(词表加一个条目就让它们暴露了,8 处命中里 4 处是误报): + +- **同文件 concise-arrow 报告器看不见。** 闸门文档明说 `catch` 一侧会追同文件的 helper, + 但遍历只访问子节点,而 `const logError = (...a) => console.error(...a)` 的函数体**就是** + 那个调用表达式本身,于是 `rest-server.ts` 里最响的两处 `/meta` PUT 反被判成「完全静默」。 +- **一处接缝被按嵌套层数重复指认。** 一个已被内层 `catch` 消化掉的调用,仍然算在每一层 + 外层 `catch` 头上 —— 而那些外层多半是正确的路由级错误处理器。`packages.ts` 里同一个 + `saveMetaItem` 因此被报了三次。现在只有当内层 `catch` 每条路径都向外传播时,外层才被 + 判定为真正的守卫。 + +两个修复都在 `--self-test` 里双向钉住(改前必失败,改后才通过),自测用例由 CI 执行。 + +判定为「故障已答给调用方」的三处(`meta.ts` 的 4xx/422、`protocol.ts` 两处结构化逐项 +失败报告)不是降级,记入 shrink-only 基线并附理由与关闭条件(#5241)。 diff --git a/packages/runtime/src/domains/packages.ts b/packages/runtime/src/domains/packages.ts index b9670cebba..42bde9da5c 100644 --- a/packages/runtime/src/domains/packages.ts +++ b/packages/runtime/src/domains/packages.ts @@ -230,6 +230,24 @@ export async function handlePackagesRequest(deps: DomainHandlerDeps, path: strin if (unhidden.length > 0) (result as any).unhiddenApps = unhidden; } } catch (e: any) { + // #4754 — ADR-0045's visibility flip is a metadata WRITE + // riding on someone else's success. The drafts are already + // promoted, so this route answers 200 either way, and + // `unhideError` lands in a response body no operator reads. + // That is the #4669 shape exactly: the write did not land, + // the runtime looks completely healthy, and the loss only + // surfaces later as "I published it but the app isn't + // there". So it is reported at `error` (AGENTS.md → + // "Degradation log levels"), not swallowed. + const logger = deps.logger ?? console; + logger.error( + `[Packages] publish-drafts: the ADR-0045 visibility flip FAILED for package '${id}' — its drafts ARE ` + + `published and live, but every hidden app bound to it is still STORED with \`hidden: true\`, so those ` + + `apps stay invisible in the launcher while the publish reports success. Nothing retries this flip. ` + + `Re-run POST /packages/${id}/publish-drafts once the cause below is resolved (it is idempotent), or ` + + `unhide one app directly via PUT /meta/app/ with \`{"hidden": false}\`. Cause: ` + + `${e?.message ?? String(e)}`, + ); (result as any).unhideError = e?.message ?? 'visibility flip failed'; } // A publish promoted drafts to active (or unhid an additive diff --git a/packages/runtime/src/http-dispatcher.test.ts b/packages/runtime/src/http-dispatcher.test.ts index 901897001a..3ed46db2c9 100644 --- a/packages/runtime/src/http-dispatcher.test.ts +++ b/packages/runtime/src/http-dispatcher.test.ts @@ -1874,6 +1874,53 @@ describe('HttpDispatcher', () => { expect((result.response as any)?.body?.data?.unhideError).toBe('meta backend down'); expect(saveMetaItem).not.toHaveBeenCalled(); }); + + // #4754 — the flip is a metadata WRITE riding on someone else's success. + // `unhideError` in a 200 body is not a signal anyone reads: the route + // still answers success, so the loss ("I published it but the app never + // appeared") surfaces much later to someone who cannot connect it back + // here. That is the #4669 shape, so AGENTS.md → "Degradation log levels" + // requires `error`, naming the CONSEQUENCE and the FIX. + it('POST /packages/:id/publish-drafts logs at ERROR (consequence + fix) when the saveMetaItem write fails', async () => { + const publishPackageDrafts = vi.fn().mockResolvedValue({ + success: true, publishedCount: 1, failedCount: 0, published: [], failed: [], seedApplied: { success: true }, + }); + const getMetaItems = vi.fn().mockResolvedValue([ + { name: 'edu_admin', hidden: true, navigation: [] }, + ]); + const saveMetaItem = vi.fn().mockRejectedValue(new Error('sys_metadata write rejected')); + (kernel as any).getService = vi.fn().mockImplementation((name: string) => { + if (name === 'protocol') return Promise.resolve({ publishPackageDrafts, getMetaItems, saveMetaItem }); + if (name === 'objectql') return Promise.resolve({ registry: { getAllPackages: vi.fn().mockReturnValue([]) } }); + return null; + }); + // No host logger is attached to the dispatcher in this harness, so + // the domain falls back to `console` (`deps.logger ?? console`). + const errorSpy = vi.spyOn(console, 'error').mockImplementation(() => {}); + + try { + const result = await dispatcher.handlePackages('/app.edu/publish-drafts', 'POST', {}, {}, { request: {} }); + + // Unchanged contract: the drafts ARE published, so this still 200s + // and still carries the machine-readable `unhideError`. + expect(result.response?.status).toBe(200); + expect((result.response as any)?.body?.data?.unhideError).toBe('sys_metadata write rejected'); + + expect(errorSpy).toHaveBeenCalledTimes(1); + const line = String(errorSpy.mock.calls[0]?.[0] ?? ''); + // The consequence, concretely — what is not durable, and that the + // system keeps looking healthy anyway. + expect(line).toContain('app.edu'); + expect(line).toMatch(/hidden/i); + expect(line).toMatch(/publish reports success|reports success/i); + // The fix — the concrete action that restores the intended state. + expect(line).toContain('publish-drafts'); + // And the cause is not swallowed. + expect(line).toContain('sys_metadata write rejected'); + } finally { + errorSpy.mockRestore(); + } + }); }); // ═══════════════════════════════════════════════════════════════ diff --git a/scripts/check-durability-degradation-log-level.mjs b/scripts/check-durability-degradation-log-level.mjs index 3c4bcb563f..436b1407ab 100644 --- a/scripts/check-durability-degradation-log-level.mjs +++ b/scripts/check-durability-degradation-log-level.mjs @@ -140,6 +140,10 @@ const DURABILITY_CRITICAL_CALLEES = new Map([ 'dropPromotedDraftRow', "A published draft was never drained — the active row is correct, but the `state='draft'` row is still in `sys_metadata`, so Studio/Setup keeps showing unpublished changes that do not exist and the next publish promotes the same stale body again (#4981).", ], + [ + 'saveMetaItem', + 'The metadata definition was never written to the authoritative store — the runtime looks completely normal because the in-memory registry already has it, and the definition simply vanishes on the next provision/restart (#4754, from #4669).', + ], ]); /** Log levels that are ACCEPTABLE inside a durability-guarding catch. */ @@ -179,24 +183,42 @@ function collectSourceFiles(dir, out = []) { return out; } +/** Does this node's body run LATER (a callback), rather than on this tick? */ +function runsLater(node) { + return ( + ts.isFunctionDeclaration(node) || + ts.isFunctionExpression(node) || + ts.isArrowFunction(node) || + ts.isMethodDeclaration(node) || + ts.isClassDeclaration(node) || + ts.isClassExpression(node) + ); +} + /** Walk `node`'s subtree without descending into bodies that run LATER. */ function walkSameTick(node, visit) { node.forEachChild((child) => { - if ( - ts.isFunctionDeclaration(child) || - ts.isFunctionExpression(child) || - ts.isArrowFunction(child) || - ts.isMethodDeclaration(child) || - ts.isClassDeclaration(child) || - ts.isClassExpression(child) - ) { - return; - } + if (runsLater(child)) return; visit(child); walkSameTick(child, visit); }); } +/** + * `walkSameTick`, plus the node itself. + * + * A concise-arrow helper body (`const logError = (...a) => console.error(...a)`) + * IS the call expression, not a block containing one, so a plain `walkSameTick` + * — which only ever visits CHILDREN — never inspects it and the helper reads as + * silent. That shape is exactly the same-file reporter the `catch` side is + * documented to follow, so missing it made a genuinely loud catch report as + * `silent-swallow` (`rest-server.ts`'s two `/meta` PUT handlers, #4754). + */ +function walkSameTickInclusive(node, visit) { + visit(node); + walkSameTick(node, visit); +} + /** Walk everything, including nested function bodies. */ function walkAll(node, visit) { node.forEachChild((child) => { @@ -280,7 +302,7 @@ function analyzeSourceFile(sf, relPath, findings, seams) { const collectResponse = (block, seen = new Set(), depth = 0) => { const levels = []; let rethrows = false; - walkSameTick(block, (child) => { + walkSameTickInclusive(block, (child) => { if (ts.isThrowStatement(child)) rethrows = true; const level = loggerLevel(child); if (level) { @@ -349,20 +371,65 @@ function analyzeSourceFile(sf, relPath, findings, seams) { return sawReturn || !block.statements.some(alwaysThrows); }; - walkAll(sf, (node) => { - if (!ts.isTryStatement(node) || !node.catchClause) return; - - // 1. Does the guarded block call a durability-critical operation? + /** + * Collect the durability-critical calls a `catch` ACTUALLY guards. + * + * A call wrapped in a NESTED try whose own catch RECOVERS can never reach + * the outer catch — the inner catch consumed it, and that inner catch is + * judged on its own as a seam in its own right. Attributing the call to + * every enclosing catch as well reported ONE seam once per level of + * nesting, and the enclosing handlers it accused are usually generic + * request-level error handlers that are correct as written. That pressures + * an author to baseline correct code, which is how a shrink-only ledger + * stops meaning anything (#4754: one `saveMetaItem` in `packages.ts` + * surfaced three times — at its real seam and at the two route/function + * level `catch`es enclosing it). + * + * Only an inner catch that propagates on EVERY path (see `catchRecovers`) + * actually delivers the failure outward, and then the outer catch is a real + * guard and is judged as one. Coverage is never lost either way: the + * shadowing catch is itself checked. + */ + const collectGuardedCalls = (tryBlock) => { const guarded = []; - const inspectForCritical = (child) => { + const inspect = (child) => { const name = calleeName(child); if (name && DURABILITY_CRITICAL_CALLEES.has(name)) { guarded.push({ callee: name, line: lineOf(child) }); } }; + const walk = (n) => { + n.forEachChild((child) => { + if (runsLater(child)) return; + if ( + ts.isTryStatement(child) && + child.catchClause && + catchRecovers(child.catchClause.block) + ) { + // The inner TRY block is shadowed. Its `catch`/`finally` + // bodies are not — a critical call there does propagate out. + for (const b of [child.catchClause.block, child.finallyBlock]) { + if (!b) continue; + inspect(b); + walk(b); + } + return; + } + inspect(child); + walk(child); + }); + }; // The try block itself may BE a call at top level, so check it too. - inspectForCritical(node.tryBlock); - walkSameTick(node.tryBlock, inspectForCritical); + inspect(tryBlock); + walk(tryBlock); + return guarded; + }; + + walkAll(sf, (node) => { + if (!ts.isTryStatement(node) || !node.catchClause) return; + + // 1. Does the guarded block call a durability-critical operation? + const guarded = collectGuardedCalls(node.tryBlock); if (guarded.length === 0) return; // 2. How does the catch respond? @@ -636,6 +703,91 @@ function selfTest() { } }`, expectViolation: true, }, + { + // #4754: `rest-server.ts` reports through + // `const logError = (...a) => console.error(...a)` — a same-file + // helper the catch side is DOCUMENTED to follow. Its body is the + // call expression itself, not a block containing one, and the + // walker only ever visited CHILDREN, so the loudest site in the + // file read as `silent-swallow`. A false positive here is not + // cosmetic: the only ways to satisfy it are to baseline correct + // code or to bolt on a redundant log. + name: 'passes: catch delegating to a loud CONCISE-ARROW helper (expression body)', + code: ` + const logError = (...args: unknown[]) => (globalThis as any).console?.error(...args); + class P { async f(driver: any, obj: any) { + try { await driver.syncSchema('t', obj); } catch (e) { logError('DDL never ran', e); } + } }`, + expectViolation: false, + }, + { + name: 'flags: catch delegating to a QUIET concise-arrow helper (expression body)', + code: ` + const note = (...args: unknown[]) => (globalThis as any).console?.warn(...args); + class P { async f(driver: any, obj: any) { + try { await driver.syncSchema('t', obj); } catch (e) { note('failed', e); } + } }`, + expectViolation: true, + }, + { + // #4754: one `saveMetaItem` in `packages.ts` was reported THREE + // times — at its real seam and again at each enclosing route- and + // function-level catch, neither of which can ever observe it. The + // enclosing handlers are correct as written, so every extra report + // is pressure to baseline correct code. + name: 'passes: enclosing catch is not accused when an inner RECOVERING catch already consumed the call', + code: ` + class P { async f(ctx: any, driver: any, obj: any) { + try { + try { await driver.syncSchema('t', obj); } + catch (e) { ctx.logger.error('DDL never ran — not durable; fix X', e); } + return 'ok'; + } catch (outer) { return 'failed'; } + } }`, + expectViolation: false, + expectCount: 0, + }, + { + name: 'flags: the inner catch itself is still judged (no coverage lost to shadowing)', + code: ` + class P { async f(ctx: any, driver: any, obj: any) { + try { + try { await driver.syncSchema('t', obj); } + catch (e) { ctx.logger.warn('oh well', e); } + return 'ok'; + } catch (outer) { return 'failed'; } + } }`, + expectViolation: true, + // Exactly one: the inner seam. The outer catch never sees it. + expectCount: 1, + }, + { + name: 'flags: enclosing catch IS accused when the inner catch rethrows on every path', + code: ` + class P { async f(ctx: any, driver: any, obj: any) { + try { + try { await driver.syncSchema('t', obj); } + catch (e) { throw e; } + return 'ok'; + } catch (outer) { return 'failed'; } + } }`, + expectViolation: true, + // Only the outer one: the inner catch propagates, so it is excused + // and the failure genuinely arrives at the outer catch. + expectCount: 1, + }, + { + name: 'flags: a critical call in an inner CATCH body still reaches the enclosing catch', + code: ` + class P { async f(ctx: any, driver: any, obj: any, fallback: any) { + try { + try { await driver.initObjects(obj); } + catch (e) { ctx.logger.error('primary failed; retrying', e); await driver.syncSchema('t', fallback); } + return 'ok'; + } catch (outer) { return 'failed'; } + } }`, + expectViolation: true, + }, ]; let failures = 0; @@ -645,9 +797,18 @@ function selfTest() { const seams = []; analyzeSourceFile(sf, 't.ts', findings, seams); const got = findings.length > 0; - if (got !== c.expectViolation) { + // `expectCount` pins HOW MANY seams a case reports, not just whether it + // reports one. Nesting cases need it: "still flags" is satisfied both by + // the correct single finding and by the duplicate-per-nesting-level bug + // it replaced, so a boolean cannot tell those two apart (#4754). + const countMismatch = c.expectCount !== undefined && findings.length !== c.expectCount; + if (got !== c.expectViolation || countMismatch) { failures++; - console.error(` ✗ ${c.name}: expected violation=${c.expectViolation}, got ${got}`); + console.error( + ` ✗ ${c.name}: expected violation=${c.expectViolation}` + + (c.expectCount !== undefined ? ` count=${c.expectCount}` : '') + + `, got violation=${got} count=${findings.length}`, + ); } else { console.log(` ✓ ${c.name}`); } diff --git a/scripts/durability-degradation.baseline.json b/scripts/durability-degradation.baseline.json index d5095d3ecc..7a75ad1b87 100644 --- a/scripts/durability-degradation.baseline.json +++ b/scripts/durability-degradation.baseline.json @@ -5,7 +5,54 @@ "site that gets fixed must have its entry deleted in the same PR. There is deliberately", "no `--fix`/`--update` flag — a generator would let a new violation be admitted by", "'just run the update command', which is precisely how a gate stops meaning anything.", - "Every entry names WHY it is still here and WHAT closes it." + "Every entry names WHY it is still here and WHAT closes it.", + "", + "Key granularity is `::`, NOT a line — line numbers churn on every", + "unrelated edit and a line-keyed ledger would go stale constantly. The cost is that an", + "entry licenses the WHOLE file for that callee: a genuinely new silent swallow of the", + "same callee in an already-listed file would be excused. Read the entry's `sites` list", + "as the set it was reviewed against, and re-review when that file grows a new one." ], - "entries": [] + "entries": [ + { + "file": "packages/runtime/src/domains/meta.ts", + "callee": "saveMetaItem", + "sites": ["PUT /metadata/:type/:name — catch → deps.errorFromThrown(e, 400)"], + "reason": [ + "Not a degradation: `saveMetaItem` IS this request's primary operation, and the catch", + "hands the failure straight back to the caller as a real 4xx/422 error envelope", + "(errorFromThrown preserves the protocol's own `.status` plus the structured", + "spec-validation `issues`). Nothing continues on a reduced path and nothing looks", + "normal afterwards — the Studio that asked for the save is told, field-anchored, that", + "it did not happen. AGENTS.md's judgment question ('does the system still look normal", + "while something it claims is persisted has not landed?') answers NO here.", + "Raising it to `error` would be the mirror-image failure AGENTS.md warns about: the", + "common case on this path is an author submitting an off-spec body, so it would emit a", + "durability `error` per bad keystroke and train everyone to skim `error` — which is", + "what made the #4420 `warn` unreadable in the first place." + ], + "closes": "#5241 — teach the checker a DECLARED failure-propagation vocabulary (a catch whose every path returns an error envelope propagates the failure and is not a degradation), then delete this entry. Until then the gate cannot tell 'reported to the caller' from 'swallowed'.", + "added": "2026-08-04 (#4754, the PR that added `saveMetaItem` to DURABILITY_CRITICAL_CALLEES)" + }, + { + "file": "packages/metadata-protocol/src/protocol.ts", + "callee": "saveMetaItem", + "sites": [ + "migrateStoredItems() apply pass — catch → record({ outcome: 'failed', reason }), which increments report.failed and itemises the row", + "duplicate/copy into target package — catch → failed.push({ type, name, error }), which flips the returned `success` to false and populates failedCount/failed[]" + ], + "reason": [ + "Not a degradation: both are batch operations whose CONTRACT is a per-item outcome", + "report, and both catches write the failure into that report rather than dropping it.", + "The first increments a `failed` counter and itemises the row with its reason; the", + "second flips the aggregate `success` to false and returns the failed item in", + "`failed[]`. This is strictly louder than a log line — it is the `error` + counter", + "shape #4669 itself adopted, delivered as structured data the caller cannot miss.", + "The system does not look normal afterwards: the response says, per item, that the", + "write did not land." + ], + "closes": "#5241 — same declared failure-propagation vocabulary (structured per-item outcome reports are the second shape it must cover), then delete this entry.", + "added": "2026-08-04 (#4754, the PR that added `saveMetaItem` to DURABILITY_CRITICAL_CALLEES)" + } + ] }