fix(durability): a refused syncObjectSchema logs error at the messaging, datasource and publish seams; the gate reads .call/.apply/.bind and declares it

.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 <table> 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 '<name>': object '<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('<object>') failed`.
+- **`@objectstack/metadata-protocol`**: publishing an object whose storage sync is refused logs `[Protocol] object '<name>' 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 '<name>': …`, so a log search for that text now finds nothing.

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<string, unknown>): boolean {
     return true;
 }
 
-function makeStubEngine() {
+function makeStubEngine(refused: ReadonlySet<string> = new Set()) {
     const rows = new Map<string, Row>();
     const historyRows: HistoryRow[] = [];
     let nextId = 0;
@@ -183,7 +183,9 @@ function makeStubEngine() {
         async transaction<T>(cb: (ctx: unknown, info: { owned: boolean }) => Promise<T>): Promise<T> {
             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<string>) {
+    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();
+    });
+});

packages/metadata-protocol/src/protocol.record-package-commit-durability.test.ts

@@ -173,6 +173,11 @@ function makeStubEngine() {
         async transaction<T>(cb: (ctx: undefined, info: { owned: boolean }) => Promise<T>): Promise<T> {
             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: () => {},

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<void> {
         // [#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,
+            );
         }
     }
 

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<string>) {
+  const drivers = new Map<string, { name?: string }>();
+  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<string>, 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']);
+  });
+});