Skip to content

Commit fe72aa5

Browse files
os-warrenclaude
andauthored
fix(objectql): make the [Registry] Collision warning fire in the cold-boot order (#12430)
The artifact-vs-DB collision warning was guarded on `packageId &&`, so it only ever spoke when the PACKAGE registered second. A kernel boot cannot produce that order: the artifact reaches the registry in Phase 1 (AppPlugin.init -> manifest.register), and the sys_metadata overlay is rehydrated in Phase 2 (ObjectQLPlugin.start -> loadMetaFromDb) under the bare name with no package id. init-all-then-start-all means the overlay is always the second arrival at boot, which is the exact order the guard excluded — so ADR-0005's claim that the shadowing is "discoverable in startup logs" was false in the only order startup produces. The cold-boot direction now warns with its own message rather than a widened version of the existing one: both orders end in the same state, but the event an operator has to act on differs. Resolution order is untouched. Claude-Session: https://claude.ai/code/session_01W6HFzyH98W1YaQXhJUJt6o Co-authored-by: Claude <noreply@anthropic.com>
1 parent ade757f commit fe72aa5

3 files changed

Lines changed: 383 additions & 1 deletion

File tree

Lines changed: 41 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,41 @@
1+
---
2+
'@objectstack/objectql': patch
3+
---
4+
5+
fix(objectql): the `[Registry] Collision` warning fires in the cold-boot order too (#12027)
6+
7+
The artifact-vs-DB collision warning was order-asymmetric, and silent in the
8+
order a kernel boot actually produces. It was guarded on `packageId &&`, so it
9+
spoke only when the PACKAGE registered second — but the artifact reaches the
10+
registry in kernel Phase 1 (`AppPlugin.init` -> `manifest.register`) and the
11+
`sys_metadata` overlay is rehydrated in Phase 2 (`ObjectQLPlugin.start` ->
12+
`loadMetaFromDb`), under the bare name with no package id. The kernel runs
13+
init-all then start-all, so at boot the overlay is ALWAYS the second arrival —
14+
the exact order the guard excluded. The direction that did warn is the
15+
late-registration one: a marketplace install, a post-`start()`
16+
`manifest.register`, an HMR reload.
17+
18+
The consequence is worse than a missing line, because the mechanism looked
19+
sound to anyone who had seen it work: ADR-0005 says this warning is what makes
20+
the silent shadowing "discoverable in startup logs", and in the only order
21+
startup produces it was not discoverable at all. Measured on a real
22+
`@objectstack/example-crm` boot before the fix: one stored `view` overlay of a
23+
packaged view produced 0 collision lines and 4 silent shadowings (the container
24+
plus its three expanded ViewItems).
25+
26+
The cold-boot direction now warns with its own message rather than a widened
27+
version of the existing one. Both orders end in the same state — the runtime
28+
row wins either way — but the event differs, and the event is what an operator
29+
acts on: a package that is dead on arrival behind a row that predates it,
30+
versus a stored row taking over a definition this process just loaded from
31+
code. Which definition wins is unchanged in both orders, and pinned as such.
32+
33+
Graded `patch`: this adds a diagnostic to a path that printed nothing. No API
34+
changes, no accept/reject behaviour changes, and resolution order is untouched.
35+
The one operator-visible effect worth stating is the log itself — a deployment
36+
that customizes packaged metadata will see one new `[Registry] Collision` line
37+
per shadowed name per process, where it previously saw none. Volume was
38+
measured rather than assumed: 0 lines on a stock boot (a stock `sys_metadata`
39+
holds no overlay of a packaged name), and the line marks the transition into
40+
the bare slot rather than the state, so the read-side hydration and the
41+
write-through do not re-emit it on later reads and writes.
Lines changed: 264 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,264 @@
1+
// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license.
2+
3+
/**
4+
* [#12027] The artifact-vs-DB collision warning fires in BOTH registration
5+
* orders — including the one a cold boot actually produces.
6+
*
7+
* ## What was wrong, and why "the warning is missing" is the wrong description
8+
*
9+
* The warning existed and worked. It was guarded on `packageId &&`, so it
10+
* spoke only when the PACKAGE registered second. A kernel boot cannot produce
11+
* that order:
12+
*
13+
* ```
14+
* Phase 1 init AppPlugin.init -> manifest.register -> ObjectQL.registerApp
15+
* -> registerItem(type, item, 'name', packageId) // pkg:name
16+
* Phase 2 start ObjectQLPlugin.start -> restoreMetadataFromDb
17+
* -> protocol.loadMetaFromDb -> hydrateOverlayIntoRegistry
18+
* -> registerItem(type, item, 'name') // bare name
19+
* ```
20+
*
21+
* The kernel runs init-all THEN start-all, so the artifact is ALWAYS the first
22+
* arrival at boot and the overlay always the second — the exact order the
23+
* `packageId &&` half excluded. Measured on a real `@objectstack/example-crm`
24+
* boot: one stored `view` overlay of a packaged view produced **0** collision
25+
* lines and 4 silent shadowings (the container plus its three expanded
26+
* ViewItems). So a reader who had ever SEEN the warning fire (a marketplace
27+
* install, an HMR reload — the late-registration order) had every reason to
28+
* believe the mechanism was sound, while the case it missed was the one that
29+
* happens on every boot.
30+
*
31+
* That is why the first case below is the load-bearing one: a pin written only
32+
* for the direction that already warned would pass on `origin/main` and prove
33+
* nothing.
34+
*
35+
* ## Two messages, not one widened message
36+
*
37+
* Both orders end in the same state — `getItem` checks the bare key first, so
38+
* the runtime row wins either way (pinned at the bottom of this file, because
39+
* a diagnostic repair must not move precedence). What differs is the EVENT,
40+
* and the event is what an operator acts on: a package that is dead on arrival
41+
* behind a row that predates it, versus a stored row taking over a definition
42+
* this process just loaded from code. `distinguishable messages` pins that a
43+
* later "one message fits both" simplification cannot silently drop it.
44+
*
45+
* ## The narrowing cases are not decoration
46+
*
47+
* A warning that fires on every boot of a normal deployment says nothing (the
48+
* #12015 ruling, one warning over). Three of the cases below are the volume
49+
* bound: no packaged item means no line at all, a re-registration of the same
50+
* overlay is silent (the line marks the transition, not the state — otherwise
51+
* the read-side hydration would warn once per GET), and a composite entry that
52+
* is itself an overlay or a tenant-authored body is not a packaged definition
53+
* being shadowed.
54+
*/
55+
56+
import { describe, it, expect, beforeEach, afterEach, vi } from 'vitest';
57+
import { SchemaRegistry } from './registry';
58+
59+
const PKG = 'com.acme.crm';
60+
61+
/** Every `[Registry] Collision` line emitted while `fn` runs. */
62+
function collisionsDuring(fn: () => void): string[] {
63+
const spy = vi.spyOn(console, 'warn').mockImplementation(() => {});
64+
try {
65+
fn();
66+
return spy.mock.calls
67+
.map((args) => args.map((a) => String(a)).join(' '))
68+
.filter((line) => line.includes('[Registry] Collision'));
69+
} finally {
70+
spy.mockRestore();
71+
}
72+
}
73+
74+
describe('[#12027] SchemaRegistry collision warning is order-symmetric', () => {
75+
let registry: SchemaRegistry;
76+
77+
beforeEach(() => {
78+
registry = new SchemaRegistry({ multiTenant: false });
79+
registry.logLevel = 'silent';
80+
});
81+
afterEach(() => {
82+
vi.restoreAllMocks();
83+
});
84+
85+
it('COMMON COLD-BOOT ORDER — artifact first, then the sys_metadata row: warns', () => {
86+
// The case that was silent on `origin/main`. Phase 1 registers the packaged
87+
// flow under `pkg:name`; Phase 2 hydrates the stored row under the bare name.
88+
registry.registerItem('flow', { name: 'nightly_sync', label: 'packaged' }, 'name', PKG);
89+
90+
const lines = collisionsDuring(() => {
91+
registry.registerItem('flow', { name: 'nightly_sync', label: 'runtime' }, 'name');
92+
});
93+
94+
expect(lines).toHaveLength(1);
95+
// The line has to carry the three things an operator needs: which item,
96+
// which package lost, and what now serves.
97+
expect(lines[0]).toContain('flow/nightly_sync');
98+
expect(lines[0]).toContain(PKG);
99+
expect(lines[0]).toContain('shadows the package value');
100+
});
101+
102+
it('LATE-REGISTRATION ORDER — sys_metadata row first, then the package: still warns', () => {
103+
// Unchanged behaviour, pinned so the repair cannot trade one order for the
104+
// other. This order is a marketplace install / HMR reload, not a boot.
105+
registry.registerItem('flow', { name: 'nightly_sync', label: 'runtime' }, 'name');
106+
107+
const lines = collisionsDuring(() => {
108+
registry.registerItem('flow', { name: 'nightly_sync', label: 'packaged' }, 'name', PKG);
109+
});
110+
111+
expect(lines).toHaveLength(1);
112+
expect(lines[0]).toContain('flow/nightly_sync');
113+
expect(lines[0]).toContain('will shadow the package value');
114+
});
115+
116+
it('the two orders produce DISTINGUISHABLE messages', () => {
117+
// Same end state, different event. A reader must be able to tell "your new
118+
// package is dead on arrival" from "a stored row just took over"; a single
119+
// message widened to fit both would have to drop which one arrived second.
120+
const bootOrder = collisionsDuring(() => {
121+
registry.registerItem('page', { name: 'home', label: 'packaged' }, 'name', PKG);
122+
registry.registerItem('page', { name: 'home', label: 'runtime' }, 'name');
123+
});
124+
const lateOrder = collisionsDuring(() => {
125+
registry.registerItem('doc', { name: 'home', label: 'runtime' }, 'name');
126+
registry.registerItem('doc', { name: 'home', label: 'packaged' }, 'name', PKG);
127+
});
128+
129+
expect(bootOrder).toHaveLength(1);
130+
expect(lateOrder).toHaveLength(1);
131+
expect(bootOrder[0]).not.toEqual(lateOrder[0]);
132+
// The tense is the discriminator, and it is the accurate part: one has
133+
// already happened, the other is what the arriving package is walking into.
134+
expect(bootOrder[0]).toContain('has just been registered from sys_metadata');
135+
expect(lateOrder[0]).toContain('already');
136+
});
137+
138+
it('a discriminated bundle member is judged against its OWN member key', () => {
139+
// [#7730] `email_template` is keyed by (name, locale). The overlay slot the
140+
// warning asks about is the member with the SAME discriminator, so the
141+
// packaged `zh-CN` member and the stored `zh-CN` row collide.
142+
registry.registerItem(
143+
'email_template',
144+
{ name: 'welcome', locale: 'zh-CN', subject: 'packaged' },
145+
'name',
146+
PKG,
147+
);
148+
149+
const lines = collisionsDuring(() => {
150+
registry.registerItem(
151+
'email_template',
152+
{ name: 'welcome', locale: 'zh-CN', subject: 'runtime' },
153+
'name',
154+
);
155+
});
156+
157+
expect(lines).toHaveLength(1);
158+
expect(lines[0]).toContain('email_template/welcome');
159+
});
160+
161+
describe('what is NOT a collision — the volume bound', () => {
162+
it('a runtime row with no packaged counterpart is silent', () => {
163+
const lines = collisionsDuring(() => {
164+
registry.registerItem('flow', { name: 'tenant_only', label: 'runtime' }, 'name');
165+
});
166+
expect(lines).toEqual([]);
167+
});
168+
169+
it('re-registering the SAME overlay warns once, not once per registration', () => {
170+
// The read-side hydration (`getMetaItems`) and the write-through both
171+
// re-register an overlay that is already in the bare slot. Warning on the
172+
// STATE rather than the transition would put a line in the log on every
173+
// GET of a customized item.
174+
registry.registerItem('flow', { name: 'nightly_sync', label: 'packaged' }, 'name', PKG);
175+
176+
const first = collisionsDuring(() => {
177+
registry.registerItem('flow', { name: 'nightly_sync', label: 'runtime' }, 'name');
178+
});
179+
const repeats = collisionsDuring(() => {
180+
registry.registerItem('flow', { name: 'nightly_sync', label: 'runtime v2' }, 'name');
181+
registry.registerItem('flow', { name: 'nightly_sync', label: 'runtime v3' }, 'name');
182+
});
183+
184+
expect(first).toHaveLength(1);
185+
expect(repeats).toEqual([]);
186+
});
187+
188+
it('a composite entry carrying the sys_metadata sentinel is not a packaged definition', () => {
189+
// `_packageId: 'sys_metadata'` marks an overlay bound to no package
190+
// (#4636). Nothing shipped from code here, so nothing is being shadowed.
191+
registry.registerItem(
192+
'flow',
193+
{ name: 'nightly_sync', _packageId: 'sys_metadata' },
194+
'name',
195+
'sys_metadata',
196+
);
197+
const lines = collisionsDuring(() => {
198+
registry.registerItem('flow', { name: 'nightly_sync', label: 'runtime' }, 'name');
199+
});
200+
expect(lines).toEqual([]);
201+
});
202+
203+
it('a tenant-authored composite entry is not a packaged definition', () => {
204+
// ADR-0010 `_provenance: 'org'` — a tenant's own item that came back from
205+
// a kernel rebuild keyed by a package id (cloud#970). `isCodeArtifactBody`
206+
// is the single answer to "does a code package ship this?", and this is
207+
// not it.
208+
registry.registerItem(
209+
'flow',
210+
{ name: 'nightly_sync', _packageId: PKG, _provenance: 'org' },
211+
'name',
212+
PKG,
213+
);
214+
const lines = collisionsDuring(() => {
215+
registry.registerItem('flow', { name: 'nightly_sync', label: 'runtime' }, 'name');
216+
});
217+
expect(lines).toEqual([]);
218+
});
219+
220+
it('a package re-registering its own item is silent in both directions', () => {
221+
const lines = collisionsDuring(() => {
222+
registry.registerItem('flow', { name: 'nightly_sync', label: 'v1' }, 'name', PKG);
223+
registry.registerItem('flow', { name: 'nightly_sync', label: 'v2' }, 'name', PKG);
224+
});
225+
expect(lines).toEqual([]);
226+
});
227+
228+
it('two packages shipping the same bare name is coexistence, not shadowing', () => {
229+
// ADR-0048 §3.4 — distinct composite keys, package-scoped resolution.
230+
// Neither registration takes the bare slot, so this guard never speaks.
231+
const lines = collisionsDuring(() => {
232+
registry.registerItem('page', { name: 'home', label: 'CRM' }, 'name', PKG);
233+
registry.registerItem('page', { name: 'home', label: 'HR' }, 'name', 'com.acme.hr');
234+
});
235+
expect(lines).toEqual([]);
236+
});
237+
});
238+
239+
describe('the diagnostic repair moves nothing', () => {
240+
it('the runtime row still wins in BOTH orders (ADR-0005 overlay precedence)', () => {
241+
// Clause ② in test form: this card adds a line to a path that printed
242+
// nothing. Which definition wins is untouched, and untouched IN BOTH
243+
// ORDERS — a warning that changed precedence would be a different card.
244+
const bootOrder = new SchemaRegistry({ multiTenant: false });
245+
bootOrder.logLevel = 'silent';
246+
collisionsDuring(() => {
247+
bootOrder.registerItem('flow', { name: 'nightly_sync', label: 'packaged' }, 'name', PKG);
248+
bootOrder.registerItem('flow', { name: 'nightly_sync', label: 'runtime' }, 'name');
249+
});
250+
expect(bootOrder.getItem<any>('flow', 'nightly_sync')?.label).toBe('runtime');
251+
expect(bootOrder.getItem<any>('flow', 'nightly_sync', PKG)?.label).toBe('runtime');
252+
// …and the packaged definition is still reachable as an artifact.
253+
expect(bootOrder.getArtifactItem<any>('flow', 'nightly_sync', PKG)?.label).toBe('packaged');
254+
255+
const lateOrder = new SchemaRegistry({ multiTenant: false });
256+
lateOrder.logLevel = 'silent';
257+
collisionsDuring(() => {
258+
lateOrder.registerItem('flow', { name: 'nightly_sync', label: 'runtime' }, 'name');
259+
lateOrder.registerItem('flow', { name: 'nightly_sync', label: 'packaged' }, 'name', PKG);
260+
});
261+
expect(lateOrder.getItem<any>('flow', 'nightly_sync')?.label).toBe('runtime');
262+
});
263+
});
264+
});

packages/objectql/src/registry.ts

Lines changed: 78 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -2911,7 +2911,12 @@ export class SchemaRegistry {
29112911
// the DB row silently shadow the new artifact value. That is correct
29122912
// ADR-0005 behavior, but the silent shadowing can surprise package
29132913
// authors and operators. Log a single warning so the situation is
2914-
// discoverable in startup logs.
2914+
// discoverable in the logs.
2915+
//
2916+
// [#12027] This guard covers ONE of the two orders — the package arriving
2917+
// second, which at runtime means a late registration (marketplace install,
2918+
// HMR reload), never a cold boot. The cold-boot order is covered by the
2919+
// second guard below; read the two together.
29152920
// [#7730] `bareKey` rather than `baseName`: for a discriminated type the
29162921
// overlay slot this warning asks about is the bundle member with the SAME
29172922
// discriminator (`auth.welcome@zh-CN`), not the name on its own — which is
@@ -2929,6 +2934,78 @@ export class SchemaRegistry {
29292934
}
29302935
}
29312936

2937+
// [#12027] THE SAME COLLISION, IN THE ORDER A COLD BOOT ACTUALLY PRODUCES.
2938+
//
2939+
// The guard above carries `packageId &&`, so it only ever speaks when the
2940+
// PACKAGE registers second. A kernel boot cannot produce that order: the
2941+
// artifact reaches this registry in kernel Phase 1 (AppPlugin.init ->
2942+
// `manifest.register` -> `ObjectQL.registerApp`), and `sys_metadata`
2943+
// rehydration runs in Phase 2 (`ObjectQLPlugin.start` ->
2944+
// `restoreMetadataFromDb` -> `loadMetaFromDb` -> the protocol's
2945+
// `hydrateOverlayIntoRegistry`, which registers under the BARE key with no
2946+
// packageId). Phase 1 strictly precedes Phase 2, so at boot the overlay is
2947+
// always the second arrival and the guard above is structurally unreachable
2948+
// — it fires only for a LATE package registration (marketplace install, a
2949+
// post-`start()` `manifest.register`, an HMR reload).
2950+
//
2951+
// Measured on a real `@objectstack/example-crm` boot before this landed: a
2952+
// stored `view` overlay of a packaged view produced 0 `[Registry] Collision`
2953+
// lines and 4 silent shadowings (the container plus its three expanded
2954+
// ViewItems). ADR-0005 §Collision-warning says this warning is what makes
2955+
// the silent shadowing "discoverable in startup logs"; in the only order
2956+
// startup produces, it was not discoverable at all.
2957+
//
2958+
// ## Why this is a SECOND message and not one message widened to fit both
2959+
//
2960+
// The two orders are the same end state (`getItem` checks the bare key
2961+
// first, so the runtime row wins either way) reached by two different
2962+
// events, and the event is the part an operator has to act on. Above: a
2963+
// package just arrived and is DEAD ON ARRIVAL behind a row that predates
2964+
// it. Here: a stored row just took over a definition this process already
2965+
// loaded from code. A single message would have to drop which one arrived
2966+
// second, which is precisely the fact that tells the reader whether they
2967+
// are looking at a failed install or at a customization taking effect.
2968+
//
2969+
// ## Why it says "may be deliberate", and why it still fires by default
2970+
//
2971+
// Unlike the order above — where `!dbOnly._packageId` narrows to a
2972+
// package-LESS row, i.e. an accidental name collision — this direction
2973+
// cannot tell a deliberate customization from an accidental collision: the
2974+
// protocol merges the artifact's `_packageId`/`_provenance` envelope onto
2975+
// the overlay body (ADR-0010 §3.3 `mergeArtifactProtection`) before it
2976+
// reaches this method, so both look identical here. The message therefore
2977+
// states the consequence and both readings rather than accusing. It stays
2978+
// at `warn` because a diagnostic nobody sees is the defect being fixed.
2979+
//
2980+
// Volume, measured rather than assumed (the #12015 discipline — a warning
2981+
// that fires on every boot of a stock deployment is saying nothing):
2982+
// 0 lines on a stock CRM boot, because a stock `sys_metadata` holds no
2983+
// overlay of a packaged name; thereafter once per shadowed name per
2984+
// process. `!collection.has(bareKey)` is what bounds it — the line marks
2985+
// the TRANSITION (a bare slot that was empty is now taken), not the state,
2986+
// so the read-side hydration and the write-through, which re-register the
2987+
// same overlay on later reads and writes, stay silent.
2988+
if (!packageId && !collection.has(bareKey)) {
2989+
let shadowed: any;
2990+
for (const [key, existing] of collection) {
2991+
if (key !== bareKey && key.endsWith(`:${bareKey}`) && isCodeArtifactBody(existing)) {
2992+
shadowed = existing;
2993+
break;
2994+
}
2995+
}
2996+
if (shadowed) {
2997+
console.warn(
2998+
`[Registry] Collision: ${type}/${baseName} is shipped by package ` +
2999+
`"${shadowed._packageId}" and a runtime-authored row with the same name has ` +
3000+
`just been registered from sys_metadata. The runtime row now shadows the ` +
3001+
`package value (ADR-0005 overlay precedence): every read of ${type}/${baseName} ` +
3002+
`serves the stored row, not the packaged definition. That is the sanctioned ` +
3003+
`path when the row is a deliberate customization — if it is not one, delete ` +
3004+
`the sys_metadata row (or rename one of the two) so the package value serves.`,
3005+
);
3006+
}
3007+
}
3008+
29323009
collection.set(storageKey, item);
29333010
this.log(`[Registry] Registered ${type}: ${storageKey}`);
29343011
}

0 commit comments

Comments
 (0)