Skip to content

Commit bbdbf28

Browse files
baozhoutaoclaude
andauthored
fix(metadata-protocol,objectql): loadMetaFromDb 用返回值表达「没读到存储」,boot 侧不再把 outage 记成空库 (#5897) (#5998)
`loadMetaFromDb` 的返回值 `{ loaded, errors, invalid }` 没有任何字段能表达 「这次水合根本没读到存储」—— 读不到的数据库与真正的空库都答 `loaded: 0`。 其唯一生产消费方 `ObjectQLPlugin.restoreMetadataFromDb` 因此无从分支:它唯一 的分支只是在两条日志之间做选择,而「什么都没回来」那一侧是 debug 级的 `No persisted metadata found in database`。于是一个一个字都没读到持久化元数据 的 kernel,在 debug 级上宣称「本来就没有」,然后照常报告 ready。 代价写在 plugin.ts Phase 2 注释里:registry 为空时 `registry.getObject` 把 「读不到」答成「没声明」—— unknown-column 查询守卫、hooks、relationships 静默 降级,overlay 对象既不建表也不桥接。这是 ADR-0110 D3(outage ≠ miss)在 boot 侧的落地,继 #5108 / #5089 / #5532 / #5707 之后。 - 生产端:返回值加 `storeUnavailable: boolean`,只在已经打印 `[Protocol] DB hydration skipped` 的那条分支上置位 —— 即 `isMissingTableError` 判为非良性的读失败。未建表的首次启动(#5841)不置位,那里 `loaded: 0` 确是事实。 - 消费端:读该位并打 **error** 级日志,按 AGENTS「Degradation log levels」写清 后果(什么都没恢复、kernel 仍报健康、哪些能力静默降级)与修法(查 sys_metadata 背后的数据源:连接、凭据、表是否存在,然后重启)。可读的空库照旧 debug。 ⛔ 不改控制流:boot 继续降级运行 —— 对着读不到的 overlay 存储拒绝启动,会把一次 瞬时故障变成彻底停机。变的只是「降级」不再被当成「健康」。 对 `ProtocolWithDbRestore` 鸭子类型实现者零破坏:新字段在消费侧声明为 optional (与既有的 `invalid` 同例),旧 shim 照常通过类型检查并被读成「不是 outage」—— 正是它此前唯一能表达的判定。 Claude-Session: https://claude.ai/code/session_019Q7oc7ASjh8yxyS3Yz78We Co-authored-by: Claude <noreply@anthropic.com>
1 parent 8dcf607 commit bbdbf28

6 files changed

Lines changed: 541 additions & 49 deletions

File tree

Lines changed: 62 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,62 @@
1+
---
2+
"@objectstack/metadata-protocol": patch
3+
"@objectstack/objectql": patch
4+
---
5+
6+
fix(metadata-protocol,objectql): a boot that could not read `sys_metadata` says so at `error`, instead of reporting "no persisted metadata" at debug (#5897)
7+
8+
`loadMetaFromDb` — the boot step that hydrates `sys_metadata` overlay rows into
9+
the SchemaRegistry — returned `{ loaded, errors, invalid }`, and no field in
10+
that shape could express **"this hydration never read the store"**. An
11+
unreachable database and a genuinely empty one both answered `loaded: 0`.
12+
13+
Its only production consumer, `ObjectQLPlugin.restoreMetadataFromDb`, therefore
14+
had nothing to branch on: its single branch chose between two log lines, and
15+
the "nothing came back" side was
16+
`logger.debug('No persisted metadata found in database')`. So a kernel that
17+
could not read a word of its persisted metadata stated at **debug** level that
18+
there was none, and went on to report ready.
19+
20+
What that costs is not hypothetical — it is written into the plugin's own
21+
Phase 2 comment. With the registry empty, `registry.getObject` answers "not
22+
declared" where the truth is "we could not look": unknown-column query guards,
23+
hooks and relationships silently degrade, and overlay objects get neither a
24+
synced table nor a metadata bridge. This is ADR-0110 D3 (an outage is not a
25+
miss) on the boot side, after the same rule landed for `DatabaseLoader`
26+
(#5108), `listForIndex` (#5089) and the overlay reads (#5532 / #5707).
27+
28+
**What changed**
29+
30+
- `loadMetaFromDb` returns `storeUnavailable: boolean`, set on exactly the
31+
branch that already prints `[Protocol] DB hydration skipped` — a read that
32+
failed for a reason `isMissingTableError` does *not* call benign. A store
33+
that has merely not been provisioned yet (first boot, before migrations)
34+
keeps `storeUnavailable: false`, because `loaded: 0` genuinely is the truth
35+
there (#5841).
36+
- `restoreMetadataFromDb` reads it and logs at **`error`**, naming the
37+
consequence (nothing was restored, the kernel keeps reporting healthy, and
38+
which capabilities silently degrade) and the fix (check the datasource behind
39+
`sys_metadata` — connection, credentials, table existence — then restart).
40+
Per AGENTS.md "Degradation log levels": persisted state and runtime state
41+
disagreeing while the system still looks healthy is the `error` class. An
42+
empty-but-readable store keeps its quiet debug line, so first boots do not
43+
start emitting durability errors.
44+
45+
**Not changed**: control flow. Boot still degrades and continues — refusing to
46+
boot on an unreadable overlay store would turn a transient outage into an
47+
outright one. What changes is that the degradation is now distinguishable from
48+
health, and reported as such.
49+
50+
**Impact on duck-typed `ProtocolWithDbRestore` implementers**: none required.
51+
`ObjectQLPlugin` matches the `protocol` service structurally, and the new field
52+
is declared **optional** on its side of the contract, exactly as `invalid`
53+
already is. A shim that predates the field keeps type-checking and is read as
54+
"not an outage" — the only verdict it was able to express before — so its
55+
behaviour is byte-for-byte what it was. The trade-off is deliberate and worth
56+
naming: an optional field cannot *force* a third-party shim to start reporting
57+
outages, so such a shim stays as silent as it is today. Requiring the field
58+
would have made that impossible to ignore at the cost of breaking every
59+
external implementer for a bit only one in-repo producer sets; the in-repo
60+
producer (`ObjectStackProtocolImplementation`) declares and returns it
61+
**required**, so the path that actually runs in every ObjectStack kernel is
62+
fully covered.

packages/metadata-protocol/src/protocol.load-meta-hydration-benign.test.ts

Lines changed: 125 additions & 35 deletions
Original file line numberDiff line numberDiff line change
@@ -32,32 +32,55 @@
3232
// `@objectstack/metadata/errors`.
3333
//
3434
// ---------------------------------------------------------------------------
35-
// Deliberately NOT covered here — #5841 fact 2
35+
// #5841 fact 2, now closed — #5897
3636
// ---------------------------------------------------------------------------
37-
// Every non-benign failure is still answered with `console.warn` + a
38-
// `{ loaded: 0, errors: 0, invalid: 0 }` return, so the return value cannot
39-
// distinguish "the store holds no overlay rows" from "the store could not be
40-
// read" (ADR-0110 D3, on the boot side). That is a change to this method's
41-
// return CONTRACT and to its consumer (`ObjectQLPlugin.restoreMetadataFromDb`),
42-
// so it was measured and reported separately rather than bundled in. The
43-
// `records the fact-2 indistinguishability` case below pins the measurement,
44-
// not an endorsement — see its comment.
37+
// The classification above decided which failures are worth a console line. It
38+
// did NOT change the return value: every non-benign failure still answered
39+
// `{ loaded: 0, errors: 0, invalid: 0 }`, the exact shape a healthy empty store
40+
// answers, so nothing a CALLER can read distinguished "the store holds no
41+
// overlay rows" from "the store could not be read" (ADR-0110 D3, on the boot
42+
// side). The sole consumer, `ObjectQLPlugin.restoreMetadataFromDb`, therefore
43+
// logged an unreachable database as `debug` "No persisted metadata found in
44+
// database" and the kernel reported ready.
45+
//
46+
// #5897 adds `storeUnavailable: boolean` to the return, set on exactly the
47+
// branch that prints `DB hydration skipped` — the non-benign one. The
48+
// `outage vs empty store` case below is the SAME measurement as before, turned
49+
// over: it used to assert the two are indistinguishable, and now asserts the
50+
// bit is precisely what tells them apart while every count stays identical.
51+
//
52+
// Not a superset of `errors`: that counter is about rows that arrived and
53+
// failed to hydrate, this bit is about a row set that never arrived. And not a
54+
// control-flow change — boot still degrades and continues.
4555
//
4656
// ---------------------------------------------------------------------------
4757
// Reverse verification, direction predicted BEFORE running
4858
// ---------------------------------------------------------------------------
49-
// Restore `if (!/no such table/i.test(e.message ?? ''))` and this file goes
50-
// PARTIALLY red — which is itself the finding, so the split is recorded rather
51-
// than rounded to "it goes red":
59+
// Two limbs, two predictions, both confirmed by running them:
60+
//
61+
// (1) Restore `if (!/no such table/i.test(e.message ?? ''))` (the #5841 fix)
62+
// and this file goes PARTIALLY red — the split is itself the finding, so it
63+
// is recorded rather than rounded to "it goes red":
64+
//
65+
// * RED: every "table not provisioned" case whose driver does not use
66+
// SQLite's wording — the Postgres message, the code-only `42P01`, the
67+
// MySQL `errno`, and the wrapped `cause` — because the regex cannot see
68+
// any of them, so the benign first boot both warns AND (post-#5897)
69+
// mis-sets `storeUnavailable`, mistaking health for an outage.
70+
// * GREEN, unchanged: the SQLite case (the one phrasing the old regex was
71+
// written against), the ECONNREFUSED outage case (already warned, still
72+
// warns), and the working-store control. A suite that went fully red
73+
// here would mean the fix had changed more than the classification.
5274
//
53-
// * RED: every "table not provisioned" case whose driver does not use
54-
// SQLite's wording — the Postgres message, the code-only `42P01`, the
55-
// MySQL `errno`, and the wrapped `cause` — because the regex cannot see any
56-
// of them and the benign first boot starts warning.
57-
// * GREEN, unchanged: the SQLite case (the one phrasing the old regex was
58-
// written against), the ECONNREFUSED outage case (already warned, still
59-
// warns), and the working-store control. A suite that went fully red here
60-
// would mean the fix had changed more than the classification.
75+
// (2) Delete `storeUnavailable = true` from that branch (the #5897 fix) and the
76+
// complementary set goes red, all in the same direction — no inversion, no
77+
// count that moves the other way:
78+
//
79+
// * RED: the outage cases (`ECONNREFUSED`, the non-Error rejection, the
80+
// unrecognised-wording case) and `outage vs empty store`, which stops
81+
// being able to tell them apart — i.e. exactly the defect #5897 names.
82+
// * GREEN, unchanged: every benign case and the working-store control,
83+
// because `false` is what they already expected.
6184
//
6285
// The engine doubles below declare `find` only — `loadMetaFromDb` calls nothing
6386
// else on the engine, and a fake with no `delete`/`update` member has no write
@@ -158,8 +181,11 @@ describe('loadMetaFromDb — an unprovisioned store is benign, by error TYPE (#5
158181

159182
const res = await protocol.loadMetaFromDb();
160183

161-
// Benign: there really are no overlay rows yet, so this IS the truth.
162-
expect(res).toEqual({ loaded: 0, errors: 0, invalid: 0 });
184+
// Benign: there really are no overlay rows yet, so this IS the
185+
// truth — including `storeUnavailable: false` (#5897). An
186+
// un-provisioned store is not an outage, and a bit that fired here
187+
// would turn every first boot into a boot-time `error`.
188+
expect(res).toEqual({ loaded: 0, errors: 0, invalid: 0, storeUnavailable: false });
163189
// …and a healthy first boot owes the operator no warning line.
164190
expect(
165191
warn.mock.calls.map((c) => String(c[0])),
@@ -178,9 +204,14 @@ describe('loadMetaFromDb — an unprovisioned store is benign, by error TYPE (#5
178204
engineThatCannotBeRead(() => new Error('role "app_ro" does not exist')),
179205
);
180206

181-
await protocol.loadMetaFromDb();
207+
const res = await protocol.loadMetaFromDb();
182208

183209
expect(warn.mock.calls.some((c) => String(c[0]).startsWith(SKIPPED))).toBe(true);
210+
// The console line and the return bit are ONE verdict, read twice —
211+
// a failure loud enough to warn about is one the caller must be able
212+
// to see too (#5897). If these two ever disagree, the boot log and the
213+
// boot's own return value are describing different systems.
214+
expect(res.storeUnavailable).toBe(true);
184215
});
185216
});
186217

@@ -193,7 +224,9 @@ describe('loadMetaFromDb — every other read failure stays loud (#5841)', () =>
193224

194225
const res = await protocol.loadMetaFromDb();
195226

196-
expect(res).toEqual({ loaded: 0, errors: 0, invalid: 0 });
227+
// #5897 — the counts are unchanged (nothing was loaded, and truthfully
228+
// so), but the shape now ALSO says why: the read never happened.
229+
expect(res).toEqual({ loaded: 0, errors: 0, invalid: 0, storeUnavailable: true });
197230
const skipped = warn.mock.calls
198231
.map((c) => String(c[0]))
199232
.filter((m) => m.startsWith(SKIPPED));
@@ -209,26 +242,31 @@ describe('loadMetaFromDb — every other read failure stays loud (#5841)', () =>
209242
engineThatCannotBeRead(() => 'pool exhausted'),
210243
);
211244

212-
await protocol.loadMetaFromDb();
245+
const res = await protocol.loadMetaFromDb();
213246

214247
const skipped = warn.mock.calls
215248
.map((c) => String(c[0]))
216249
.filter((m) => m.startsWith(SKIPPED));
217250
expect(skipped).toHaveLength(1);
218251
expect(skipped[0]).toContain('pool exhausted');
219252
expect(skipped[0]).not.toContain('undefined');
253+
// A driver that rejects with a bare string is still an outage: the bit
254+
// is set from the CLASSIFICATION, never from the thrown value's shape.
255+
expect(res.storeUnavailable).toBe(true);
220256
});
221257

222-
it('records the fact-2 indistinguishability: an outage returns exactly what an empty store returns', async () => {
223-
// NOT an endorsement — this is #5841 fact 2, measured. The console.warn
224-
// above is the only channel that separates these two, and the RETURN
225-
// VALUE (the thing `ObjectQLPlugin.restoreMetadataFromDb` reads) makes
226-
// them identical, so boot logs `No persisted metadata found in database`
227-
// at debug level for an unreachable store.
258+
it('an outage and an empty store agree on every count and are told apart by the bit alone', async () => {
259+
// This case is #5841 fact 2, TURNED OVER (#5897). It used to assert
260+
// `expect(outage).toEqual(emptyStore)` and carried the note "when the
261+
// return contract grows a way to say the store could not be read, this
262+
// assertion is EXPECTED to flip — update it to assert the difference;
263+
// do not delete the case." This is that flip.
228264
//
229-
// When the return contract grows a way to say "the store could not be
230-
// read", this assertion is EXPECTED to flip — update it to assert the
231-
// difference; do not delete the case.
265+
// The `console.warn` is no longer the ONLY channel separating the two.
266+
// The return value — the thing `ObjectQLPlugin.restoreMetadataFromDb`
267+
// actually reads — now separates them as well, which is what lets boot
268+
// log an unreachable store at `error` instead of `debug` "No persisted
269+
// metadata found in database".
232270
const warn = vi.spyOn(console, 'warn').mockImplementation(() => {});
233271
const outage = await new ObjectStackProtocolImplementation(
234272
engineThatCannotBeRead(connectionRefused),
@@ -237,7 +275,20 @@ describe('loadMetaFromDb — every other read failure stays loud (#5841)', () =>
237275
engineWithRows([]).engine,
238276
).loadMetaFromDb();
239277

240-
expect(outage).toEqual(emptyStore);
278+
// Distinguishable at all — the defect, gone.
279+
expect(outage).not.toEqual(emptyStore);
280+
expect(outage.storeUnavailable).toBe(true);
281+
expect(emptyStore.storeUnavailable).toBe(false);
282+
283+
// …and distinguishable by the bit ALONE. Asserted rather than implied:
284+
// every count is still identical, so nothing downstream can reconstruct
285+
// the difference from `loaded`/`errors`/`invalid` and quietly grow a
286+
// second, weaker way of asking the same question.
287+
const { storeUnavailable: _o, ...outageCounts } = outage;
288+
const { storeUnavailable: _e, ...emptyCounts } = emptyStore;
289+
expect(outageCounts).toEqual(emptyCounts);
290+
expect(outageCounts).toEqual({ loaded: 0, errors: 0, invalid: 0 });
291+
241292
expect(warn).toHaveBeenCalled();
242293
});
243294
});
@@ -266,7 +317,46 @@ describe('loadMetaFromDb — a working store is untouched by the classification
266317

267318
expect(res.loaded).toBe(1);
268319
expect(res.errors).toBe(0);
320+
// #5897 — the control that keeps the bit from becoming decorative: a
321+
// read that SUCCEEDED must report `false`, or every boot is an outage.
322+
expect(res.storeUnavailable).toBe(false);
269323
expect(registered).toHaveLength(1);
270324
expect(warn.mock.calls.some((c) => String(c[0]).startsWith(SKIPPED))).toBe(false);
271325
});
326+
327+
it('rows that fail to hydrate are counted in `errors`, NOT reported as an unavailable store', async () => {
328+
// #5897 — the other half of "not a superset of `errors`". Here the read
329+
// succeeded and one row is unparseable: the store was perfectly
330+
// available, the hydration is PARTIAL. Setting the bit here would make
331+
// boot print the durability `error` for a single corrupt row, which is
332+
// the mirror-image failure AGENTS.md "Degradation log levels" warns
333+
// about — it trains everyone to skim `error`.
334+
const warn = vi.spyOn(console, 'warn').mockImplementation(() => {});
335+
const { engine } = engineWithRows([
336+
{
337+
id: 'r_ok',
338+
type: 'app',
339+
name: 'crm',
340+
organization_id: null,
341+
state: 'active',
342+
metadata: JSON.stringify({ name: 'crm', label: 'CRM' }),
343+
},
344+
{
345+
id: 'r_bad',
346+
type: 'app',
347+
name: 'broken',
348+
organization_id: null,
349+
state: 'active',
350+
metadata: 'not-valid-json{{{',
351+
},
352+
]);
353+
354+
const res = await new ObjectStackProtocolImplementation(engine).loadMetaFromDb();
355+
356+
expect(res.loaded).toBe(1);
357+
expect(res.errors).toBe(1);
358+
expect(res.storeUnavailable).toBe(false);
359+
expect(warn).toHaveBeenCalled(); // the per-row line, not the skipped one
360+
expect(warn.mock.calls.some((c) => String(c[0]).startsWith(SKIPPED))).toBe(false);
361+
});
272362
});

packages/metadata-protocol/src/protocol.stored-conversions.test.ts

Lines changed: 4 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -163,7 +163,10 @@ describe('loadMetaFromDb — boot hydration converts, diagnoses, never drops (#3
163163
const { engine, registered } = makeStubEngine([legacyObjectRow, legacyActionRow]);
164164
const protocol = new ObjectStackProtocolImplementation(engine);
165165
const res = await protocol.loadMetaFromDb();
166-
expect(res).toEqual({ loaded: 2, errors: 0, invalid: 0 });
166+
// `storeUnavailable: false` (#5897) — a read that happened. The whole
167+
// return is asserted rather than the three counts, so a future field
168+
// cannot appear here unexamined.
169+
expect(res).toEqual({ loaded: 2, errors: 0, invalid: 0, storeUnavailable: false });
167170

168171
const obj = registered.find((r) => r.kind === 'object')!;
169172
expect(obj.body.fields.amount.requiredWhen).toBe("record.status == 'sent'");

0 commit comments

Comments
 (0)