fix(objectql): make the [Registry] Collision warning fire in the cold-boot order too

.changeset/registry-collision-order-symmetric.md

@@ -0,0 +1,41 @@
+---
+'@objectstack/objectql': patch
+---
+
+fix(objectql): the `[Registry] Collision` warning fires in the cold-boot order too (#12027)
+
+The artifact-vs-DB collision warning was order-asymmetric, and silent in the
+order a kernel boot actually produces. It was guarded on `packageId &&`, so it
+spoke only when the PACKAGE registered second — but the artifact reaches the
+registry in kernel 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. The kernel runs
+init-all then start-all, so at boot the overlay is ALWAYS the second arrival —
+the exact order the guard excluded. The direction that did warn is the
+late-registration one: a marketplace install, a post-`start()`
+`manifest.register`, an HMR reload.
+
+The consequence is worse than a missing line, because the mechanism looked
+sound to anyone who had seen it work: ADR-0005 says this warning is what makes
+the silent shadowing "discoverable in startup logs", and in the only order
+startup produces it was not discoverable at all. Measured on a real
+`@objectstack/example-crm` boot before the fix: one stored `view` overlay of a
+packaged view produced 0 collision lines and 4 silent shadowings (the container
+plus its three expanded ViewItems).
+
+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 — the runtime
+row wins either way — but the event differs, and the event is what an operator
+acts on: a package that is dead on arrival behind a row that predates it,
+versus a stored row taking over a definition this process just loaded from
+code. Which definition wins is unchanged in both orders, and pinned as such.
+
+Graded `patch`: this adds a diagnostic to a path that printed nothing. No API
+changes, no accept/reject behaviour changes, and resolution order is untouched.
+The one operator-visible effect worth stating is the log itself — a deployment
+that customizes packaged metadata will see one new `[Registry] Collision` line
+per shadowed name per process, where it previously saw none. Volume was
+measured rather than assumed: 0 lines on a stock boot (a stock `sys_metadata`
+holds no overlay of a packaged name), and the line marks the transition into
+the bare slot rather than the state, so the read-side hydration and the
+write-through do not re-emit it on later reads and writes.

packages/objectql/src/registry-collision-order.test.ts

@@ -0,0 +1,264 @@
+// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license.
+
+/**
+ * [#12027] The artifact-vs-DB collision warning fires in BOTH registration
+ * orders — including the one a cold boot actually produces.
+ *
+ * ## What was wrong, and why "the warning is missing" is the wrong description
+ *
+ * The warning existed and worked. It was guarded on `packageId &&`, so it
+ * spoke only when the PACKAGE registered second. A kernel boot cannot produce
+ * that order:
+ *
+ * ```
+ * Phase 1 init AppPlugin.init -> manifest.register -> ObjectQL.registerApp
+ * -> registerItem(type, item, 'name', packageId) // pkg:name
+ * Phase 2 start ObjectQLPlugin.start -> restoreMetadataFromDb
+ * -> protocol.loadMetaFromDb -> hydrateOverlayIntoRegistry
+ * -> registerItem(type, item, 'name') // bare name
+ * ```
+ *
+ * The kernel runs init-all THEN start-all, so the artifact is ALWAYS the first
+ * arrival at boot and the overlay always the second — the exact order the
+ * `packageId &&` half excluded. Measured on a real `@objectstack/example-crm`
+ * boot: one stored `view` overlay of a packaged view produced **0** collision
+ * lines and 4 silent shadowings (the container plus its three expanded
+ * ViewItems). So a reader who had ever SEEN the warning fire (a marketplace
+ * install, an HMR reload — the late-registration order) had every reason to
+ * believe the mechanism was sound, while the case it missed was the one that
+ * happens on every boot.
+ *
+ * That is why the first case below is the load-bearing one: a pin written only
+ * for the direction that already warned would pass on `origin/main` and prove
+ * nothing.
+ *
+ * ## Two messages, not one widened message
+ *
+ * Both orders end in the same state — `getItem` checks the bare key first, so
+ * the runtime row wins either way (pinned at the bottom of this file, because
+ * a diagnostic repair must not move precedence). What differs is the EVENT,
+ * and the event is what an operator acts on: a package that is dead on arrival
+ * behind a row that predates it, versus a stored row taking over a definition
+ * this process just loaded from code. `distinguishable messages` pins that a
+ * later "one message fits both" simplification cannot silently drop it.
+ *
+ * ## The narrowing cases are not decoration
+ *
+ * A warning that fires on every boot of a normal deployment says nothing (the
+ * #12015 ruling, one warning over). Three of the cases below are the volume
+ * bound: no packaged item means no line at all, a re-registration of the same
+ * overlay is silent (the line marks the transition, not the state — otherwise
+ * the read-side hydration would warn once per GET), and a composite entry that
+ * is itself an overlay or a tenant-authored body is not a packaged definition
+ * being shadowed.
+ */
+
+import { describe, it, expect, beforeEach, afterEach, vi } from 'vitest';
+import { SchemaRegistry } from './registry';
+
+const PKG = 'com.acme.crm';
+
+/** Every `[Registry] Collision` line emitted while `fn` runs. */
+function collisionsDuring(fn: () => void): string[] {
+ const spy = vi.spyOn(console, 'warn').mockImplementation(() => {});
+ try {
+ fn();
+ return spy.mock.calls
+ .map((args) => args.map((a) => String(a)).join(' '))
+ .filter((line) => line.includes('[Registry] Collision'));
+ } finally {
+ spy.mockRestore();
+ }
+}
+
+describe('[#12027] SchemaRegistry collision warning is order-symmetric', () => {
+ let registry: SchemaRegistry;
+
+ beforeEach(() => {
+ registry = new SchemaRegistry({ multiTenant: false });
+ registry.logLevel = 'silent';
+ });
+ afterEach(() => {
+ vi.restoreAllMocks();
+ });
+
+ it('COMMON COLD-BOOT ORDER — artifact first, then the sys_metadata row: warns', () => {
+ // The case that was silent on `origin/main`. Phase 1 registers the packaged
+ // flow under `pkg:name`; Phase 2 hydrates the stored row under the bare name.
+ registry.registerItem('flow', { name: 'nightly_sync', label: 'packaged' }, 'name', PKG);
+
+ const lines = collisionsDuring(() => {
+ registry.registerItem('flow', { name: 'nightly_sync', label: 'runtime' }, 'name');
+ });
+
+ expect(lines).toHaveLength(1);
+ // The line has to carry the three things an operator needs: which item,
+ // which package lost, and what now serves.
+ expect(lines[0]).toContain('flow/nightly_sync');
+ expect(lines[0]).toContain(PKG);
+ expect(lines[0]).toContain('shadows the package value');
+ });
+
+ it('LATE-REGISTRATION ORDER — sys_metadata row first, then the package: still warns', () => {
+ // Unchanged behaviour, pinned so the repair cannot trade one order for the
+ // other. This order is a marketplace install / HMR reload, not a boot.
+ registry.registerItem('flow', { name: 'nightly_sync', label: 'runtime' }, 'name');
+
+ const lines = collisionsDuring(() => {
+ registry.registerItem('flow', { name: 'nightly_sync', label: 'packaged' }, 'name', PKG);
+ });
+
+ expect(lines).toHaveLength(1);
+ expect(lines[0]).toContain('flow/nightly_sync');
+ expect(lines[0]).toContain('will shadow the package value');
+ });
+
+ it('the two orders produce DISTINGUISHABLE messages', () => {
+ // Same end state, different event. A reader must be able to tell "your new
+ // package is dead on arrival" from "a stored row just took over"; a single
+ // message widened to fit both would have to drop which one arrived second.
+ const bootOrder = collisionsDuring(() => {
+ registry.registerItem('page', { name: 'home', label: 'packaged' }, 'name', PKG);
+ registry.registerItem('page', { name: 'home', label: 'runtime' }, 'name');
+ });
+ const lateOrder = collisionsDuring(() => {
+ registry.registerItem('doc', { name: 'home', label: 'runtime' }, 'name');
+ registry.registerItem('doc', { name: 'home', label: 'packaged' }, 'name', PKG);
+ });
+
+ expect(bootOrder).toHaveLength(1);
+ expect(lateOrder).toHaveLength(1);
+ expect(bootOrder[0]).not.toEqual(lateOrder[0]);
+ // The tense is the discriminator, and it is the accurate part: one has
+ // already happened, the other is what the arriving package is walking into.
+ expect(bootOrder[0]).toContain('has just been registered from sys_metadata');
+ expect(lateOrder[0]).toContain('already');
+ });
+
+ it('a discriminated bundle member is judged against its OWN member key', () => {
+ // [#7730] `email_template` is keyed by (name, locale). The overlay slot the
+ // warning asks about is the member with the SAME discriminator, so the
+ // packaged `zh-CN` member and the stored `zh-CN` row collide.
+ registry.registerItem(
+ 'email_template',
+ { name: 'welcome', locale: 'zh-CN', subject: 'packaged' },
+ 'name',
+ PKG,
+ );
+
+ const lines = collisionsDuring(() => {
+ registry.registerItem(
+ 'email_template',
+ { name: 'welcome', locale: 'zh-CN', subject: 'runtime' },
+ 'name',
+ );
+ });
+
+ expect(lines).toHaveLength(1);
+ expect(lines[0]).toContain('email_template/welcome');
+ });
+
+ describe('what is NOT a collision — the volume bound', () => {
+ it('a runtime row with no packaged counterpart is silent', () => {
+ const lines = collisionsDuring(() => {
+ registry.registerItem('flow', { name: 'tenant_only', label: 'runtime' }, 'name');
+ });
+ expect(lines).toEqual([]);
+ });
+
+ it('re-registering the SAME overlay warns once, not once per registration', () => {
+ // The read-side hydration (`getMetaItems`) and the write-through both
+ // re-register an overlay that is already in the bare slot. Warning on the
+ // STATE rather than the transition would put a line in the log on every
+ // GET of a customized item.
+ registry.registerItem('flow', { name: 'nightly_sync', label: 'packaged' }, 'name', PKG);
+
+ const first = collisionsDuring(() => {
+ registry.registerItem('flow', { name: 'nightly_sync', label: 'runtime' }, 'name');
+ });
+ const repeats = collisionsDuring(() => {
+ registry.registerItem('flow', { name: 'nightly_sync', label: 'runtime v2' }, 'name');
+ registry.registerItem('flow', { name: 'nightly_sync', label: 'runtime v3' }, 'name');
+ });
+
+ expect(first).toHaveLength(1);
+ expect(repeats).toEqual([]);
+ });
+
+ it('a composite entry carrying the sys_metadata sentinel is not a packaged definition', () => {
+ // `_packageId: 'sys_metadata'` marks an overlay bound to no package
+ // (#4636). Nothing shipped from code here, so nothing is being shadowed.
+ registry.registerItem(
+ 'flow',
+ { name: 'nightly_sync', _packageId: 'sys_metadata' },
+ 'name',
+ 'sys_metadata',
+ );
+ const lines = collisionsDuring(() => {
+ registry.registerItem('flow', { name: 'nightly_sync', label: 'runtime' }, 'name');
+ });
+ expect(lines).toEqual([]);
+ });
+
+ it('a tenant-authored composite entry is not a packaged definition', () => {
+ // ADR-0010 `_provenance: 'org'` — a tenant's own item that came back from
+ // a kernel rebuild keyed by a package id (cloud#970). `isCodeArtifactBody`
+ // is the single answer to "does a code package ship this?", and this is
+ // not it.
+ registry.registerItem(
+ 'flow',
+ { name: 'nightly_sync', _packageId: PKG, _provenance: 'org' },
+ 'name',
+ PKG,
+ );
+ const lines = collisionsDuring(() => {
+ registry.registerItem('flow', { name: 'nightly_sync', label: 'runtime' }, 'name');
+ });
+ expect(lines).toEqual([]);
+ });
+
+ it('a package re-registering its own item is silent in both directions', () => {
+ const lines = collisionsDuring(() => {
+ registry.registerItem('flow', { name: 'nightly_sync', label: 'v1' }, 'name', PKG);
+ registry.registerItem('flow', { name: 'nightly_sync', label: 'v2' }, 'name', PKG);
+ });
+ expect(lines).toEqual([]);
+ });
+
+ it('two packages shipping the same bare name is coexistence, not shadowing', () => {
+ // ADR-0048 §3.4 — distinct composite keys, package-scoped resolution.
+ // Neither registration takes the bare slot, so this guard never speaks.
+ const lines = collisionsDuring(() => {
+ registry.registerItem('page', { name: 'home', label: 'CRM' }, 'name', PKG);
+ registry.registerItem('page', { name: 'home', label: 'HR' }, 'name', 'com.acme.hr');
+ });
+ expect(lines).toEqual([]);
+ });
+ });
+
+ describe('the diagnostic repair moves nothing', () => {
+ it('the runtime row still wins in BOTH orders (ADR-0005 overlay precedence)', () => {
+ // Clause ② in test form: this card adds a line to a path that printed
+ // nothing. Which definition wins is untouched, and untouched IN BOTH
+ // ORDERS — a warning that changed precedence would be a different card.
+ const bootOrder = new SchemaRegistry({ multiTenant: false });
+ bootOrder.logLevel = 'silent';
+ collisionsDuring(() => {
+ bootOrder.registerItem('flow', { name: 'nightly_sync', label: 'packaged' }, 'name', PKG);
+ bootOrder.registerItem('flow', { name: 'nightly_sync', label: 'runtime' }, 'name');
+ });
+ expect(bootOrder.getItem<any>('flow', 'nightly_sync')?.label).toBe('runtime');
+ expect(bootOrder.getItem<any>('flow', 'nightly_sync', PKG)?.label).toBe('runtime');
+ // …and the packaged definition is still reachable as an artifact.
+ expect(bootOrder.getArtifactItem<any>('flow', 'nightly_sync', PKG)?.label).toBe('packaged');
+
+ const lateOrder = new SchemaRegistry({ multiTenant: false });
+ lateOrder.logLevel = 'silent';
+ collisionsDuring(() => {
+ lateOrder.registerItem('flow', { name: 'nightly_sync', label: 'runtime' }, 'name');
+ lateOrder.registerItem('flow', { name: 'nightly_sync', label: 'packaged' }, 'name', PKG);
+ });
+ expect(lateOrder.getItem<any>('flow', 'nightly_sync')?.label).toBe('runtime');
+ });
+ });
+});

packages/objectql/src/registry.ts

@@ -2911,7 +2911,12 @@ export class SchemaRegistry {
  // the DB row silently shadow the new artifact value. That is correct
  // ADR-0005 behavior, but the silent shadowing can surprise package
  // authors and operators. Log a single warning so the situation is
- // discoverable in startup logs.
+ // discoverable in the logs.
+ //
+ // [#12027] This guard covers ONE of the two orders — the package arriving
+ // second, which at runtime means a late registration (marketplace install,
+ // HMR reload), never a cold boot. The cold-boot order is covered by the
+ // second guard below; read the two together.
  // [#7730] `bareKey` rather than `baseName`: for a discriminated type the
  // overlay slot this warning asks about is the bundle member with the SAME
  // discriminator (`auth.welcome@zh-CN`), not the name on its own — which is
@@ -2929,6 +2934,78 @@ export class SchemaRegistry {
  }
  }
 
+ // [#12027] THE SAME COLLISION, IN THE ORDER A COLD BOOT ACTUALLY PRODUCES.
+ //
+ // The guard above carries `packageId &&`, so it only ever speaks when the
+ // PACKAGE registers second. A kernel boot cannot produce that order: the
+ // artifact reaches this registry in kernel Phase 1 (AppPlugin.init ->
+ // `manifest.register` -> `ObjectQL.registerApp`), and `sys_metadata`
+ // rehydration runs in Phase 2 (`ObjectQLPlugin.start` ->
+ // `restoreMetadataFromDb` -> `loadMetaFromDb` -> the protocol's
+ // `hydrateOverlayIntoRegistry`, which registers under the BARE key with no
+ // packageId). Phase 1 strictly precedes Phase 2, so at boot the overlay is
+ // always the second arrival and the guard above is structurally unreachable
+ // — it fires only for a LATE package registration (marketplace install, a
+ // post-`start()` `manifest.register`, an HMR reload).
+ //
+ // Measured on a real `@objectstack/example-crm` boot before this landed: a
+ // stored `view` overlay of a packaged view produced 0 `[Registry] Collision`
+ // lines and 4 silent shadowings (the container plus its three expanded
+ // ViewItems). ADR-0005 §Collision-warning says this warning is what makes
+ // the silent shadowing "discoverable in startup logs"; in the only order
+ // startup produces, it was not discoverable at all.
+ //
+ // ## Why this is a SECOND message and not one message widened to fit both
+ //
+ // The two orders are the same end state (`getItem` checks the bare key
+ // first, so the runtime row wins either way) reached by two different
+ // events, and the event is the part an operator has to act on. Above: a
+ // package just arrived and is DEAD ON ARRIVAL behind a row that predates
+ // it. Here: a stored row just took over a definition this process already
+ // loaded from code. A single message would have to drop which one arrived
+ // second, which is precisely the fact that tells the reader whether they
+ // are looking at a failed install or at a customization taking effect.
+ //
+ // ## Why it says "may be deliberate", and why it still fires by default
+ //
+ // Unlike the order above — where `!dbOnly._packageId` narrows to a
+ // package-LESS row, i.e. an accidental name collision — this direction
+ // cannot tell a deliberate customization from an accidental collision: the
+ // protocol merges the artifact's `_packageId`/`_provenance` envelope onto
+ // the overlay body (ADR-0010 §3.3 `mergeArtifactProtection`) before it
+ // reaches this method, so both look identical here. The message therefore
+ // states the consequence and both readings rather than accusing. It stays
+ // at `warn` because a diagnostic nobody sees is the defect being fixed.
+ //
+ // Volume, measured rather than assumed (the #12015 discipline — a warning
+ // that fires on every boot of a stock deployment is saying nothing):
+ // 0 lines on a stock CRM boot, because a stock `sys_metadata` holds no
+ // overlay of a packaged name; thereafter once per shadowed name per
+ // process. `!collection.has(bareKey)` is what bounds it — the line marks
+ // the TRANSITION (a bare slot that was empty is now taken), not the state,
+ // so the read-side hydration and the write-through, which re-register the
+ // same overlay on later reads and writes, stay silent.
+ if (!packageId && !collection.has(bareKey)) {
+ let shadowed: any;
+ for (const [key, existing] of collection) {
+ if (key !== bareKey && key.endsWith(`:${bareKey}`) && isCodeArtifactBody(existing)) {
+ shadowed = existing;
+ break;
+ }
+ }
+ if (shadowed) {
+ console.warn(
+ `[Registry] Collision: ${type}/${baseName} is shipped by package ` +
+ `"${shadowed._packageId}" and a runtime-authored row with the same name has ` +
+ `just been registered from sys_metadata. The runtime row now shadows the ` +
+ `package value (ADR-0005 overlay precedence): every read of ${type}/${baseName} ` +
+ `serves the stored row, not the packaged definition. That is the sanctioned ` +
+ `path when the row is a deliberate customization — if it is not one, delete ` +
+ `the sys_metadata row (or rename one of the two) so the package value serves.`,
+ );
+ }
+ }
+
  collection.set(storageKey, item);
  this.log(`[Registry] Registered ${type}: ${storageKey}`);
  }