diff --git a/.changeset/filewatch-degraded-not-announced.md b/.changeset/filewatch-degraded-not-announced.md new file mode 100644 index 0000000000..85e7a49d9a --- /dev/null +++ b/.changeset/filewatch-degraded-not-announced.md @@ -0,0 +1,50 @@ +--- +"@objectstack/metadata": patch +--- + +fix(metadata): an unreadable file is no longer announced as `data: null` (#5228) + +`NodeMetadataManager.handleFileEvent()` — the chokidar handler behind +`watch: true` — wrapped its re-read in a `try/catch` that logged +"Failed to load changed file" and returned without announcing. That `catch` was +**unreachable for the failure it was written to catch**. `load()` is +`(await loadDiagnosed(...)).data`, and `loadDiagnosed` (ADR-0110 D3) +deliberately absorbs a loader throw: it records the message in `errors[]` and +answers `{ data: null, degraded: true }`. `FilesystemLoader.load()` does throw +on an unparseable file — the throw simply died one frame below the handler, so +the `catch` never ran and the `logger.error` inside it never printed once. + +What went out instead was a watch event carrying `data: null`, which is the wire +shape of "this metadata legitimately holds nothing". A file the loader could not +read and a file the author had emptied reached every subscriber in exactly the +same shape — the miss/outage distinction ADR-0110 D3 exists to preserve, erased +at the one call site that had picked the variant which throws it away. + +The handler now reads through `loadDiagnosed` and splits on `degraded`: + +- **Degraded** (a loader threw and none answered — an unreadable or unparseable + file): take the road the dead `catch` meant to take. Log `filePath`, the + metadata type and name, and `loadDiagnosed`'s `errors[]`, and announce + nothing. A developer who breaks a metadata file now gets told; before, the + event claimed the definition had been emptied and nothing was logged. +- **Clean miss** (`data: null`, no loader threw — the file is gone or + legitimately empty): unchanged, announced exactly as before. +- **Deleted** events never read, so a deletion can never be degraded and is + always announced. + +Cache invalidation is unaffected and deliberately runs **before** the read, so +the read's verdict can never decide whether the caches are dropped. #5218's +contract holds in full: an unreadable file is still a real change to the stored +set (`loadMany` skips it), so `listCache` and the `registry` entry still go, and +the `api` endpoint index still rebuilds — `invalidateListCache` is that index's +first invalidation seam (#5089), so suppressing the announcement costs it +nothing. + +No in-repo subscriber loses invalidation or reload correctness: the endpoint +index is covered by the seam above, `ObjectQLPlugin`'s `subscribe('object', …)` +answers events by re-reading (an unreadable file yields nothing to re-read +either way), and the email-template bridge falls through `event.data ?? get(...)` +to the same empty result. One behaviour does change for the dev HMR/SSE stream: +a file left permanently unparseable no longer wakes the Studio, which keeps +showing the last known-good definition until the next event instead of watching +it vanish. diff --git a/packages/metadata/src/node-metadata-manager-degraded-file-event.test.ts b/packages/metadata/src/node-metadata-manager-degraded-file-event.test.ts new file mode 100644 index 0000000000..dae08096ff --- /dev/null +++ b/packages/metadata/src/node-metadata-manager-degraded-file-event.test.ts @@ -0,0 +1,270 @@ +// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license. + +/** + * #5228 — a file the loader cannot read must not be announced as `data: null`. + * + * `NodeMetadataManager.handleFileEvent()` used to wrap its re-read in a + * `try/catch` that logged "Failed to load changed file" and returned without + * announcing. That `catch` was unreachable for the failure it was written to + * catch: `load()` is `(await loadDiagnosed(...)).data`, and `loadDiagnosed` + * (ADR-0110 D3) absorbs a loader throw into `{ data: null, degraded: true }` + * rather than rethrowing. `FilesystemLoader.load()` does throw on an + * unparseable file — the throw simply died one frame below the handler. + * + * So an unreadable file was announced with `data: null`, which is the wire + * shape of "this metadata legitimately holds nothing": a miss and an outage, + * the two facts ADR-0110 D3 exists to keep apart, arrived at every subscriber + * in exactly the same shape. The fix reads through `loadDiagnosed` and splits + * on `degraded`. + * + * **What each case discriminates.** Reverting the fix turns the "no watcher is + * notified" cases red — the old handler announced `data: null` there. The + * invalidation half is the *other* direction and is why it is asserted in the + * same case rather than its own: a fix that returned before invalidating would + * also produce "no event", so only "no event AND the caches went" rules out + * both the pre-fix handler and the naive fix. #5218's own regression case + * ("still invalidates when the changed file cannot be parsed") is green on both + * sides of this change and therefore discriminates nothing here — its note was + * corrected, not its assertions. + * + * **Test approach** matches `node-metadata-manager-fs-invalidation.test.ts`: + * synthetic events into the real handler, over real files in a real tmpdir, + * read by the real default `FilesystemLoader`. Only the chokidar notification + * is synthesized; #5218's end-to-end case already pins that chokidar reaches + * the handler at all. + */ + +import { describe, it, expect, vi, beforeEach, afterEach } from 'vitest'; +import * as fs from 'node:fs/promises'; +import * as os from 'node:os'; +import * as path from 'node:path'; +import type { MetadataWatchEvent } from '@objectstack/spec/system'; +import { NodeMetadataManager } from './node-metadata-manager.js'; +import type { MetadataManager } from './metadata-manager.js'; + +// Hoisted so the `vi.mock` factory below (which vitest evaluates during the +// import phase) can close over a logger that already exists. A plain +// module-level `const` would be in its TDZ at that point. +const { logger } = vi.hoisted(() => ({ + logger: { + info: vi.fn(), + warn: vi.fn(), + error: vi.fn(), + debug: vi.fn(), + }, +})); + +vi.mock('@objectstack/core', () => ({ + createLogger: () => logger, +})); + +let rootDir: string; +const managers: NodeMetadataManager[] = []; + +beforeEach(async () => { + vi.clearAllMocks(); + rootDir = await fs.mkdtemp(path.join(os.tmpdir(), 'os-5228-')); +}); + +afterEach(async () => { + for (const mgr of managers.splice(0)) await mgr.stopWatching(); + await fs.rm(rootDir, { recursive: true, force: true }); +}); + +/** Write `rootDir//.json`, returning the absolute path. */ +async function writeMetadataFile( + type: string, + name: string, + data: Record, +): Promise { + const dir = path.join(rootDir, type); + await fs.mkdir(dir, { recursive: true }); + const filePath = path.join(dir, `${name}.json`); + await fs.writeFile(filePath, JSON.stringify(data), 'utf-8'); + return filePath; +} + +/** Write `rootDir//.json` with a body no serializer can parse. */ +async function writeUnparseableFile(type: string, name: string): Promise { + const dir = path.join(rootDir, type); + await fs.mkdir(dir, { recursive: true }); + const filePath = path.join(dir, `${name}.json`); + await fs.writeFile(filePath, '{ not json', 'utf-8'); + return filePath; +} + +function makeManager(): NodeMetadataManager { + // No `loaders`, so the constructor installs the default FilesystemLoader + // over `rootDir` — the real read path this issue is about. + const mgr = new NodeMetadataManager({ rootDir, watch: false, formats: ['json'] }); + managers.push(mgr); + return mgr; +} + +function fireFileEvent( + mgr: NodeMetadataManager, + eventType: 'added' | 'changed' | 'deleted', + filePath: string, +): Promise { + return ( + mgr as unknown as { + handleFileEvent(t: 'added' | 'changed' | 'deleted', p: string): Promise; + } + ).handleFileEvent(eventType, filePath); +} + +/** Collect every event announced for `type`. */ +function record(mgr: NodeMetadataManager, type: string): MetadataWatchEvent[] { + const seen: MetadataWatchEvent[] = []; + mgr.subscribe(type, (evt) => { seen.push(evt); }); + return seen; +} + +/** Read the private list cache without waiting on any async seam. */ +const cachedTypes = (mgr: MetadataManager): string[] => + Array.from((mgr as unknown as { listCache: Map }).listCache.keys()); + +/** The "Failed to load changed file" calls, newest last. */ +const loadFailureLogs = (): Record[] => + logger.error.mock.calls + .filter((call) => call[0] === 'Failed to load changed file') + .map((call) => call[2] as Record); + +const view = (name: string, title = name) => ({ name, title, object: 'account' }); + +const viewNames = (items: unknown[]): string[] => + (items as { name: string }[]).map((v) => v.name).sort(); + +describe('#5228 — a degraded read is not announced', () => { + it('announces nothing, and drops the caches anyway', async () => { + await writeMetadataFile('view', 'v_a', view('v_a')); + const mgr = makeManager(); + await mgr.list('view'); // pre-warm + expect(cachedTypes(mgr)).toEqual(['view']); + + const seen = record(mgr, 'view'); + const broken = await writeUnparseableFile('view', 'v_broken'); + await fireFileEvent(mgr, 'added', broken); + + // Before the fix this was one event carrying `data: null` — the file + // the loader could not read, announced as a file the author emptied. + expect(seen).toEqual([]); + + // …and the #5218 contract is untouched by the early return: an + // unreadable file IS a real change to the stored set (`loadMany` skips + // it), so the caches must age out regardless of the read's verdict. + // Asserting both here is deliberate — "no event" alone would also hold + // for a fix that returned before invalidating. + expect(cachedTypes(mgr)).toEqual([]); + expect(viewNames(await mgr.list('view'))).toEqual(['v_a']); + }); + + it('finally reaches the logger.error that never printed once', async () => { + const mgr = makeManager(); + const broken = await writeUnparseableFile('view', 'v_broken'); + + await fireFileEvent(mgr, 'changed', broken); + + expect(loadFailureLogs()).toHaveLength(1); + expect(loadFailureLogs()[0]).toMatchObject({ + filePath: broken, + metadataType: 'view', + name: 'v_broken', + }); + // `errors[]` is what `loadDiagnosed` collected — the loader name plus + // its message. Without it the log names a file and no cause. + const errors = loadFailureLogs()[0]!.errors as string[]; + expect(errors).toHaveLength(1); + expect(errors[0]).toContain('filesystem:'); + }); + + it('keeps a legitimate miss on its existing semantics — announced, data null', async () => { + // Not degraded: every loader answered, none had the item (the file was + // already gone by the time the event was drained). That is the fact + // `data: null` is the correct wire shape for, so this path is + // untouched — announced exactly as before. + const mgr = makeManager(); + const seen = record(mgr, 'view'); + + const vanished = path.join(rootDir, 'view', 'v_vanished.json'); + await fs.mkdir(path.dirname(vanished), { recursive: true }); + await fireFileEvent(mgr, 'changed', vanished); + + expect(seen).toHaveLength(1); + expect(seen[0]!.data).toBeNull(); + expect(loadFailureLogs()).toEqual([]); + }); + + it('announces a readable file with its parsed body', async () => { + const mgr = makeManager(); + const seen = record(mgr, 'view'); + + const added = await writeMetadataFile('view', 'v_b', view('v_b', 'fresh')); + await fireFileEvent(mgr, 'added', added); + + expect(seen).toHaveLength(1); + expect(seen[0]!.data).toMatchObject({ name: 'v_b', title: 'fresh' }); + expect(loadFailureLogs()).toEqual([]); + }); + + it('never reads on a deleted event, so a deletion can never be degraded', async () => { + // The file left behind here is unparseable. If `deleted` consulted the + // loader at all it would come back degraded and be swallowed — and a + // deletion that nobody announces is the one loss this change must not + // introduce. `data` stays `undefined` (nothing was read), which is + // distinct from the `null` a miss carries. + const mgr = makeManager(); + const seen = record(mgr, 'view'); + + const broken = await writeUnparseableFile('view', 'v_gone'); + await fireFileEvent(mgr, 'deleted', broken); + + expect(seen).toHaveLength(1); + expect(seen[0]!.type).toBe('deleted'); + expect(seen[0]!.data).toBeUndefined(); + expect(loadFailureLogs()).toEqual([]); + }); +}); + +/** + * The one in-repo subscriber whose job is pure invalidation — the endpoint + * index (#5089) — keeps working without the broadcast, because it has a second + * seam that does not go through a watcher. This is the case that makes + * "degraded means no announcement" safe rather than merely quiet. + */ +describe('#5228 — a degraded `api` event still invalidates the endpoint index', () => { + const endpoint = (name: string, urlPath: string) => ({ + name, + path: urlPath, + method: 'GET', + type: 'object_operation', + target: 'showcase_task', + objectParams: { object: 'showcase_task', operation: 'find' }, + }); + + it('rebuilds the index through invalidateListCache, not through subscribe()', async () => { + await writeMetadataFile('api', 'list_tasks', endpoint('list_tasks', '/api/v1/apps/showcase/tasks')); + const mgr = makeManager(); + + // Build the index, so a stale one would be observable. + expect(await mgr.matchEndpoint({ method: 'GET', path: '/api/v1/apps/showcase/tasks' })) + .toMatchObject({ endpoint: { name: 'list_tasks' } }); + + // A second declaration lands on disk without an event of its own — an + // editor writing two files, one of which is caught mid-save. + await writeMetadataFile('api', 'list_users', endpoint('list_users', '/api/v1/apps/showcase/users')); + const broken = await writeUnparseableFile('api', 'half_written'); + const announced = record(mgr, 'api'); + await fireFileEvent(mgr, 'added', broken); + + // No announcement, so `subscribe('api', … endpointMatcher.invalidate())` + // never ran. `invalidateForForeignWrite` → `invalidateListCache('api')` + // — the index's FIRST seam, the one that already covers the + // `{ notify: false }` writes — carried it. + expect(announced).toEqual([]); + expect(await mgr.matchEndpoint({ method: 'GET', path: '/api/v1/apps/showcase/users' })) + .toMatchObject({ endpoint: { name: 'list_users' } }); + expect(await mgr.matchEndpoint({ method: 'GET', path: '/api/v1/apps/showcase/tasks' })) + .toMatchObject({ endpoint: { name: 'list_tasks' } }); + }); +}); diff --git a/packages/metadata/src/node-metadata-manager-fs-invalidation.test.ts b/packages/metadata/src/node-metadata-manager-fs-invalidation.test.ts index d7f11fc39d..8da04f18e2 100644 --- a/packages/metadata/src/node-metadata-manager-fs-invalidation.test.ts +++ b/packages/metadata/src/node-metadata-manager-fs-invalidation.test.ts @@ -232,13 +232,18 @@ describe('#5218 — an FS change invalidates the local listCache', () => { // An unparseable file is a real change to the stored set — `loadMany` // skips it, so the cached list is stale either way and must go. // - // Note the handler does NOT take its `catch` here: `load()` delegates - // to `loadDiagnosed`, which absorbs a loader throw into - // `{ data: null, degraded: true }` and returns `null` rather than - // rethrowing. So the early-return guards nothing in this case and the - // event is announced with `data: null`. That announcement is its own - // (pre-existing, out-of-scope) problem — filed separately; this test - // pins only that the invalidation happens. + // This case was written expecting the handler's `catch` to fire and + // return early; it does not, and finding out why is what became #5228. + // `load()` delegates to `loadDiagnosed`, which absorbs a loader throw + // into `{ data: null, degraded: true }` rather than rethrowing, so the + // `catch` was unreachable and the event went out claiming the view was + // empty. #5228 fixed the announcement (degraded now reads through + // `loadDiagnosed` and announces nothing — see + // `node-metadata-manager-degraded-file-event.test.ts`) and moved the + // invalidation ABOVE the read so this contract survived it. What this + // case pins is unchanged and deliberately narrow: whatever the read + // says, the caches go. It is green on both sides of #5228, which is + // exactly why that change needed pins of its own. await writeMetadataFile('view', 'v_a', view('v_a')); const mgr = makeManager(); await mgr.list('view'); diff --git a/packages/metadata/src/node-metadata-manager.ts b/packages/metadata/src/node-metadata-manager.ts index a9e2807f50..91ba17c672 100644 --- a/packages/metadata/src/node-metadata-manager.ts +++ b/packages/metadata/src/node-metadata-manager.ts @@ -101,35 +101,15 @@ export class NodeMetadataManager extends MetadataManager { const fileName = parts[parts.length - 1]; const name = path.basename(fileName, path.extname(fileName)); - let data: any = undefined; - if (eventType !== 'deleted') { - try { - data = await this.load(type, name, { useCache: false }); - } catch (error) { - this.logger.error('Failed to load changed file', undefined, { - filePath, - error: error instanceof Error ? error.message : String(error), - }); - return; - } - } - - const event: MetadataWatchEvent = { - type: eventType, - metadataType: type, - name, - path: filePath, - data, - timestamp: new Date().toISOString(), - }; - - // [#5218] Invalidate BEFORE announcing. A file event is a *foreign write* - // in the precise sense {@link MetadataManager.invalidateForForeignWrite} - // means: it did not come through this manager's write API, so — unlike - // `register()` / `unregister()` — nothing has refreshed the caches on its - // behalf. `load()` above is a pure read (it delegates to `loadDiagnosed`, - // which only walks the loaders), so before this call the handler left both - // `listCache` and `registry` holding the pre-change state. + // [#5218] Invalidate BEFORE announcing — and, since #5228, before reading + // too, so that the read's verdict can never decide whether the caches are + // dropped. A file event is a *foreign write* in the precise sense + // {@link MetadataManager.invalidateForForeignWrite} means: it did not come + // through this manager's write API, so — unlike `register()` / + // `unregister()` — nothing has refreshed the caches on its behalf. The + // read below is pure (it only walks the loaders and writes neither cache), + // so before this call the handler left both `listCache` and `registry` + // holding the pre-change state. // // Without it, editing `rootDir/view/x.json` left the two read surfaces // contradicting each other for up to LIST_CACHE_TTL_MS (30s): `get()` saw @@ -154,6 +134,59 @@ export class NodeMetadataManager extends MetadataManager { // forever. Deleted, never pre-filled from `data`, per the helper's contract. this.invalidateForForeignWrite(type, name); + // [#5228] `loadDiagnosed`, not `load` — and the difference is the whole + // point of this branch. `load()` is `(await loadDiagnosed(...)).data`, and + // `loadDiagnosed` (ADR-0110 D3) ABSORBS a loader throw: it records the + // message in `errors[]` and answers `{ data: null, degraded: true }`. + // `FilesystemLoader.load()` does throw on an unreadable / unparseable + // file, but that throw dies inside `loadDiagnosed`, so the `try/catch` + // this handler used to wrap `load()` in was unreachable for exactly the + // failure it was written to catch. The handler announced `data: null` + // instead, and its `logger.error` never printed once. + // + // `data: null` is the wire-shape of "this metadata legitimately holds + // nothing" — so a file the loader could not read was announced as a file + // the author had emptied. Those are the two facts ADR-0110 D3 exists to + // keep apart (a miss and an outage mean opposite things), and this call + // site was using the variant that throws the distinction away. + // + // So: split on `degraded`. An outage takes the road the dead `catch` meant + // to take — log loudly, announce nothing. A clean miss (`data: null`, no + // loader threw: the file is gone or legitimately empty) keeps its existing + // semantics and is announced as before. + // + // Note what deliberately does NOT move with the early return: the + // invalidation above. An unreadable file is still a real change to the + // stored set — `loadMany` skips it, so `list()` genuinely answers + // differently than it did — and #5218's contract is that a file event + // always ages out the caches. That is also what keeps the `api` endpoint + // index correct on this path without a broadcast: `invalidateListCache` + // is the index's first invalidation seam (#5089), so suppressing the + // `subscribe('api', …)` seam costs nothing. + let data: unknown = undefined; + if (eventType !== 'deleted') { + const read = await this.loadDiagnosed(type, name, { useCache: false }); + if (read.degraded) { + this.logger.error('Failed to load changed file', undefined, { + filePath, + metadataType: type, + name, + errors: read.errors, + }); + return; + } + data = read.data; + } + + const event: MetadataWatchEvent = { + type: eventType, + metadataType: type, + name, + path: filePath, + data, + timestamp: new Date().toISOString(), + }; + this.notifyWatchers(type, event); } }