fix(objectql): 区分「同一实例的幂等重入」与「真正的 driver 名字冲突」(#4773)

.changeset/driver-double-registration-log.md

@@ -0,0 +1,45 @@
+---
+"@objectstack/objectql": patch
+---
+
+fix(objectql): a re-registered driver stops crying wolf, and a real name collision starts saying what it cost (#4773)
+
+Every boot printed one line into `⚠ Boot diagnostics`:
+
+```
+WARN Driver already registered, skipping {"driverName":"com.objectstack.driver.sql"}
+```
+
+It was never an anomaly. The standalone `default` datasource is registered
+twice, on two legs of one round trip, and traced end to end it is the **same
+object instance** both times:
+
+1. `DatasourceConnectionService.attemptConnect()` builds the default driver and
+   registers it (`isDefault: true`), driven by `DefaultDatasourcePlugin.init()`;
+2. that plugin republishes the instance it just read back out of the engine as
+   the `driver.<name>` kernel service — the surface `os migrate` and serve's
+   storage detection resolve the primary DB through — and
+   `ObjectQLPlugin.start()`'s `driver.*` discovery loop bridges every such
+   service into the engine, handing back the driver it already holds.
+
+Nothing is decided and nothing is discarded, so `registerDriver` now reports
+that at `debug`. A no-anomaly line on every single boot does not belong at
+`warn`; it only teaches operators that `warn` means nothing.
+
+The reason this is not a blanket downgrade: the same `warn` also covered the
+case that genuinely matters — **two different driver instances claiming one
+name**, where "skipping" silently drops one of two configurations (connection
+string, pool, tenant scoping, capability set) while every query bound to that
+name keeps working against the winner. The two are now told apart by object
+identity:
+
+- **same instance** → `debug`, nothing happened;
+- **different instance under a held name** → still `warn`, now naming which
+  configuration was KEPT and which was DISCARDED (with both versions) so the
+  operator can tell what is actually in force;
+- **same instance re-registered with `isDefault` while another driver holds
+  that role** → `warn`, because the caller's intent is otherwise dropped in
+  silence.
+
+Registration behaviour is unchanged in all three cases — first registration
+still wins. Only which of them is worth an operator's attention changed.

packages/objectql/src/engine-driver-registration.test.ts

@@ -0,0 +1,147 @@
+// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license.
+//
+// framework#4773: every showcase boot logged
+// `WARN Driver already registered, skipping {"driverName":"com.objectstack.driver.sql"}`.
+//
+// The diagnosis: the standalone `default` datasource is registered twice, on
+// two legs of ONE round trip, with the SAME object instance both times —
+// `DatasourceConnectionService.attemptConnect()` registers the driver it built
+// (isDefault: true), `DefaultDatasourcePlugin.init()` republishes that same
+// instance as the `driver.<name>` kernel service, and `ObjectQLPlugin.start()`'s
+// `driver.*` discovery loop bridges it back in (isDefault: false). Nothing is
+// decided and nothing is discarded, so a `warn` on every boot was pure noise —
+// and worse, it was indistinguishable from the case that DOES matter: two
+// DIFFERENT drivers claiming one name, where "skipping" silently drops one of
+// two configurations.
+//
+// These tests pin the split: identical re-entry is quiet, real divergence is
+// loud. Deleting the split would make both cases warn again (the #4773 noise)
+// or both cases quiet (a silently-adopted config, strictly worse).
+
+import { describe, it, expect } from 'vitest';
+import { ObjectQL } from './engine.js';
+
+type Record_ = { level: string; message: string; meta?: Record<string, unknown> };
+
+/** Captures every record the engine logs, at every level. */
+function makeCapturingLogger() {
+  const records: Record_[] = [];
+  const push = (level: string) => (message: string, meta?: Record<string, unknown>) => {
+    records.push({ level, message, meta });
+  };
+  const logger: any = {
+    debug: push('debug'),
+    info: push('info'),
+    warn: push('warn'),
+    error: push('error'),
+    fatal: push('fatal'),
+    child: () => logger,
+  };
+  return { logger, records };
+}
+
+/** Minimal IDataDriver stub — only identity/name/version matter here. */
+function makeDriver(name: string, version = '1.0.0') {
+  const driver: any = {
+    name,
+    version,
+    supports: {},
+    async connect() {}, async disconnect() {}, async checkHealth() { return true; },
+    async execute() { return null; },
+    async find() { return []; },
+    async findOne() { return null; },
+    async create(_o: string, data: Record<string, unknown>) { return { id: 'r_1', ...data }; },
+    async update(_o: string, id: string, data: Record<string, unknown>) { return { ...data, id }; },
+    async delete() { return true; },
+    async count() { return 0; },
+    async bulkCreate() { return []; },
+    async bulkUpdate() { return []; },
+    async bulkDelete() {},
+    async beginTransaction() { return { __trx: true, commit: async () => {}, rollback: async () => {} }; },
+    async commit() {}, async rollback() {},
+  };
+  return driver;
+}
+
+const warnsAbout = (records: Record_[], driverName: string) =>
+  records.filter((r) => r.level === 'warn' && r.meta?.driverName === driverName);
+
+describe('ObjectQL.registerDriver — identical re-entry vs. real name collision (#4773)', () => {
+  it('re-registering the SAME instance is quiet: debug, never warn', () => {
+    const { logger, records } = makeCapturingLogger();
+    const engine = new ObjectQL({ logger });
+    const driver = makeDriver('com.objectstack.driver.sql');
+
+    engine.registerDriver(driver, true);
+    // The `driver.*` discovery loop's leg: same object, no default claim.
+    engine.registerDriver(driver);
+
+    expect(warnsAbout(records, 'com.objectstack.driver.sql')).toEqual([]);
+    const debugs = records.filter((r) => r.level === 'debug' && r.meta?.driverName === 'com.objectstack.driver.sql');
+    expect(debugs).toHaveLength(1);
+    expect(debugs[0]!.message).toMatch(/same instance is a no-op/);
+  });
+
+  it('the quiet re-entry changes nothing: the first registration still stands', () => {
+    const { logger } = makeCapturingLogger();
+    const engine = new ObjectQL({ logger });
+    const driver = makeDriver('com.objectstack.driver.sql');
+
+    engine.registerDriver(driver, true);
+    engine.registerDriver(driver);
+
+    expect(engine.getDriverByName('com.objectstack.driver.sql')).toBe(driver);
+    expect(engine.getDefaultDriverName()).toBe('com.objectstack.driver.sql');
+  });
+
+  it('a DIFFERENT instance under a held name stays LOUD and names which config survived', () => {
+    const { logger, records } = makeCapturingLogger();
+    const engine = new ObjectQL({ logger });
+    const kept = makeDriver('com.objectstack.driver.sql', '1.0.0');
+    const discarded = makeDriver('com.objectstack.driver.sql', '2.0.0');
+
+    engine.registerDriver(kept, true);
+    engine.registerDriver(discarded);
+
+    const warns = warnsAbout(records, 'com.objectstack.driver.sql');
+    expect(warns).toHaveLength(1);
+    // The operator must be able to tell WHICH of the two configurations is in
+    // force without reading the source — that is the whole cost of a collision.
+    expect(warns[0]!.message).toMatch(/collision/i);
+    expect(warns[0]!.message).toMatch(/KEEPING/);
+    expect(warns[0]!.message).toMatch(/DISCARDING/);
+    expect(warns[0]!.meta).toMatchObject({ keptVersion: '1.0.0', discardedVersion: '2.0.0' });
+    // First-wins is unchanged behaviour — only the reporting got sharper.
+    expect(engine.getDriverByName('com.objectstack.driver.sql')).toBe(kept);
+  });
+
+  it('a dropped `isDefault` request stays LOUD — the intent is silently lost otherwise', () => {
+    const { logger, records } = makeCapturingLogger();
+    const engine = new ObjectQL({ logger });
+    const first = makeDriver('driver.a');
+    const second = makeDriver('driver.b');
+
+    engine.registerDriver(first, true);
+    engine.registerDriver(second);
+    // Same instance, but now asking for a role another driver already holds.
+    engine.registerDriver(second, true);
+
+    const warns = warnsAbout(records, 'driver.b');
+    expect(warns).toHaveLength(1);
+    expect(warns[0]!.message).toMatch(/IGNORED/);
+    expect(warns[0]!.meta).toMatchObject({ currentDefault: 'driver.a' });
+    expect(engine.getDefaultDriverName()).toBe('driver.a');
+  });
+
+  it('a same-instance re-entry that re-asserts an ALREADY-held default stays quiet', () => {
+    const { logger, records } = makeCapturingLogger();
+    const engine = new ObjectQL({ logger });
+    const driver = makeDriver('com.objectstack.driver.sql');
+
+    engine.registerDriver(driver, true);
+    engine.registerDriver(driver, true);
+
+    expect(warnsAbout(records, 'com.objectstack.driver.sql')).toEqual([]);
+    expect(engine.getDefaultDriverName()).toBe('com.objectstack.driver.sql');
+  });
+});

packages/objectql/src/engine.ts

@@ -2020,11 +2020,69 @@ export class ObjectQL implements IObjectQLEngine {
   }
 
   /**
-   * Register a new storage driver
+   * Register a new storage driver.
+   *
+   * **Re-registering the SAME driver instance is by design, not an anomaly**
+   * (#4773). Every standalone boot does it exactly once, on two legs of one
+   * round trip:
+   *
+   *  1. `DatasourceConnectionService.attemptConnect()` builds the `default`
+   *     datasource's driver and registers it here with `isDefault: true`
+   *     (`service-datasource/src/datasource-connection-service.ts`), driven by
+   *     `DefaultDatasourcePlugin.init()`;
+   *  2. that plugin then republishes **the very object it just read back out of
+   *     this engine** as the `driver.<name>` kernel service — the surface
+   *     `os migrate` and serve's storage detection resolve the primary DB
+   *     through — and `ObjectQLPlugin.start()`'s `driver.*` discovery loop
+   *     bridges every such service into the engine, handing us back the
+   *     instance we already hold.
+   *
+   * So this guard has to answer two different questions, and the whole point of
+   * splitting it is that they deserve different voices:
+   *
+   *  - **Same instance** → leg 2 above. Nothing is decided and nothing is
+   *    discarded, and it happens on every boot: `debug`. Reporting a
+   *    no-anomaly, every-boot event at `warn` only teaches operators that
+   *    `warn` means nothing, which is what makes the next real one unreadable
+   *    (the degradation-log-level rule, #4632).
+   *  - **A DIFFERENT driver under a name we already hold** → two distinct
+   *    configurations claim one name and exactly one of them is silently
+   *    dropped. Whatever the loser carried — connection string, pool, tenant
+   *    scoping, capability set — is simply not in force, while every query
+   *    bound to that name keeps working against the winner. That is a real
+   *    caller-side defect and stays loud, now saying *which* config survived.
+   *  - **Same instance, but the caller asked for `isDefault` and something
+   *    else already is the default** → the caller's intent is being dropped,
+   *    so it is loud too rather than folded into the quiet path.
    */
   registerDriver(driver: IDataDriver, isDefault: boolean = false) {
-    if (this.drivers.has(driver.name)) {
-      this.logger.warn('Driver already registered, skipping', { driverName: driver.name });
+    const existing = this.drivers.get(driver.name);
+    if (existing) {
+      if (existing !== driver) {
+        this.logger.warn(
+          'Driver name collision — KEEPING the already-registered driver and DISCARDING the one just supplied. ' +
+            'Two different driver instances claim one name, so whatever configuration the discarded instance carried ' +
+            '(connection string, pool, capabilities) is NOT in force, while queries routed to this name keep working ' +
+            'against the one that was kept. Fix the caller: give the second datasource a name of its own.',
+          {
+            driverName: driver.name,
+            keptVersion: existing.version,
+            discardedVersion: driver.version,
+          },
+        );
+      } else if (isDefault && this.defaultDriver !== driver.name) {
+        this.logger.warn(
+          'Driver re-registered as DEFAULT but another driver already holds that role — the request is IGNORED and ' +
+            'the existing default stands. Unregister the current default first if the switch was intended.',
+          { driverName: driver.name, currentDefault: this.defaultDriver },
+        );
+      } else {
+        // The by-design round trip documented above — expected on every boot,
+        // so it must not reach the boot-diagnostics warning list.
+        this.logger.debug('Driver already registered — re-registering the same instance is a no-op', {
+          driverName: driver.name,
+        });
+      }
       return;
     }
 

packages/objectql/src/plugin.ts

@@ -432,7 +432,17 @@ export class ObjectQLPlugin implements Plugin {
         const services = ctx.getServices();
         for (const [name, service] of services.entries()) {
             if (name.startsWith('driver.')) {
-                 // Register Driver
+                 // Register Driver.
+                 //
+                 // For the standalone `default` this is the SECOND leg of a
+                 // round trip, not a new registration (#4773):
+                 // `DefaultDatasourcePlugin.init()` already registered the
+                 // driver through `DatasourceConnectionService`, then
+                 // republished that same instance as this `driver.<name>`
+                 // service for `os migrate` / serve storage detection. Handing
+                 // it back is a deliberate no-op — see `registerDriver`, which
+                 // distinguishes this identical re-entry (quiet) from a real
+                 // name collision between two different instances (loud).
                  this.ql.registerDriver(service);
                  ctx.logger.debug('Discovered and registered driver service', { serviceName: name });
             }

packages/runtime/src/default-datasource-plugin.test.ts

@@ -228,6 +228,66 @@ describe('DefaultDatasourcePlugin — the default datasource as a declaration (#
     expect(disconnects).toBe(0);
   }, BOOT_TIMEOUT);
 
+  it('registers the default driver TWICE with the same instance, and says nothing about it (#4773)', async () => {
+    // The round trip this pins: DefaultDatasourcePlugin.init() connects the
+    // driver through DatasourceConnectionService (registerDriver, isDefault:
+    // true), then republishes THAT instance as the `driver.<name>` kernel
+    // service, and ObjectQLPlugin.start()'s `driver.*` discovery loop bridges
+    // it straight back in (registerDriver, isDefault: false). Every boot logged
+    // `WARN Driver already registered, skipping` for it — a no-anomaly line in
+    // the boot diagnostics of every single `pnpm dev`.
+    //
+    // Both halves are asserted on purpose: the warning count alone would stay
+    // green if the second registration simply stopped happening, which is a
+    // different change with different consequences (the `driver.*` bridge is
+    // what a pre-built DriverPlugin relies on).
+    const { ObjectQL } = await import('@objectstack/objectql');
+    const registrations: Array<{ name: string; instance: unknown; isDefault: boolean }> = [];
+    const originalRegister = ObjectQL.prototype.registerDriver;
+    ObjectQL.prototype.registerDriver = function (driver: any, isDefault = false) {
+      registrations.push({ name: driver?.name, instance: driver, isDefault });
+      return originalRegister.call(this, driver, isDefault);
+    };
+    // ObjectLogger writes straight to `process.stdout` in Node (console is only
+    // its browser fallback), and `serve`'s boot-quiet window intercepts exactly
+    // this stream — so this is the same bytes the `⚠ Boot diagnostics` block
+    // replays. Capturing `console.warn` instead would see nothing and pass
+    // vacuously.
+    const stdoutLines: string[] = [];
+    const originalWrite = process.stdout.write.bind(process.stdout);
+    (process.stdout as any).write = (chunk: any, ...rest: any[]) => {
+      stdoutLines.push(String(chunk));
+      return (originalWrite as any)(chunk, ...rest);
+    };
+
+    const kernel = await assemble({});
+    try {
+      await kernel.bootstrap();
+      const engine = kernel.getService<IDataEngine>('data');
+      const defaultName = engine.getDefaultDriverName!()!;
+
+      // (a) it really is registered twice, with ONE object — object identity,
+      // not merely an equal configuration.
+      const forDefault = registrations.filter((r) => r.name === defaultName);
+      expect(forDefault).toHaveLength(2);
+      expect(forDefault[0]!.isDefault).toBe(true);
+      expect(forDefault[1]!.isDefault).toBe(false);
+      expect(forDefault[1]!.instance).toBe(forDefault[0]!.instance);
+      // …and the second leg is the `driver.*` service bridge, same instance again.
+      expect(kernel.getService(`driver.${defaultName}`)).toBe(engine.getDriverByName!(defaultName));
+
+      // (b) that round trip is silent — no boot-diagnostics warning.
+      const driverWarns = stdoutLines.filter(
+        (l) => /\bWARN\b/.test(l) && /already registered|Driver name collision/i.test(l),
+      );
+      expect(driverWarns).toEqual([]);
+    } finally {
+      (process.stdout as any).write = originalWrite;
+      ObjectQL.prototype.registerDriver = originalRegister;
+      try { await (kernel as any)?.stop?.(); } catch { /* noop */ }
+    }
+  }, BOOT_TIMEOUT);
+
   it("rejects an app bundle that declares a datasource named 'default' (host-reserved name)", async () => {
     const kernel = await assemble({
       bundle: {