fix(metadata-protocol): seed-loader 中「计为错误」的失败一律记 error,不再自相矛盾地记 warn (#4729)

.changeset/seed-loader-loud-failure-log-level.md

@@ -0,0 +1,44 @@
+---
+"@objectstack/metadata-protocol": patch
+---
+
+fix(metadata-protocol): a seed failure that is COUNTED as an error now logs at `error` (#4729)
+
+`SeedLoaderService`'s pass-2 deferred back-fill carried a comment stating that a
+failed back-fill "must be a reported, counted error, **never** a silent warning"
+— and the line under it called `logger.warn`. The count was right (the failure
+lands in `result.errors`, flips `success: false`) but the level contradicted it,
+and that log line is the only trace a seed leaves in a host's console. `warn` is
+the level #4420 proved nobody reads.
+
+**What changed**
+
+- The failed back-fill logs at **`error`**, and the line now owes what
+  AGENTS.md → "Degradation log levels" requires of one: the **consequence**
+  (`<object>.<field>` stays NULL on a named record, the row itself was seeded so
+  every row counter reads clean, the circular relationship is half-written) and
+  the **fix** (nothing retries it — repair the write error, which is either a
+  transient failure that outlasted the retry budget or a validation rule vetoing
+  the update, then re-run the seed).
+- The rest of the file was audited against the same criterion — *is this failure
+  counted in the load's `errors` (i.e. does it make `success: false`)?* Five more
+  sites answered yes while logging `warn`, and were raised to `error`: a failed
+  batch insert row, a record dropped because its `cel` expression could not
+  resolve, the two invalid-reference paths that DROP a reference field (the row
+  lands without its association and the row counters stay clean — framework#3932),
+  and the two write-failure catches on the sequential/update paths. The two
+  dropped-reference lines also gained the consequence and fix in the message.
+- Deliberately left at `warn`, and now documented as audited: "Halting on first
+  error" (a control-flow notice about failures already reported at `error`), the
+  `NODE_ENV` scope warning (a functional, fail-open degradation), and the
+  roll-up-summary recompute (records *were* written; whether a stale summary
+  column is the same class is #4998).
+- The seam is now pinned by CI, not only by tests: the back-fill write was
+  extracted as `writeDeferredReference` and added — with `writeRecord` — to
+  `DURABILITY_CRITICAL_CALLEES` in `scripts/check-durability-degradation-log-level.mjs`,
+  so `pnpm check:durability-log-level` fails if either catch is ever quietened
+  again.
+
+No API, schema or result-object change: the same errors are reported in
+`SeedLoaderResult` exactly as before. What changed is the level and the wording
+of what a seeding host sees in its log.

packages/metadata-protocol/src/seed-loader-deferred-failure.test.ts

@@ -186,6 +186,86 @@ describe('seed deferred back-fill failure is reported, not swallowed (framework#
     expect(result.errors.some((e: { field: string }) => e.field === 'head_id')).toBe(true);
   });
 
+  /**
+   * #4729 — the LOG LEVEL has to agree with the count.
+   *
+   * The comment above this catch has always said the failure "must be a
+   * reported, counted error, never a silent warning", and `recordDeferredError`
+   * duly counts it — but the call underneath it was `logger.warn`, i.e. the
+   * level #4420 proved nobody reads, on the ONE line this failure leaves in a
+   * seed's console output. AGENTS.md → "Degradation log levels" also requires
+   * that line to carry the consequence and the fix, not just a label.
+   */
+  it('logs the failed back-fill at ERROR, naming object.field, the NULL consequence and the remedy (#4729)', async () => {
+    const { engine, store } = createFaithfulEngine();
+    const metadata = createMetadata();
+    const logger = createLogger();
+
+    const realUpdate = (engine.update as any).getMockImplementation();
+    (engine.update as any).mockImplementation(async (obj: string, data: any, opts: any) => {
+      if (obj === 'audit_department') throw new Error('UPDATE rejected by validation rule');
+      return realUpdate(obj, data, opts);
+    });
+
+    const result = await new SeedLoaderService(engine, metadata, logger).load({
+      seeds: SEEDS,
+      config: CONFIG,
+    });
+
+    // The reference genuinely did not land.
+    expect(store.audit_department.find((r) => r.name === 'Engineering')!.head_id == null).toBe(true);
+
+    const line = logger.error.mock.calls
+      .map((c: unknown[]) => String(c[0]))
+      .find((m: string) => m.includes('audit_department.head_id'));
+    expect(line, 'the failed back-fill was not reported at error level').toBeDefined();
+
+    // The consequence, concretely: which reference stays NULL, and that
+    // everything else looks fine.
+    expect(line).toContain('stays NULL');
+    expect(line).toContain('HALF-WRITTEN');
+    expect(line).toContain('audit_worker.name');
+    // The fix.
+    expect(line).toMatch(/re-run the seed/);
+    // The cause travels on the same line (a `warn` reader is not owed a second look).
+    expect(line).toContain('UPDATE rejected by validation rule');
+    // The structured error object is passed through for the logger's own
+    // error rendering, per the `Logger` contract's `(message, error, meta)`.
+    const [, err, meta] = logger.error.mock.calls.find((c: unknown[]) =>
+      String(c[0]).includes('audit_department.head_id'),
+    )!;
+    expect(err).toBeInstanceOf(Error);
+    expect(meta).toMatchObject({ object: 'audit_department', field: 'head_id' });
+
+    // NOT at warn — the level this issue exists to correct.
+    expect(
+      logger.warn.mock.calls.some((c: unknown[]) => String(c[0]).includes('deferred reference')),
+      'the back-fill failure is still being reported at warn',
+    ).toBe(false);
+
+    // …and it is still COUNTED, which is what the level now agrees with.
+    expect(result.success).toBe(false);
+    expect(result.summary.totalErrored).toBeGreaterThan(0);
+    expect(result.errors.some((e: { field: string }) => e.field === 'head_id')).toBe(true);
+  });
+
+  it('a back-fill that SUCCEEDS logs nothing loud (#4729 — do not train readers to skim `error`)', async () => {
+    const { engine, store } = createFaithfulEngine();
+    const metadata = createMetadata();
+    const logger = createLogger();
+
+    const result = await new SeedLoaderService(engine, metadata, logger).load({
+      seeds: SEEDS,
+      config: CONFIG,
+    });
+
+    const aliceId = store.audit_worker.find((r) => r.name === 'Alice')!.id;
+    expect(store.audit_department.find((r) => r.name === 'Engineering')!.head_id).toBe(aliceId);
+    expect(result.success).toBe(true);
+    expect(logger.error).not.toHaveBeenCalled();
+    expect(logger.warn).not.toHaveBeenCalled();
+  });
+
   it('a transient blip that recovers on retry still reports clean success', async () => {
     const { engine, store } = createFaithfulEngine();
     const metadata = createMetadata();

packages/metadata-protocol/src/seed-loader-multi-value-reference.test.ts

@@ -276,7 +276,14 @@ describe('seed reference resolution — multi-value lookup (multiple: true)', ()
     // The unwritable value never reaches the driver; the record still lands.
     expect(store.book[0].reviewer).toBeUndefined();
     expect(store.book[0].name).toBe('Refactoring');
-    expect(logger.warn).toHaveBeenCalled();
+    // #4729: the row landed WITHOUT its association and the row counters stay
+    // clean, so this is reported at `error` — the one level a reader of the
+    // console is not trained to skim — and the line says what was lost.
+    const dropped = logger.error.mock.calls.map((c: any[]) => String(c[0])).find((m: string) => m.includes('reviewer'));
+    expect(dropped, 'the dropped reference was not reported at error level').toBeDefined();
+    expect(dropped).toContain('DROPPED');
+    expect(dropped).toContain('re-run the seed');
+    expect(logger.warn).not.toHaveBeenCalled();
 
     // framework#3932: the row WAS written, so `errored` stays 0 and the row
     // counters all look healthy — the loss only shows up here.