From a91725f9e46b9a0f5c15f6ba67ce935511b5b8dd Mon Sep 17 00:00:00 2001 From: Claude Date: Mon, 12 Oct 2026 11:47:11 +0000 Subject: [PATCH 1/6] check:durability-log-level: read what .call/.apply/.bind invoke on the guarded side; declare syncObjectSchema The guarded-side callee read used the property a call is spelled through, so `sync.call(engine, name)` read as `call`. It now resolves the adapter to the function it invokes, through a scope-aware const alias, the way the log side has read the same adapters for a long time. The plain reading is still consulted, so reach is only added. `syncObjectSchema` joins the vocabulary. On this commit the checker is RED on the four members it now sees (service-messaging, service-datasource, metadata-protocol, cli); the plugin-audit site is seen and already loud. The members are answered in the next commits. Claude-Session: https://claude.ai/code/session_01CeRCvvvjxbxu2iYJAc5Cce Co-authored-by: Claude --- ...check-durability-degradation-log-level.mjs | 253 +++++++++++++++++- 1 file changed, 247 insertions(+), 6 deletions(-) diff --git a/scripts/check-durability-degradation-log-level.mjs b/scripts/check-durability-degradation-log-level.mjs index 1f3bd68d61c..f25dc3e2e01 100644 --- a/scripts/check-durability-degradation-log-level.mjs +++ b/scripts/check-durability-degradation-log-level.mjs @@ -344,6 +344,10 @@ const DURABILITY_CRITICAL_CALLEES = new Map([ 'syncRegisteredSchemas', 'The schema-sync pass never completed — objects are registered and served against tables that were never created or altered.', ], + [ + 'syncObjectSchema', + "One object's storage was never set up on demand — for a managed object its table/columns were not created or altered, for a federated object its binding to the remote table was not installed — yet the object stays registered and served. Its callers run AFTER the boot's own schema sync (a service provisioning its tables at kernel:ready, a datasource connected late, a publish), so the boot's sync never covers them and nothing reports the gap: the deployment keeps looking healthy while writes to that object fail or land nowhere and reads fail or answer from the wrong table.", + ], [ 'initObjects', 'Object storage was never initialized — writes go to a table that does not exist.', @@ -1878,6 +1882,158 @@ function calleeName(node) { return undefined; } +/** + * The GUARDED side's callee read (#22985): which declared durability-critical + * operation, if any, does this call INVOKE? + * + * `calleeName()` reads the property a call is spelled through, so + * `sync.call(engine, name)` reads as `call`. That is the right answer for + * every other use of it in this file (helper following, the read vocabulary), + * and the wrong one here: `.call(recv, …)` / `.apply(recv, args)` / + * `.bind(recv)(…)` are ADAPTERS, and what runs is the function they are + * applied to. `resolveLogCallee` has read them that way on the LOG side since + * #9657; this is the same reading on the guarded side, nothing more. + * + * The adapter is spelled because the operation is optional on its contract + * (`IDataEngine.syncObjectSchema?`): a caller probes it into a local + * (`const sync = engine.syncObjectSchema`) and calls the local with the + * engine as its receiver. So the function value is resolved through a + * `const` alias too, with the scope rules a reader would apply: + * + * - the NEAREST enclosing declaration of the name wins, walking out from the + * call; a parameter, a `catch` binding, a loop variable or a function + * declaration of that name in between SHADOWS any outer alias and stops + * the walk, unresolved; + * - only `const` is an alias — a `let`/`var` binding can be reassigned + * after it is read, and a destructured binding names no single value; + * - a bare `.bind(recv)` invokes nothing, so it is not a guarded call (it + * is a call of `bind`), while `fn.bind(recv)(…)` and a `const` holding + * `fn.bind(recv)` are calls of `fn`. + * + * Reach is only ever ADDED: the plain `calleeName()` reading is still + * consulted, so a call this resolver reads differently can never drop a seam + * the gate already held. The vocabulary is unchanged by this function — it + * matches the same names, through more of the spellings that invoke them. + */ +function guardedCriticalCallee(node) { + if (!ts.isCallExpression(node)) return undefined; + for (const name of [invokedOperationName(node.expression, 0), calleeName(node)]) { + if (name && DURABILITY_CRITICAL_CALLEES.has(name)) return name; + } + return undefined; +} + +/** `(…)`, `…!`, `… as T`, `…`, `… satisfies T` — the value is unchanged. */ +function stripValueWrappers(expr) { + let e = expr; + while ( + e && + (ts.isParenthesizedExpression(e) || + ts.isNonNullExpression(e) || + ts.isAsExpression(e) || + ts.isTypeAssertionExpression(e) || + (typeof ts.isSatisfiesExpression === 'function' && ts.isSatisfiesExpression(e))) + ) { + e = e.expression; + } + return e; +} + +/** The name of the operation a call whose callee is `calleeExpr` invokes. */ +function invokedOperationName(calleeExpr, depth) { + if (depth > MAX_CALLEE_RESOLUTION_DEPTH) return undefined; + const expr = stripValueWrappers(calleeExpr); + if (!expr) return undefined; + if (ts.isPropertyAccessExpression(expr) && ts.isIdentifier(expr.name)) { + const name = expr.name.text; + if (name === 'call' || name === 'apply') return functionValueName(expr.expression, depth + 1); + return name; + } + // `fn.bind(recv)(…)`: the callee is itself the `.bind(…)` call. + if (ts.isCallExpression(expr)) { + const target = boundTarget(expr); + return target ? functionValueName(target, depth + 1) : undefined; + } + if (ts.isIdentifier(expr)) return functionValueName(expr, depth + 1); + return undefined; +} + +/** `fn.bind(recv)` → `fn`; anything else → undefined. */ +function boundTarget(call) { + const callee = stripValueWrappers(call.expression); + if (callee && ts.isPropertyAccessExpression(callee) && ts.isIdentifier(callee.name) && callee.name.text === 'bind') { + return callee.expression; + } + return undefined; +} + +/** The operation name a FUNCTION VALUE expression denotes. */ +function functionValueName(valueExpr, depth) { + if (depth > MAX_CALLEE_RESOLUTION_DEPTH) return undefined; + const expr = stripValueWrappers(valueExpr); + if (!expr) return undefined; + if (ts.isPropertyAccessExpression(expr) && ts.isIdentifier(expr.name)) return expr.name.text; + if (ts.isCallExpression(expr)) { + const target = boundTarget(expr); + return target ? functionValueName(target, depth + 1) : undefined; + } + if (ts.isIdentifier(expr)) { + const init = constAliasInitializer(expr); + if (init === null) return expr.text; + return functionValueName(init, depth + 1) ?? expr.text; + } + return undefined; +} + +/** Does this binding name (identifier or pattern) bind `name`? */ +function bindingBinds(bindingName, name) { + if (!bindingName) return false; + if (ts.isIdentifier(bindingName)) return bindingName.text === name; + if (ts.isObjectBindingPattern(bindingName) || ts.isArrayBindingPattern(bindingName)) { + return bindingName.elements.some((el) => !ts.isOmittedExpression(el) && bindingBinds(el.name, name)); + } + return false; +} + +/** + * The initializer of the `const` the identifier `ident` reads, from the + * nearest enclosing scope that declares the name — or `null` when the nearest + * binding is not a plain `const = ` (see `guardedCriticalCallee`). + */ +function constAliasInitializer(ident) { + const name = ident.text; + for (let scope = ident.parent; scope; scope = scope.parent) { + if (ts.isFunctionLike(scope) && scope.parameters?.some((p) => bindingBinds(p.name, name))) return null; + if (ts.isCatchClause(scope) && scope.variableDeclaration && bindingBinds(scope.variableDeclaration.name, name)) { + return null; + } + if ( + (ts.isForStatement(scope) || ts.isForOfStatement(scope) || ts.isForInStatement(scope)) && + scope.initializer && + ts.isVariableDeclarationList(scope.initializer) && + scope.initializer.declarations.some((d) => bindingBinds(d.name, name)) + ) { + return null; + } + const statements = + ts.isBlock(scope) || ts.isSourceFile(scope) || ts.isModuleBlock(scope) || ts.isCaseClause(scope) || + ts.isDefaultClause(scope) + ? scope.statements + : undefined; + if (!statements) continue; + for (const st of statements) { + if ((ts.isFunctionDeclaration(st) || ts.isClassDeclaration(st)) && st.name?.text === name) return null; + if (!ts.isVariableStatement(st)) continue; + const list = st.declarationList; + const decl = list.declarations.find((d) => bindingBinds(d.name, name)); + if (!decl) continue; + if (!(list.flags & ts.NodeFlags.Const) || !ts.isIdentifier(decl.name) || !decl.initializer) return null; + return decl.initializer; + } + } + return null; +} + /** * The receiver names that make a `.(…)` call a LOG. * @@ -3342,10 +3498,8 @@ function analyzeSourceFile(sf, relPath, findings, seams, options = {}) { const collectGuardedCalls = (tryBlock) => { const guarded = []; const inspect = (child) => { - const name = calleeName(child); - if (name && DURABILITY_CRITICAL_CALLEES.has(name)) { - guarded.push({ callee: name, line: lineOf(child) }); - } + const name = guardedCriticalCallee(child); + if (name) guarded.push({ callee: name, line: lineOf(child) }); }; const walk = (n) => { n.forEachChild((child) => { @@ -4383,6 +4537,11 @@ const SELF_TEST_BATTERIES = Object.freeze({ 'summary limb: a counter-guarded if INSIDE the catch stays the catch rule\'s finding': 1, 'summary limb: a counter-guarded branch that logs nothing is not a report': 1, 'passes: a propagating catch is still counted as a seam (not made invisible)': 1, + 'flags: #22985 — `sync.call(engine, name)` through a const alias is the critical call it invokes': 1, + 'passes: #22985 — the same alias shape through a cast, logging error, is a seam and loud': 1, + 'flags: #22985 — `.apply(recv, args)` and `.bind(recv)(…)` invoke their target too': 1, + 'passes: #22985 — a bare `.bind(recv)` invokes nothing, so it guards nothing': 1, + 'passes: #22985 — a shadowing parameter or a `let` binding is not resolved as an alias': 1, }), // Partition 2 — the read-seam invention rule's table, driven by // `selfTestReadSeams()`. @@ -4454,7 +4613,7 @@ const SELF_TEST_BATTERIES = Object.freeze({ // added to the roster with no size pin at all: the lookup below reads // `undefined` and the comparison fails loudly. const SELF_TEST_BATTERY_FLOOR = Object.freeze({ - selfTest: 63, + selfTest: 68, selfTestReadSeams: 57, }); @@ -4463,7 +4622,7 @@ const SELF_TEST_BATTERY_FLOOR = Object.freeze({ // `selfTestReadSeams`'s partition being deleted from the roster wholesale — the // deleted partition's own size pin is not evaluated by anyone once its entry // stops reaching it. This is the one assertion that survives that deletion. -const SELF_TEST_BATTERY_TOTAL_FLOOR = 120; +const SELF_TEST_BATTERY_TOTAL_FLOOR = 125; /** * The floor for ONE partition of the roster, run from that partition's own @@ -5475,6 +5634,88 @@ function selfTest() { expectViolation: false, expectSeams: 1, }, + // ── #22985: the guarded side reads what `.call` / `.apply` / `.bind` INVOKE ── + // + // The live shape, verbatim in structure: an optional operation probed + // into a local `const` and called with the engine as its receiver. The + // plain reading saw `call`, so neither catch below was a seam at all. + { + name: 'flags: #22985 — `sync.call(engine, name)` through a const alias is the critical call it invokes', + code: ` + class P { async f(ctx: any, engine: any, objects: any[]) { + const sync = engine.syncObjectSchema; + if (typeof sync !== 'function') return; + for (const obj of objects) { + try { await sync.call(engine, obj.name); } + catch (err) { ctx.logger.warn('could not provision ' + obj.name); } + } + } }`, + expectViolation: true, + expectKinds: ['quiet-log'], + expectSeams: 1, + }, + { + // The same seam DISCOVERED and judged loud — the green direction is a + // seam count, not an absence, so it cannot pass by matching nothing. + name: 'passes: #22985 — the same alias shape through a cast, logging error, is a seam and loud', + code: ` + class P { async f(ctx: any, engine: any, obj: any) { + const sync = (engine as unknown as { syncObjectSchema?: (n: string) => Promise }).syncObjectSchema; + if (typeof sync !== 'function') return; + try { await sync.call(engine, obj.name); } + catch (err) { ctx.logger.error('storage NOT created; the boot looks healthy; fix: os migrate apply'); } + } }`, + expectViolation: false, + expectSeams: 1, + }, + { + name: 'flags: #22985 — `.apply(recv, args)` and `.bind(recv)(…)` invoke their target too', + code: ` + class P { async f(ctx: any, engine: any, obj: any) { + try { await engine.syncObjectSchema.apply(engine, [obj.name]); } + catch (err) { ctx.logger.warn('apply'); } + const bound = engine.syncObjectSchema.bind(engine); + try { await bound(obj.name); } + catch (err) { ctx.logger.warn('bound alias'); } + try { await engine.syncObjectSchema.bind(engine)(obj.name); } + catch (err) { ctx.logger.warn('bound inline'); } + } }`, + expectViolation: true, + expectCount: 3, + expectSeams: 3, + }, + { + // MUST NOT LIGHT: binding a function runs nothing. + name: 'passes: #22985 — a bare `.bind(recv)` invokes nothing, so it guards nothing', + code: ` + class P { f(ctx: any, engine: any) { + try { this.sync = engine.syncObjectSchema.bind(engine); } + catch (err) { ctx.logger.warn('bind failed'); } + } }`, + expectViolation: false, + expectSeams: 0, + }, + { + // MUST NOT LIGHT: the nearest binding of the name is a PARAMETER, + // which shadows the outer alias; and a let-binding is not an alias, + // because it can be reassigned after it is read. + name: 'passes: #22985 — a shadowing parameter or a `let` binding is not resolved as an alias', + code: ` + const sync = engine.syncObjectSchema; + class P { + async f(ctx: any, sync: any) { + try { await sync.call(null, 't'); } + catch (err) { ctx.logger.warn('parameter'); } + } + async g(ctx: any, engine: any) { + let run = engine.syncObjectSchema; + try { await run.call(engine, 't'); } + catch (err) { ctx.logger.warn('let'); } + } + }`, + expectViolation: false, + expectSeams: 0, + }, ]; // The ledger this entry's partition of the floor is evaluated against From d5686f98d8f9b2c052a2c10fab66b9f98cb1ca14 Mon Sep 17 00:00:00 2001 From: Claude Date: Mon, 12 Oct 2026 11:51:37 +0000 Subject: [PATCH 2/6] durability: a refused syncObjectSchema logs error with consequence and fix; the migrate-plan catch is declared as delivering - service-messaging provisionSystemTables: one `error` per refused object per boot, consequence + fix, the refusal in meta (mirrors plugin-audit's line). - service-datasource connect: one `error` per refused bound object per connect, spelled `(logger.error ?? logger.warn).call(...)` against the warn-required sink contract. - metadata-protocol ensureObjectStorage: `console.error` with consequence + fix after a publish that already answered success. - cli measureComposedCoverage: not a durability seam (deferred DDL); its catch delivers each refusal into the returned plan notes through `failures.set`, declared in FAILURE_PROPAGATION_SITES. check:durability-log-level: 51 seams, all loud, rethrowing or propagating. Claude-Session: https://claude.ai/code/session_01CeRCvvvjxbxu2iYJAc5Cce Co-authored-by: Claude --- ...otocol.object-storage-sync-refusal.test.ts | 237 ++++++++++++++++++ packages/metadata-protocol/src/protocol.ts | 22 +- ...source-connect-object-sync-refusal.test.ts | 143 +++++++++++ .../src/datasource-connection-service.ts | 48 +++- .../src/messaging-service-plugin.test.ts | 84 +++++++ .../src/messaging-service-plugin.ts | 64 ++++- ...check-durability-degradation-log-level.mjs | 15 ++ 7 files changed, 608 insertions(+), 5 deletions(-) create mode 100644 packages/metadata-protocol/src/protocol.object-storage-sync-refusal.test.ts create mode 100644 packages/services/service-datasource/src/__tests__/datasource-connect-object-sync-refusal.test.ts diff --git a/packages/metadata-protocol/src/protocol.object-storage-sync-refusal.test.ts b/packages/metadata-protocol/src/protocol.object-storage-sync-refusal.test.ts new file mode 100644 index 00000000000..e0f46b6845e --- /dev/null +++ b/packages/metadata-protocol/src/protocol.object-storage-sync-refusal.test.ts @@ -0,0 +1,237 @@ +// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license. +// +// [#22985] A publish whose object-storage sync is REFUSED is reported at +// `error`, once, with its consequence and its fix — and the publish is not +// failed. +// +// `ensureObjectStorage` runs after the publish has already been written and +// registered, so when the driver refuses its `syncObjectSchema` the publish +// still answers success and the object is served with no table behind it. +// From the outside nothing looks wrong, which is the class AGENTS.md +// "Degradation log levels" sends to `error`. The wording is not pinned: the +// pins hold the level, the count, the named object, the named remedy and the +// driver's refusal as its own argument — and the "looks healthy" half, as the +// publish verdict the caller reads. +// +// The stub engine is the one `protocol.publish-side-effects-canonical-type.test.ts` +// drives the same publish path with, plus a set of object names whose schema +// sync the driver refuses. + +import { afterEach, describe, expect, it, vi } from 'vitest'; +import { assertEngineDeleteDispatch, assertEngineUpdateDispatch, assertEngineFindOnePredicate } from '@objectstack/metadata-core'; +import { ObjectStackProtocolImplementation } from './protocol.js'; + +interface Row { + id: string; + type: string; + name: string; + organization_id: string | null; + package_id: string | null; + state: string; + metadata: string; + checksum?: string; + version?: number; +} + +interface HistoryRow { + id: string; + type: string; + name: string; + version: number; + organization_id: string | null; + operation_type: string; + recorded_at: string; +} + +/** ADR-0048 overlay key — (type, name, org, state, package_id). */ +const keyOf = (w: Record) => + `${w.type}|${w.name}|${w.organization_id ?? '__env__'}|${w.state ?? 'active'}|${w.package_id ?? '__nopkg__'}`; + +/** Top-level eq + `$or` + explicit-NULL, the subset these paths emit. */ +function matchesWhere(r: Row, where: Record): boolean { + for (const [k, v] of Object.entries(where)) { + if (k === '$or') { + const clauses = v as Array>; + if (!clauses.some((c) => matchesWhere(r, c))) return false; + continue; + } + if (v === undefined) continue; + if ((r as unknown as Record)[k] !== v) return false; + } + return true; +} + +function makeStubEngine(refused: ReadonlySet) { + const rows = new Map(); + const historyRows: HistoryRow[] = []; + let nextId = 0; + /** + * The observation channel this file is about: every name handed to the + * driver's schema sync, in call order. `ensureObjectStorage` is the only + * caller of it on a publish, so this doubles as "did Phase 2's DDL step + * run, and under which spelling did it decide to". + */ + const syncedObjects: string[] = []; + + const findRow = (w: Record): { key: string; row: Row } | null => { + if (w.id !== undefined) { + for (const [k, r] of rows) if (r.id === w.id) return { key: k, row: r }; + return null; + } + if (w.package_id !== undefined) { + const k = keyOf(w); + const r = rows.get(k); + if (r) return { key: k, row: r }; + } + for (const [k, r] of rows) if (matchesWhere(r, w)) return { key: k, row: r }; + return null; + }; + + const engine: any = { + async findOne(table: string, opts: { where: Record }) { + assertEngineFindOnePredicate(table, opts); + if (table === 'sys_metadata_history') { + return historyRows.find((h) => { + const w = opts.where; + if (w.type !== undefined && h.type !== w.type) return false; + if (w.name !== undefined && h.name !== w.name) return false; + if (w.version !== undefined && h.version !== w.version) return false; + if (w.organization_id !== undefined && h.organization_id !== w.organization_id) return false; + return true; + }) ?? null; + } + if (table === 'sys_metadata_commit') return null; + return findRow(opts.where)?.row ?? null; + }, + async find(table: string, opts?: { where?: Record }) { + if (table === 'sys_metadata_history') return historyRows; + if (table !== 'sys_metadata') return []; + return Array.from(rows.values()).filter((r) => matchesWhere(r, opts?.where ?? {})); + }, + async insert(table: string, data: Record) { + if (table === 'sys_metadata_audit') return { id: 'audit_skip' }; + if (table === 'sys_metadata_history') { + nextId += 1; + const h = { ...(data as unknown as HistoryRow), id: `h_${nextId}` }; + historyRows.push(h); + return { id: h.id }; + } + if (table !== 'sys_metadata') return { id: 'side_effect_skip' }; + nextId += 1; + const row = { ...(data as unknown as Row), id: `r_${nextId}` }; + rows.set(keyOf(data), row); + return { id: row.id }; + }, + async update(_t: string, data: Record, opts: { where: Record }) { + assertEngineUpdateDispatch(data, opts); + const found = findRow(opts.where); + if (!found) return { id: null }; + const merged = { ...found.row, ...(data as unknown as Row) }; + rows.delete(found.key); + rows.set(keyOf(merged), merged); + return { id: found.row.id }; + }, + async delete(_t: string, opts: { where: Record }) { + assertEngineDeleteDispatch(opts); + const found = findRow(opts.where); + if (!found) return { deleted: 0 }; + rows.delete(found.key); + return { deleted: 1 }; + }, + async transaction(cb: (ctx: unknown, info: { owned: boolean }) => Promise): Promise { + return cb(undefined, { owned: true }); + }, + syncObjectSchema: vi.fn(async (name: string) => { + if (refused.has(name)) throw new Error(`there is already an index named ${name}`); + syncedObjects.push(name); + return true; + }), + registry: { + registerItem: () => {}, + registerObject: () => {}, + listItems: () => [], + getItem: () => undefined, + getObject: () => undefined, + getPackage: () => undefined, + getArtifactItem: () => undefined, + }, + }; + return { engine, rows, syncedObjects }; +} + +function makeProtocol(refused: ReadonlySet = new Set()) { + const { engine, syncedObjects } = makeStubEngine(refused); + const protocol = new ObjectStackProtocolImplementation(engine, () => new Map(), 'env_prod') as any; + return { protocol, syncedObjects }; +} + +const PKG = 'app.demo'; + +/** An object body that clears the authoring gates the publish path runs first. */ +const objectBody = (name: string) => ({ + name, + label: 'Ticket', + sharingModel: 'private', + fields: { title: { type: 'text', label: 'Title' } }, +}); + +/** The fragment an operator greps for; the rest of the wording is not pinned. */ +const HEADLINE = 'its storage was NOT created or altered'; + +afterEach(() => { + vi.restoreAllMocks(); +}); + +function spyConsole() { + return { + error: vi.spyOn(console, 'error').mockImplementation(() => {}), + warn: vi.spyOn(console, 'warn').mockImplementation(() => {}), + }; +} + +async function publish(protocol: any, name: string) { + await protocol.saveMetaItem({ + type: 'object', name, item: objectBody(name), packageId: PKG, mode: 'draft', + }); + return protocol.publishMetaItem({ type: 'object', name }); +} + +describe('[#22985] a refused object-storage sync on publish is an error, once', () => { + it('the publish still answers success, and exactly one error line names the object, the remedy and the refusal', async () => { + const spy = spyConsole(); + const { protocol, syncedObjects } = makeProtocol(new Set(['ticket'])); + + const res = await publish(protocol, 'ticket'); + + // The half that makes it the durability class: the caller is told the + // publish succeeded, while the storage it was published for is absent. + expect(res.success).toBe(true); + expect(syncedObjects).toEqual([]); + + const reports = spy.error.mock.calls.filter((args) => String(args[0]).includes(HEADLINE)); + expect(reports).toHaveLength(1); + const [message, refusal] = reports[0]; + expect(message).toContain("object 'ticket'"); + // ② the fix, by its named subjects. + expect(message).toContain('publish the object again'); + expect(message).toContain('restart'); + // One line: the first line carries both halves, and the driver's + // refusal rides as its own argument rather than inside it. + expect(message).not.toContain('\n'); + expect(message).not.toContain('there is already an index'); + expect(refusal).toBe('there is already an index named ticket'); + // …and it is not ALSO reported at a quieter level. + expect(spy.warn.mock.calls.filter((args) => /table sync failed|ticket/.test(String(args[0])))).toEqual([]); + }); + + it('CONTROL: a publish whose sync succeeds reports nothing at error', async () => { + const spy = spyConsole(); + const { protocol, syncedObjects } = makeProtocol(); + + const res = await publish(protocol, 'ticket'); + + expect(res.success).toBe(true); + expect(syncedObjects).toEqual(['ticket']); + expect(spy.error.mock.calls.filter((args) => String(args[0]).includes(HEADLINE))).toEqual([]); + }); +}); diff --git a/packages/metadata-protocol/src/protocol.ts b/packages/metadata-protocol/src/protocol.ts index 85a9bc26d6a..6db5944f593 100644 --- a/packages/metadata-protocol/src/protocol.ts +++ b/packages/metadata-protocol/src/protocol.ts @@ -19387,7 +19387,10 @@ export class ObjectStackProtocolImplementation implements * this, inserting into a freshly-published object fails with "no such * table" (surfaced as `object_not_found`) until the next restart. * Best-effort + non-fatal: drivers without DDL (or read-only datasources) - * simply no-op, and a sync failure must not abort the publish. + * simply no-op, and a sync failure must not abort the publish. Non-fatal is + * not quiet: a refused sync is reported at `error` with its consequence + * and fix (#22985), because the publish it follows has already answered + * success. */ private async ensureObjectStorage(type: string, name: string): Promise { // [#8862] The `&& type !== 'objects'` limb is GONE. Both call sites @@ -19403,7 +19406,22 @@ export class ObjectStackProtocolImplementation implements try { await this.engine.syncObjectSchema(name); } catch (err: any) { - console.warn(`[Protocol] table sync failed for object '${name}': ${err?.message ?? err}`); + // [#22985] `error`, not `warn`, by the one question AGENTS.md + // "Degradation log levels" turns this on: the publish still + // answers success and the object is registered and served, while + // the storage it was published for does not exist. Said once per + // publish of the object, never per write; the publish is + // deliberately NOT failed (see the docblock). The driver's refusal + // is a separate argument, so a multi-line driver error cannot split + // the line that carries the level. + console.error( + `[Protocol] object '${name}' was published but its storage was NOT created or altered — its schema ` + + 'sync was refused. The publish answered success and the object is registered and served, so it ' + + 'looks usable while its writes fail (or drop the columns this publish added) until the sync runs. ' + + "Fix: resolve the driver's refusal (logged after this line), then publish the object again, which " + + 're-runs this sync, or restart, since the boot syncs every registered object\'s storage.', + err?.message ?? err, + ); } } diff --git a/packages/services/service-datasource/src/__tests__/datasource-connect-object-sync-refusal.test.ts b/packages/services/service-datasource/src/__tests__/datasource-connect-object-sync-refusal.test.ts new file mode 100644 index 00000000000..81deeb3e7cd --- /dev/null +++ b/packages/services/service-datasource/src/__tests__/datasource-connect-object-sync-refusal.test.ts @@ -0,0 +1,143 @@ +// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license. + +/** + * [#22985] A bound object's schema sync refused at connect is a DURABILITY + * degradation, so it is reported at `error` — once per object per connect — + * and the connect is not failed. + * + * `connect()` re-drives `syncObjectSchema` for every object bound to the + * datasource it just connected, because the boot's own schema sync ran before + * this driver existed. When that call throws, the datasource still answers + * `connected` and the object stays registered and served with no working + * storage — a managed object has no table, a federated one is not bound to its + * remote table. Nothing about the connect looks wrong from the outside, which + * is the class AGENTS.md "Degradation log levels" sends to `error`. + * + * The wording is not pinned: the pins hold the level, the count, the named + * object and datasource, the named remedy and the driver's refusal in meta — + * and the "looks healthy" half, as the connect verdict an operator reads. + */ + +import { describe, it, expect } from 'vitest'; +import { + DatasourceConnectionService, + type ConnectableDatasource, + type ConnectionEngineLike, +} from '../datasource-connection-service.js'; +import type { IDatasourceDriverFactory } from '../contracts/datasource-driver-factory.js'; +import type { IDataDriver } from '@objectstack/spec/contracts'; + +/** An engine whose schema sync refuses the objects in `refused` and syncs the rest. */ +function engineRefusing(refused: Set) { + const drivers = new Map(); + const synced: string[] = []; + const engine: ConnectionEngineLike = { + registerDriver: (driver) => { + if (!drivers.has(driver.name)) drivers.set(driver.name, driver); + }, + registerDatasourceDef: () => {}, + getDriverByName: (name) => drivers.get(name) as IDataDriver | undefined, + syncObjectSchema: async (name) => { + if (refused.has(name)) throw new Error(`there is already an index named ${name}`); + synced.push(name); + }, + }; + return { engine, synced }; +} + +function factory(): IDatasourceDriverFactory { + return { + supports: () => true, + create: async () => ({ driver: { name: 'com.fake.driver' }, connect: async () => {} }), + }; +} + +type ErrorCall = { message: string; meta: unknown }; + +/** A sink recording both channels; `withError: false` is the contract's `{ warn }`-only sink. */ +function sink(withError = true) { + const warn: string[] = []; + const error: ErrorCall[] = []; + const logger = { + warn: (message: string) => { warn.push(message); }, + info: () => {}, + ...(withError ? { error: (message: string, meta?: unknown) => { error.push({ message, meta }); } } : {}), + }; + return { logger, warn, error }; +} + +const reporting: ConnectableDatasource = { + name: 'reporting', + driver: 'sqlite', + schemaMode: 'managed', + config: {}, +}; +const OBJECTS = [ + { name: 'report_row', datasource: 'reporting' }, + { name: 'report_rollup', datasource: 'reporting' }, +]; + +async function connect(refused: Set, withError = true) { + const { engine, synced } = engineRefusing(refused); + const log = sink(withError); + const service = new DatasourceConnectionService({ + factory: () => factory(), + engine: () => engine, + logger: log.logger, + }); + const results = await service.connectDeclared({ datasources: [reporting], objects: OBJECTS }); + return { results, synced, service, log }; +} + +describe('DatasourceConnectionService — a refused bound-object sync is an error, once per object (#22985)', () => { + it('a refused sync logs exactly one error line naming the object, the datasource, the remedy and the refusal', async () => { + const { results, synced, service, log } = await connect(new Set(['report_row'])); + + // The half that makes it the durability class: from the outside the + // connect looks healthy — the verdict an operator and the admin list read. + expect(results).toEqual([{ name: 'reporting', status: 'connected' }]); + expect(service.getConnectionState('reporting')?.status).toBe('connected'); + + expect(log.error).toHaveLength(1); + const [line] = log.error; + expect(line.message).toContain("object 'report_row'"); + expect(line.message).toContain("datasource 'reporting'"); + // ② the fix, by its named subject. + expect(line.message).toContain('restart'); + // One line: the first line carries both halves. + expect(line.message).not.toContain('\n'); + // The driver's refusal travels in meta, never interpolated into the line. + expect(line.message).not.toContain('there is already an index'); + expect(line.meta).toEqual({ + datasource: 'reporting', + object: 'report_row', + error: 'there is already an index named report_row', + }); + // …and it is not ALSO reported at a quieter level. + expect(log.warn).toEqual([]); + // The connect is not failed: the other bound object still synced. + expect(synced).toEqual(['report_rollup']); + }); + + it('every refused object gets its own line', async () => { + const { log } = await connect(new Set(['report_row', 'report_rollup'])); + + expect(log.error.map((c) => (c.meta as { object: string }).object)).toEqual(['report_row', 'report_rollup']); + }); + + it('a `{ warn }`-only sink still prints the line — the fallback, never an optional `error?.()`', async () => { + const { log } = await connect(new Set(['report_row']), false); + + expect(log.warn).toHaveLength(1); + expect(log.warn[0]).toContain("object 'report_row'"); + }); + + it('CONTROL: a clean connect logs no error and syncs every bound object', async () => { + const { results, synced, log } = await connect(new Set()); + + expect(results).toEqual([{ name: 'reporting', status: 'connected' }]); + expect(log.error).toEqual([]); + expect(log.warn).toEqual([]); + expect(synced).toEqual(['report_row', 'report_rollup']); + }); +}); diff --git a/packages/services/service-datasource/src/datasource-connection-service.ts b/packages/services/service-datasource/src/datasource-connection-service.ts index 7e50dc8f65e..1964c9bd16c 100644 --- a/packages/services/service-datasource/src/datasource-connection-service.ts +++ b/packages/services/service-datasource/src/datasource-connection-service.ts @@ -652,11 +652,29 @@ export class DatasourceConnectionService { // equals by the fail-fast policy below (both mean "no fallback // driver"); they were unequal only here. `syncObjectSchema` is // idempotent, so an object in both lists is harmless. + // + // [#22985] A refusal here is reported at `error`, once per object per + // connect: see {@link objectStorageSyncFailureLine}. Both kinds of bound + // object end up registered and served with no working storage while the + // datasource answers `connected`, which is the durability class AGENTS.md + // "Degradation log levels" sends to `error`. The connect is deliberately + // NOT failed: one object's DDL refusal must not take every other object + // on the datasource down with it. for (const objectName of [...(opts.objects ?? []), ...(opts.mappedObjects ?? [])]) { try { await engine.syncObjectSchema?.(objectName); } catch (err) { - this.logger?.warn?.(`datasource '${name}': syncObjectSchema('${objectName}') failed: ${errMsg(err)}`); + // `warn` is the contract's required channel and `error` its optional + // one, so the fallback is spelled out: never `error?.(…)`, which + // prints nothing against a sink that has no `error`. + const logger = this.logger; + if (logger) { + (logger.error ?? logger.warn).call(logger, objectStorageSyncFailureLine(name, objectName), { + datasource: name, + object: objectName, + error: errMsg(err), + }); + } } } @@ -1006,3 +1024,31 @@ function toSpec(record: ConnectableDatasource): DatasourceConnectionSpec { function errMsg(err: unknown): string { return err instanceof Error ? err.message : String(err); } + +/** + * [#22985] The ONE line `connect()` prints when a bound object's + * `syncObjectSchema` throws — at `error`, carrying both halves AGENTS.md + * "Degradation log levels" asks of a durability degradation: ① the + * consequence, and that the deployment keeps looking healthy; ② the fix. + * + * Both kinds of bound object are covered, because the catch cannot tell them + * apart and both land in the same place: a managed object's DDL never ran, so + * its table/columns do not exist, and a federated object's binding to its + * remote table was never installed, so its reads resolve to a table named + * after the object. Either way the object stays registered and served while + * this datasource answers `connected`. The remedy is the one the code path + * gives: this loop runs inside `connectDeclared`, which every boot calls, so a + * restart re-runs the sync once the refusal is resolved. `os migrate` is not + * named, because it plans only the primary datasource and its telemetry + * sibling, never a datasource an app declares. + */ +function objectStorageSyncFailureLine(datasource: string, objectName: string): string { + return ( + `datasource '${datasource}': object '${objectName}' has NO working storage here — its schema sync was refused, ` + + 'so a managed object\'s table/columns were not created or altered, and a federated object is not bound to its ' + + `remote table. The datasource still reports connected and '${objectName}' stays registered and served, so reads ` + + 'and writes against it fail, or hit a table named after the object, while the deployment looks healthy. ' + + "Fix: resolve the driver's refusal (in this record's meta), then restart: every boot re-runs this sync when it " + + 'connects the declared datasource.' + ); +} diff --git a/packages/services/service-messaging/src/messaging-service-plugin.test.ts b/packages/services/service-messaging/src/messaging-service-plugin.test.ts index 4b340e3629a..285d2fdcaad 100644 --- a/packages/services/service-messaging/src/messaging-service-plugin.test.ts +++ b/packages/services/service-messaging/src/messaging-service-plugin.test.ts @@ -337,3 +337,87 @@ describe('MessagingServicePlugin — boot provisioning honours skipSchemaSync (# } }); }); + +/** + * [#22985] A failed boot provision is a DURABILITY degradation, so it is + * reported at `error` — once per object, never per write — and the boot is not + * failed. + * + * When an object's DDL throws, the boot still completes and the deployment + * serves as healthy while the table does not exist; the pipeline tables are + * written as a side effect of actions (an approval step, an @mention) that + * complete without them. AGENTS.md "Degradation log levels" sends that class to + * `error`, with the consequence and the fix in the first line. The wording is + * not pinned: the pins hold the level, the count, the named object, the named + * remedy command and the driver's refusal in meta. + */ +describe('MessagingServicePlugin — a failed provision is an error, once per object (#22985)', () => { + const OBJECTS = [ + 'sys_notification', 'sys_inbox_message', 'sys_notification_receipt', 'sys_notification_delivery', + 'sys_notification_preference', 'sys_notification_subscription', 'sys_notification_template', 'sys_http_delivery', + ]; + + /** Every DDL succeeds except the named object's, which the driver refuses. */ + async function boot(refused?: string) { + const synced: string[] = []; + const engine = { + async syncObjectSchema(name: string) { + if (name === refused) throw new Error(`there is already an index named ${name}`); + synced.push(name); + }, + }; + const services = new Map([['data', engine], ['manifest', { register() {} }]]); + const readyHooks: Array<() => Promise | void> = []; + const logs = { + warn: [] as string[], + error: [] as Array<{ message: string; error: unknown; meta: Record | undefined }>, + }; + const logger = { + info() {}, + warn(msg: string) { logs.warn.push(String(msg)); }, + error(msg: string, error?: unknown, meta?: Record) { + logs.error.push({ message: String(msg), error, meta }); + }, + debug() {}, + child() { return logger; }, + }; + const ctx = { + logger, + getService(name: string) { return services.get(name); }, + registerService(name: string, svc: unknown) { services.set(name, svc); }, + hook(event: string, fn: () => Promise | void) { + if (event === 'kernel:ready') readyHooks.push(fn); + }, + } as any; + await new MessagingServicePlugin({ reliableDelivery: false }).init(ctx); + // The boot is NOT failed: kernel:ready resolves. + await expect((async () => { for (const fn of readyHooks) await fn(); })()).resolves.toBeUndefined(); + return { logs, synced }; + } + + it.each(OBJECTS)('a refused DDL for %s logs exactly one error line naming it, the remedy and the refusal', async (name) => { + const { logs, synced } = await boot(name); + + expect(logs.error).toHaveLength(1); + const [line] = logs.error; + expect(line.message).toContain(name); + // ② the fix, by its named subject: the command measured to create it. + expect(line.message).toContain('os migrate apply'); + // One line: the first line carries both halves. + expect(line.message).not.toContain('\n'); + // The driver's refusal travels in meta, never interpolated into the line. + expect(line.meta).toEqual({ object: name, error: `there is already an index named ${name}` }); + // …and it is not ALSO reported at a quieter level. + expect(logs.warn.filter((m) => m.includes('could not provision'))).toEqual([]); + // The other seven objects still provisioned. + expect(synced).toEqual(OBJECTS.filter((o) => o !== name)); + }); + + it('CONTROL: a clean provision logs no error at all', async () => { + const { logs, synced } = await boot(); + + expect(logs.error).toEqual([]); + expect(logs.warn.filter((m) => m.includes('could not provision'))).toEqual([]); + expect(synced).toEqual(OBJECTS); + }); +}); diff --git a/packages/services/service-messaging/src/messaging-service-plugin.ts b/packages/services/service-messaging/src/messaging-service-plugin.ts index b27e4d79669..83e111fe594 100644 --- a/packages/services/service-messaging/src/messaging-service-plugin.ts +++ b/packages/services/service-messaging/src/messaging-service-plugin.ts @@ -44,6 +44,48 @@ function bootSchemaSyncSkipped(engine: IDataEngine): boolean { return (engine as unknown as { skipSchemaSync?: unknown }).skipSchemaSync === true; } +/** + * What an operator loses while `objectName`'s storage is missing, for + * {@link provisionFailureLine}. The four pipeline objects are written as a SIDE + * EFFECT of other actions — `emit()` writes the event, then the delivery outbox + * row, the inbox row and its receipt — and the callers that emit (an approval + * step, an @mention) catch a failed emit and complete anyway. So the loss there + * is invisible from the action that caused it. + */ +function lostWithoutStorage(objectName: string): string { + switch (objectName) { + case 'sys_notification': + case 'sys_notification_delivery': + case 'sys_inbox_message': + case 'sys_notification_receipt': + return ( + 'Notifications are written as a side effect of other actions, so an approval step or an @mention ' + + 'keeps completing while the notification rows it needs here cannot land.' + ); + default: + return 'Every write to it fails until it exists.'; + } +} + +/** + * The ONE line `provisionSystemTables` prints when an object's DDL throws — at + * `error`, carrying both halves AGENTS.md "Degradation log levels" asks of a + * durability degradation: ① the consequence, and that the deployment keeps + * looking healthy; ② the fix. Both remedies are measured: this provisioning + * runs on every boot that runs DDL, and `os migrate apply` creates all eight + * of these tables. + */ +function provisionFailureLine(objectName: string): string { + return ( + `[messaging] could not provision ${objectName} storage — its storage was NOT created. ` + + `${lostWithoutStorage(objectName)} The boot still completes and the deployment keeps looking healthy. ` + + "Fix: resolve the driver's refusal (in this record's meta), then restart, since this provisioning runs on " + + 'every boot, or run `os migrate apply`, which creates the missing storage (`os migrate plan` lists it as ' + + `\`create_table:${objectName}\`). If the boot log also carries \`Schema sync FAILED for object ` + + `'${objectName}'\`, that is the same refusal.` + ); +} + export interface MessagingServicePluginOptions { /** * Register the always-on `inbox` channel during init (default `true`). @@ -441,6 +483,13 @@ export class MessagingServicePlugin implements Plugin { * start. Idempotent (the driver only creates a table when absent), so it is * safe on every boot; per-object failures are isolated. * + * [#22985] A failed provision is reported at `error`, once per object + * ({@link provisionFailureLine}): the boot completes and the deployment + * looks healthy while the table does not exist, and the pipeline tables + * are written as a side effect of actions that complete without them. That + * is the durability class AGENTS.md "Degradation log levels" sends to + * `error`; `check:durability-log-level` holds it there. + * * [#22984] It is boot-time DDL, so it honours `skipSchemaSync` / * `OS_SKIP_SCHEMA_SYNC=1` the way the engine's own boot sync does: a * deployment that declared its DDL managed out-of-band ("Use after running @@ -486,10 +535,21 @@ export class MessagingServicePlugin implements Plugin { const sync = engine.syncObjectSchema; if (typeof sync !== 'function') return; for (const obj of objects) { + const name = (obj as { name: string }).name; try { - await sync.call(engine, (obj as { name: string }).name); + await sync.call(engine, name); } catch (err) { - ctx.logger.warn(`[messaging] could not provision ${(obj as { name: string }).name} storage — ${(err as Error)?.message ?? err}`); + // A DURABILITY degradation, so `error` (AGENTS.md "Degradation + // log levels"): the boot completes and the deployment looks + // healthy while this table does not exist. Once per object per + // boot, never per write; the boot is deliberately NOT failed. + // The driver's refusal goes in meta, not in the message: a + // multi-line driver error would split the record, and only its + // first fragment would carry the level. + ctx.logger.error(provisionFailureLine(name), undefined, { + object: name, + error: (err as Error)?.message ?? String(err), + }); } } } diff --git a/scripts/check-durability-degradation-log-level.mjs b/scripts/check-durability-degradation-log-level.mjs index f25dc3e2e01..62abfc5e3a2 100644 --- a/scripts/check-durability-degradation-log-level.mjs +++ b/scripts/check-durability-degradation-log-level.mjs @@ -581,6 +581,21 @@ const FAILURE_PROPAGATION_SITES = new Map([ + 'baseline in #4754).', }, ], + [ + 'packages/cli/src/utils/schema-migration-plugins.ts::measureComposedCoverage', + { + callees: [['failures.set', 'effect']], + why: + "`failures` is this function's per-refusal outcome recorder: every entry becomes one note of the " + + 'RETURNED report (`The driver REFUSED schema registration for N object(s) (); those ' + + 'objects are NOT in the plan below.`), beside `coverage.reasons.failed`, and `os migrate plan` / ' + + '`apply` print those notes and mark the plan PARTIAL. So the caller is told, per refusal, which ' + + 'objects the plan did not examine. It is not a durability seam at all: this pass runs only on a ' + + 'boot that DEFERRED its DDL, so the `syncObjectSchema` it guards registers metadata in memory and ' + + 'writes nothing. Declared here because the vocabulary is a name and the name reaches this catch ' + + "(#22985); `schema-migration-plugins.test.ts` pins the refusal note and the failed count.", + }, + ], ]); // ───────────────────────────────────────────────────────────────────────────── From 1d519f3749455b47f46519af756bd1184902d073 Mon Sep 17 00:00:00 2001 From: Claude Date: Mon, 12 Oct 2026 11:57:46 +0000 Subject: [PATCH 3/6] test(metadata-protocol): the publish CONTROL asserts no console.error at all Claude-Session: https://claude.ai/code/session_01CeRCvvvjxbxu2iYJAc5Cce Co-authored-by: Claude --- .../src/protocol.object-storage-sync-refusal.test.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/metadata-protocol/src/protocol.object-storage-sync-refusal.test.ts b/packages/metadata-protocol/src/protocol.object-storage-sync-refusal.test.ts index e0f46b6845e..cb35b2af90e 100644 --- a/packages/metadata-protocol/src/protocol.object-storage-sync-refusal.test.ts +++ b/packages/metadata-protocol/src/protocol.object-storage-sync-refusal.test.ts @@ -232,6 +232,6 @@ describe('[#22985] a refused object-storage sync on publish is an error, once', expect(res.success).toBe(true); expect(syncedObjects).toEqual(['ticket']); - expect(spy.error.mock.calls.filter((args) => String(args[0]).includes(HEADLINE))).toEqual([]); + expect(spy.error).not.toHaveBeenCalled(); }); }); From 8a59d7e0a783bb712d3615d3717fdb3b3013eb8f Mon Sep 17 00:00:00 2001 From: Claude Date: Mon, 12 Oct 2026 12:06:05 +0000 Subject: [PATCH 4/6] test(metadata-protocol): the commit-durability stub engine declares syncObjectSchema `HostEngine` declares it and an object publish calls it. Without it the publish's storage sync threw a TypeError, which the protocol now reports at `error`, and the file's "logs nothing" control read that as a commit-store line. Claude-Session: https://claude.ai/code/session_01CeRCvvvjxbxu2iYJAc5Cce Co-authored-by: Claude --- .../src/protocol.record-package-commit-durability.test.ts | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/packages/metadata-protocol/src/protocol.record-package-commit-durability.test.ts b/packages/metadata-protocol/src/protocol.record-package-commit-durability.test.ts index 0de0b947d71..c3e450c811e 100644 --- a/packages/metadata-protocol/src/protocol.record-package-commit-durability.test.ts +++ b/packages/metadata-protocol/src/protocol.record-package-commit-durability.test.ts @@ -173,6 +173,11 @@ function makeStubEngine() { async transaction(cb: (ctx: undefined, info: { owned: boolean }) => Promise): Promise { return cb(undefined, { owned: true }); }, + // [#22985] `HostEngine` declares it, and a publish of an object calls + // it. Without it the publish's storage sync threw a TypeError that the + // protocol now reports at `error` — which the "logs nothing" control + // below would read as a commit-store report. + async syncObjectSchema() {}, registry: { registerItem: () => {}, registerObject: () => {}, From 295b0e58615f52ef3b6da03a374e8831dec0e5b3 Mon Sep 17 00:00:00 2001 From: Claude Date: Mon, 12 Oct 2026 12:09:21 +0000 Subject: [PATCH 5/6] changeset: a refused syncObjectSchema is logged at error in service-messaging, service-datasource and metadata-protocol Claude-Session: https://claude.ai/code/session_01CeRCvvvjxbxu2iYJAc5Cce Co-authored-by: Claude --- .changeset/22985-schema-sync-refusal-error.md | 13 +++++++++++++ 1 file changed, 13 insertions(+) create mode 100644 .changeset/22985-schema-sync-refusal-error.md diff --git a/.changeset/22985-schema-sync-refusal-error.md b/.changeset/22985-schema-sync-refusal-error.md new file mode 100644 index 00000000000..ad34658afbb --- /dev/null +++ b/.changeset/22985-schema-sync-refusal-error.md @@ -0,0 +1,13 @@ +--- +'@objectstack/service-messaging': patch +'@objectstack/service-datasource': patch +'@objectstack/metadata-protocol': patch +--- + +fix: a refused on-demand schema sync (`syncObjectSchema`) is logged at `error`, naming what was not created and how to fix it (#22985) + +Three places create an object's storage after the boot's own schema sync has run. When the driver refused that DDL, each of them logged a `warn` and carried on, so the deployment looked healthy while a table did not exist. Each now logs one `error` line that says what was not created, that nothing else will look wrong, and what fixes it. The driver's refusal is kept out of the line itself. Nothing else changes: the boot, the connect and the publish still complete as before. + +- **`@objectstack/service-messaging`**: boot-time provisioning of the eight notification tables. A refused table logs `[messaging] could not provision storage — its storage was NOT created. …` at `error`, once per table per boot, with the refusal in the record's meta. The fix it names: resolve the refusal, then restart or run `os migrate apply`. This used to be a `warn`. Under `skipSchemaSync` / `OS_SKIP_SCHEMA_SYNC=1` the provisioning still issues no DDL, so this line cannot appear. +- **`@objectstack/service-datasource`**: connecting a declared datasource re-runs the schema sync of every object bound to it. A refused object logs `datasource '': object '' has NO working storage here — …` at `error`, once per object per connect, with the refusal in meta. On a logger that has no `error`, the same line is logged at `warn`. The fix it names: resolve the refusal, then restart. This used to be a `warn` reading `syncObjectSchema('') failed`. +- **`@objectstack/metadata-protocol`**: publishing an object whose storage sync is refused logs `[Protocol] object '' was published but its storage was NOT created or altered — …` with `console.error`. The driver's refusal is the second argument. The fix it names: resolve the refusal, then publish the object again or restart. The publish still answers success. This replaces the `console.warn` line `[Protocol] table sync failed for object '': …`, so a log search for that text now finds nothing. From d80c6d1244304d18602760cf12a57f1eaedfef95 Mon Sep 17 00:00:00 2001 From: Claude Date: Mon, 12 Oct 2026 12:38:48 +0000 Subject: [PATCH 6/6] test(metadata-protocol): pin the refused publish sync in the publish stub that is already ledgered; census copy learns syncObjectSchema The member-3 pin moves into protocol.publish-side-effects-canonical-type.test.ts, whose stub already carries the publish path and is already in the engine-double and limit ledgers, instead of a copied stub that both gates would have to learn. The stub's syncObjectSchema takes a set of refused names. measure-durability-swallow-family.mjs copies the gate vocabulary by value and self-tests the copy, so it gains syncObjectSchema with the gate. Claude-Session: https://claude.ai/code/session_01CeRCvvvjxbxu2iYJAc5Cce Co-authored-by: Claude --- ...otocol.object-storage-sync-refusal.test.ts | 237 ------------------ ...ublish-side-effects-canonical-type.test.ts | 85 ++++++- scripts/measure-durability-swallow-family.mjs | 1 + 3 files changed, 82 insertions(+), 241 deletions(-) delete mode 100644 packages/metadata-protocol/src/protocol.object-storage-sync-refusal.test.ts diff --git a/packages/metadata-protocol/src/protocol.object-storage-sync-refusal.test.ts b/packages/metadata-protocol/src/protocol.object-storage-sync-refusal.test.ts deleted file mode 100644 index cb35b2af90e..00000000000 --- a/packages/metadata-protocol/src/protocol.object-storage-sync-refusal.test.ts +++ /dev/null @@ -1,237 +0,0 @@ -// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license. -// -// [#22985] A publish whose object-storage sync is REFUSED is reported at -// `error`, once, with its consequence and its fix — and the publish is not -// failed. -// -// `ensureObjectStorage` runs after the publish has already been written and -// registered, so when the driver refuses its `syncObjectSchema` the publish -// still answers success and the object is served with no table behind it. -// From the outside nothing looks wrong, which is the class AGENTS.md -// "Degradation log levels" sends to `error`. The wording is not pinned: the -// pins hold the level, the count, the named object, the named remedy and the -// driver's refusal as its own argument — and the "looks healthy" half, as the -// publish verdict the caller reads. -// -// The stub engine is the one `protocol.publish-side-effects-canonical-type.test.ts` -// drives the same publish path with, plus a set of object names whose schema -// sync the driver refuses. - -import { afterEach, describe, expect, it, vi } from 'vitest'; -import { assertEngineDeleteDispatch, assertEngineUpdateDispatch, assertEngineFindOnePredicate } from '@objectstack/metadata-core'; -import { ObjectStackProtocolImplementation } from './protocol.js'; - -interface Row { - id: string; - type: string; - name: string; - organization_id: string | null; - package_id: string | null; - state: string; - metadata: string; - checksum?: string; - version?: number; -} - -interface HistoryRow { - id: string; - type: string; - name: string; - version: number; - organization_id: string | null; - operation_type: string; - recorded_at: string; -} - -/** ADR-0048 overlay key — (type, name, org, state, package_id). */ -const keyOf = (w: Record) => - `${w.type}|${w.name}|${w.organization_id ?? '__env__'}|${w.state ?? 'active'}|${w.package_id ?? '__nopkg__'}`; - -/** Top-level eq + `$or` + explicit-NULL, the subset these paths emit. */ -function matchesWhere(r: Row, where: Record): boolean { - for (const [k, v] of Object.entries(where)) { - if (k === '$or') { - const clauses = v as Array>; - if (!clauses.some((c) => matchesWhere(r, c))) return false; - continue; - } - if (v === undefined) continue; - if ((r as unknown as Record)[k] !== v) return false; - } - return true; -} - -function makeStubEngine(refused: ReadonlySet) { - const rows = new Map(); - const historyRows: HistoryRow[] = []; - let nextId = 0; - /** - * The observation channel this file is about: every name handed to the - * driver's schema sync, in call order. `ensureObjectStorage` is the only - * caller of it on a publish, so this doubles as "did Phase 2's DDL step - * run, and under which spelling did it decide to". - */ - const syncedObjects: string[] = []; - - const findRow = (w: Record): { key: string; row: Row } | null => { - if (w.id !== undefined) { - for (const [k, r] of rows) if (r.id === w.id) return { key: k, row: r }; - return null; - } - if (w.package_id !== undefined) { - const k = keyOf(w); - const r = rows.get(k); - if (r) return { key: k, row: r }; - } - for (const [k, r] of rows) if (matchesWhere(r, w)) return { key: k, row: r }; - return null; - }; - - const engine: any = { - async findOne(table: string, opts: { where: Record }) { - assertEngineFindOnePredicate(table, opts); - if (table === 'sys_metadata_history') { - return historyRows.find((h) => { - const w = opts.where; - if (w.type !== undefined && h.type !== w.type) return false; - if (w.name !== undefined && h.name !== w.name) return false; - if (w.version !== undefined && h.version !== w.version) return false; - if (w.organization_id !== undefined && h.organization_id !== w.organization_id) return false; - return true; - }) ?? null; - } - if (table === 'sys_metadata_commit') return null; - return findRow(opts.where)?.row ?? null; - }, - async find(table: string, opts?: { where?: Record }) { - if (table === 'sys_metadata_history') return historyRows; - if (table !== 'sys_metadata') return []; - return Array.from(rows.values()).filter((r) => matchesWhere(r, opts?.where ?? {})); - }, - async insert(table: string, data: Record) { - if (table === 'sys_metadata_audit') return { id: 'audit_skip' }; - if (table === 'sys_metadata_history') { - nextId += 1; - const h = { ...(data as unknown as HistoryRow), id: `h_${nextId}` }; - historyRows.push(h); - return { id: h.id }; - } - if (table !== 'sys_metadata') return { id: 'side_effect_skip' }; - nextId += 1; - const row = { ...(data as unknown as Row), id: `r_${nextId}` }; - rows.set(keyOf(data), row); - return { id: row.id }; - }, - async update(_t: string, data: Record, opts: { where: Record }) { - assertEngineUpdateDispatch(data, opts); - const found = findRow(opts.where); - if (!found) return { id: null }; - const merged = { ...found.row, ...(data as unknown as Row) }; - rows.delete(found.key); - rows.set(keyOf(merged), merged); - return { id: found.row.id }; - }, - async delete(_t: string, opts: { where: Record }) { - assertEngineDeleteDispatch(opts); - const found = findRow(opts.where); - if (!found) return { deleted: 0 }; - rows.delete(found.key); - return { deleted: 1 }; - }, - async transaction(cb: (ctx: unknown, info: { owned: boolean }) => Promise): Promise { - return cb(undefined, { owned: true }); - }, - syncObjectSchema: vi.fn(async (name: string) => { - if (refused.has(name)) throw new Error(`there is already an index named ${name}`); - syncedObjects.push(name); - return true; - }), - registry: { - registerItem: () => {}, - registerObject: () => {}, - listItems: () => [], - getItem: () => undefined, - getObject: () => undefined, - getPackage: () => undefined, - getArtifactItem: () => undefined, - }, - }; - return { engine, rows, syncedObjects }; -} - -function makeProtocol(refused: ReadonlySet = new Set()) { - const { engine, syncedObjects } = makeStubEngine(refused); - const protocol = new ObjectStackProtocolImplementation(engine, () => new Map(), 'env_prod') as any; - return { protocol, syncedObjects }; -} - -const PKG = 'app.demo'; - -/** An object body that clears the authoring gates the publish path runs first. */ -const objectBody = (name: string) => ({ - name, - label: 'Ticket', - sharingModel: 'private', - fields: { title: { type: 'text', label: 'Title' } }, -}); - -/** The fragment an operator greps for; the rest of the wording is not pinned. */ -const HEADLINE = 'its storage was NOT created or altered'; - -afterEach(() => { - vi.restoreAllMocks(); -}); - -function spyConsole() { - return { - error: vi.spyOn(console, 'error').mockImplementation(() => {}), - warn: vi.spyOn(console, 'warn').mockImplementation(() => {}), - }; -} - -async function publish(protocol: any, name: string) { - await protocol.saveMetaItem({ - type: 'object', name, item: objectBody(name), packageId: PKG, mode: 'draft', - }); - return protocol.publishMetaItem({ type: 'object', name }); -} - -describe('[#22985] a refused object-storage sync on publish is an error, once', () => { - it('the publish still answers success, and exactly one error line names the object, the remedy and the refusal', async () => { - const spy = spyConsole(); - const { protocol, syncedObjects } = makeProtocol(new Set(['ticket'])); - - const res = await publish(protocol, 'ticket'); - - // The half that makes it the durability class: the caller is told the - // publish succeeded, while the storage it was published for is absent. - expect(res.success).toBe(true); - expect(syncedObjects).toEqual([]); - - const reports = spy.error.mock.calls.filter((args) => String(args[0]).includes(HEADLINE)); - expect(reports).toHaveLength(1); - const [message, refusal] = reports[0]; - expect(message).toContain("object 'ticket'"); - // ② the fix, by its named subjects. - expect(message).toContain('publish the object again'); - expect(message).toContain('restart'); - // One line: the first line carries both halves, and the driver's - // refusal rides as its own argument rather than inside it. - expect(message).not.toContain('\n'); - expect(message).not.toContain('there is already an index'); - expect(refusal).toBe('there is already an index named ticket'); - // …and it is not ALSO reported at a quieter level. - expect(spy.warn.mock.calls.filter((args) => /table sync failed|ticket/.test(String(args[0])))).toEqual([]); - }); - - it('CONTROL: a publish whose sync succeeds reports nothing at error', async () => { - const spy = spyConsole(); - const { protocol, syncedObjects } = makeProtocol(); - - const res = await publish(protocol, 'ticket'); - - expect(res.success).toBe(true); - expect(syncedObjects).toEqual(['ticket']); - expect(spy.error).not.toHaveBeenCalled(); - }); -}); diff --git a/packages/metadata-protocol/src/protocol.publish-side-effects-canonical-type.test.ts b/packages/metadata-protocol/src/protocol.publish-side-effects-canonical-type.test.ts index 67723c395be..9faf267f549 100644 --- a/packages/metadata-protocol/src/protocol.publish-side-effects-canonical-type.test.ts +++ b/packages/metadata-protocol/src/protocol.publish-side-effects-canonical-type.test.ts @@ -55,7 +55,7 @@ // this helper calling `syncObjectSchema` with the folded // spelling, rather than passing for want of an assertion) -import { describe, expect, it, vi } from 'vitest'; +import { afterEach, describe, expect, it, vi } from 'vitest'; // [#5619] The producer's OWN write-verb dispatch decisions, imported from // `@objectstack/metadata-core` and NOT from `@objectstack/objectql`: objectql // depends on this package, so that import would close a dependency cycle turbo @@ -103,7 +103,7 @@ function matchesWhere(r: Row, where: Record): boolean { return true; } -function makeStubEngine() { +function makeStubEngine(refused: ReadonlySet = new Set()) { const rows = new Map(); const historyRows: HistoryRow[] = []; let nextId = 0; @@ -183,7 +183,9 @@ function makeStubEngine() { async transaction(cb: (ctx: unknown, info: { owned: boolean }) => Promise): Promise { return cb(undefined, { owned: true }); }, + // [#22985] A name in `refused` is the driver refusing that object's DDL. syncObjectSchema: vi.fn(async (name: string) => { + if (refused.has(name)) throw new Error(`there is already an index named ${name}`); syncedObjects.push(name); return true; }), @@ -200,8 +202,8 @@ function makeStubEngine() { return { engine, rows, syncedObjects }; } -function makeProtocol() { - const { engine, rows, syncedObjects } = makeStubEngine(); +function makeProtocol(refused?: ReadonlySet) { + const { engine, rows, syncedObjects } = makeStubEngine(refused); const protocol = new ObjectStackProtocolImplementation(engine, () => new Map(), 'env_prod') as any; return { protocol, rows, syncedObjects, engine }; } @@ -327,3 +329,78 @@ describe('[#8820] publish Phase 2 resolves the object table from the folded type expect(seen).toEqual(['object/ticket']); }); }); + +// --------------------------------------------------------------------------- +// [#22985] A REFUSED storage sync on publish is an `error`, once — and the +// publish is not failed. +// --------------------------------------------------------------------------- +// `ensureObjectStorage` runs after the publish has been written and registered, +// so when the driver refuses its `syncObjectSchema` the publish still answers +// success and the object is served with no table behind it. From the outside +// nothing looks wrong, which is the class AGENTS.md "Degradation log levels" +// sends to `error`. The wording is not pinned: the pins hold the level, the +// count, the named object, the named remedies and the driver's refusal as its +// own argument — and the "looks healthy" half, as the publish verdict the +// caller reads. Driven through this file's stub because it is the one that +// already carries the publish path end to end. + +/** The fragment an operator greps for; the rest of the wording is not pinned. */ +const REFUSED_HEADLINE = 'its storage was NOT created or altered'; + +describe('[#22985] a refused object-storage sync on publish is an error, once', () => { + afterEach(() => { + vi.restoreAllMocks(); + }); + + function spyConsole() { + return { + error: vi.spyOn(console, 'error').mockImplementation(() => {}), + warn: vi.spyOn(console, 'warn').mockImplementation(() => {}), + }; + } + + async function publish(protocol: any, name: string) { + await protocol.saveMetaItem({ + type: 'object', name, item: objectBody(name), packageId: PKG, mode: 'draft', + }); + return protocol.publishMetaItem({ type: 'object', name }); + } + + it('the publish still answers success, and exactly one error line names the object, the remedy and the refusal', async () => { + const spy = spyConsole(); + const { protocol, syncedObjects } = makeProtocol(new Set(['ticket'])); + + const res = await publish(protocol, 'ticket'); + + // The half that makes it the durability class: the caller is told the + // publish succeeded, while the storage it was published for is absent. + expect(res.success).toBe(true); + expect(syncedObjects).toEqual([]); + + const reports = spy.error.mock.calls.filter((args) => String(args[0]).includes(REFUSED_HEADLINE)); + expect(reports).toHaveLength(1); + const [message, refusal] = reports[0]; + expect(message).toContain("object 'ticket'"); + // ② the fix, by its named subjects. + expect(message).toContain('publish the object again'); + expect(message).toContain('restart'); + // One line: the first line carries both halves, and the driver's + // refusal rides as its own argument rather than inside it. + expect(message).not.toContain('\n'); + expect(message).not.toContain('there is already an index'); + expect(refusal).toBe('there is already an index named ticket'); + // …and it is not ALSO reported at a quieter level. + expect(spy.warn.mock.calls.filter((args) => /table sync failed|ticket/.test(String(args[0])))).toEqual([]); + }); + + it('CONTROL: a publish whose sync succeeds logs no error at all', async () => { + const spy = spyConsole(); + const { protocol, syncedObjects } = makeProtocol(); + + const res = await publish(protocol, 'ticket'); + + expect(res.success).toBe(true); + expect(syncedObjects).toEqual(['ticket']); + expect(spy.error).not.toHaveBeenCalled(); + }); +}); diff --git a/scripts/measure-durability-swallow-family.mjs b/scripts/measure-durability-swallow-family.mjs index d4c915aeddb..f6af9a4bac3 100644 --- a/scripts/measure-durability-swallow-family.mjs +++ b/scripts/measure-durability-swallow-family.mjs @@ -314,6 +314,7 @@ const WRITE_SHAPED_CALLEES = new Map([ ['syncSchema', 'gate-vocabulary'], ['syncSchemasBatch', 'gate-vocabulary'], ['syncRegisteredSchemas', 'gate-vocabulary'], + ['syncObjectSchema', 'gate-vocabulary'], ['initObjects', 'gate-vocabulary'], ['rearmSuspendedWaitTimers', 'gate-vocabulary'], ['writeDeferredReference', 'gate-vocabulary'],