diff --git a/DESIGN.md b/DESIGN.md index 276e5ac32a..ecc83e5cc0 100644 --- a/DESIGN.md +++ b/DESIGN.md @@ -1248,3 +1248,27 @@ absolute paths built from `cwd`, so its bases must be derived from the same spel paths are relative to `cwd` and reads stay on the configured `component.directory`. And a watcher that degrades to polling stays there for its lifetime, so a caller with no polling story of its own (`resources/blob.ts`) needs one — there it polls `readMore` on the existing no-progress deadline. + +## No descriptor on the root config may outlive a turn (`config/configUtils.ts`, `config/RootConfigWatcher.ts`, `components/OptionsWatcher.ts`) + +`atomicWriteFile` replaces `harper-config.yaml` by rename-over and retries `EPERM`/`EACCES` with a +synchronous `Atomics.wait`. On Windows a rename over an open destination fails, and a descriptor +belongs to the process, not the thread — measured on `windows-latest`/Node 24: a single Node read +descriptor on the destination blocks it, while `fs.watch` and chokidar handles do not. + +That makes the retry unable to outlast a holder on the _calling_ thread, because the sleep blocks +the event loop whose turn would close it: the holder's lifetime becomes exactly the retry budget +and every attempt fails. This is why widening the budget (#1714, #2036) never fixed the +`set_configuration` 500s it was aimed at, and why both root-config watchers read with +`readFileSync`. Any future `fsPromises.readFile` of this file reintroduces harper#2313 — the rule +is unenforced by anything but this note and the comment on `atomicWriteFile`. + +The synchronous read then sees writers mid-write, which promise-based reads mostly skipped. A read +that is unusable — empty, or parsing to anything but an object — is retried by `PartialReadRetry` +(`utility/watcherFallback.ts`) rather than adopted, because chokidar may emit nothing further for +that write. Completeness is judged on the file's own parse, _before_ `overlayRootEnvConfig`, which +returns a non-null object whenever a config env var is set and would otherwise launder a +half-written file into a valid-looking env-only config. Its three outcomes are distinct and each +one matters: a usable read withdraws the file's give-up report and restores the budget; giving up +restores the budget (the write that repairs the file can itself be read mid-write) but leaves the +report standing, since it is shared with every other watcher of that file; closing is terminal. diff --git a/components/OptionsWatcher.ts b/components/OptionsWatcher.ts index f4f16be3d2..7f84dfe6f5 100644 --- a/components/OptionsWatcher.ts +++ b/components/OptionsWatcher.ts @@ -4,10 +4,17 @@ import { EventEmitter, once } from 'events'; import yaml from 'yaml'; import chokidar, { type FSWatcher } from 'chokidar'; import { readFile } from 'node:fs/promises'; +import { readFileSync } from 'node:fs'; import { isDeepStrictEqual } from 'util'; import { DEFAULT_CONFIG } from './DEFAULT_CONFIG.ts'; import { cloneDeep } from 'lodash'; -import { POLLING_FALLBACK_OPTIONS, isWatcherExhaustionError, warnWatcherFallback } from '../utility/watcherFallback.ts'; +import { + POLLING_FALLBACK_OPTIONS, + PartialReadRetry, + isPartialReadError, + isWatcherExhaustionError, + warnWatcherFallback, +} from '../utility/watcherFallback.ts'; import { resolveWatchTarget } from '../utility/watchPath.ts'; import { overlayRootEnvConfig, isRootConfigFilename } from '../config/harperConfigEnvVars.ts'; @@ -96,6 +103,7 @@ export class OptionsWatcher extends EventEmitter { #closed: boolean; #openCount: number = 0; #pendingReads: Set> = new Set(); + #partialRead: PartialReadRetry; ready: Promise; constructor(name: string, filePath: string, logger?: Logger, isRootConfig?: boolean) { @@ -104,6 +112,7 @@ export class OptionsWatcher extends EventEmitter { this.#filePath = filePath; const watchTarget = resolveWatchTarget(filePath); this.#watchPath = watchTarget.path; + this.#partialRead = new PartialReadRetry(filePath); // Root-config watchers must see runtime env config (HARPER_SET_CONFIG et al.) // even when it hasn't been flushed to disk yet — see #handleChange (#1618). // Application scopes watch their own config.yaml and are never overlaid. @@ -129,72 +138,123 @@ export class OptionsWatcher extends EventEmitter { .on('ready', this.#handleChange.bind(this)); } + // Root config only: see the descriptor-lifetime invariant on atomicWriteFile (DESIGN.md). #handleChange() { + if (this.#isRootConfig) { + this.#applyRead(() => readFileSync(this.#filePath, 'utf-8')); + return; + } const read: Promise = readFile(this.#filePath, 'utf-8') - .then((contents) => { - let parsed = yaml.parse(contents); - // The on-disk root config is not guaranteed to include runtime env config at - // boot: the file flush races component loading, so a scope's boot-time reads - // (e.g. an `enabled` gate in handleApplication) could observe pre-env values - // the componentLoader itself never saw. Ask the config layer to overlay env - // config onto EVERY root-config read so scope.options matches the resolved - // view (#1618). Non-root scopes and the no-env-vars case are untouched - // (overlayRootEnvConfig is a no-op there). - if (this.#isRootConfig) parsed = overlayRootEnvConfig(parsed); - this.#rootConfig = parsed && typeof parsed === 'object' ? parsed : undefined; - // If the extension is in the config file - if (this.#rootConfig && this.#name in this.#rootConfig) { - // If a config object does not exist - if (!this.#scopedConfig) { - // set it - this.#scopedConfig = this.#rootConfig[this.#name]; - // and emit a ready event - this.emit('ready', this.#scopedConfig); - } else { - // Otherwise, merge the new config with the old config - this.#merge(this.#rootConfig[this.#name], this.#scopedConfig); - } - } else { - // Otherwise, if the extension is not in the config file - // This means the plugin was removed from the config file - if (this.#scopedConfig) { - // and a config exists, remove it - this.#scopedConfig = undefined; - this.emit('remove'); - } - // Otherwise do nothing - the user may add the config back in later - } - }) - .catch((error) => { - // If the config file does not exist - if (error instanceof Error && 'code' in error && error.code === 'ENOENT') { - // A readFile ENOENT here is the install window (file not written yet) or a - // transient read race — NOT a real deletion, which chokidar routes to - // `#handleUnlink`. Env config is file-independent, so when it provides this - // scope the missing file must not discard it (#1618). When it does not, fall - // through to the original ENOENT handling with #rootConfig untouched, so a - // first boot still emits `ready` (not `remove`, which nothing consumes at - // boot → `ready` would hang forever). - if (this.#applyEnvOnlyConfig()) return; - // And a config already exists, reset it to the default - if (this.#rootConfig) { - this.#resetConfig(); - this.emit('remove'); - } else { - // Otherwise, if no config exists, then just set to default and emit ready - this.#resetConfig(); - this.emit('ready'); - } - return; - } - this.emit('error', error); - }) + .then((contents) => this.#applyRead(() => contents)) + .catch((error) => this.#recoverOrReport(error)) .finally(() => { this.#pendingReads.delete(read); }); this.#pendingReads.add(read); } + #applyRead(read: () => string) { + let parsed; + try { + parsed = yaml.parse(read()); + } catch (error) { + // A read or parse that fails while the file is being replaced is the same event as an + // incomplete one, and #handleReadError's ENOENT arm would answer it with a `remove` + // that restarts the scope. Re-read first; only an exhausted budget means it is real. + this.#recoverOrReport(error); + return; + } + // Tested on the file's own parse, before any env overlay: `''`, `'\n'` and a truncated + // document all parse to null, and an env-configured deployment would otherwise overlay + // one into a valid-looking object and adopt it. A file that is still unusable once the + // budget is spent is taken at face value, so emptying one still reaches `remove`. + if (!parsed || typeof parsed !== 'object') { + if (this.#partialRead.schedule(() => this.#handleChange())) return; + this.#partialRead.gaveUp(); + } else { + this.#partialRead.settled(); + } + try { + this.#applyParsed(this.#overlayEnvConfig(parsed)); + } catch (error) { + // Applying is past the point where an incomplete file could explain a failure, so a + // listener's throw keeps the error route rather than being retried. + this.emit('error', error); + } + } + + #recoverOrReport(error: unknown) { + if (!isPartialReadError(error)) return this.#handleReadError(error); + if (this.#partialRead.schedule(() => this.#handleChange())) return; + // Same give-up as the unusable-parse case, so the budget is restored for the repair: the + // write that fixes the file can itself be read mid-write. The error still takes the + // scope's own route. + this.#partialRead.gaveUp(error); + this.#handleReadError(error); + } + + #overlayEnvConfig(parsed: unknown) { + // The on-disk root config is not guaranteed to include runtime env config at + // boot: the file flush races component loading, so a scope's boot-time reads + // (e.g. an `enabled` gate in handleApplication) could observe pre-env values + // the componentLoader itself never saw. Ask the config layer to overlay env + // config onto EVERY root-config read so scope.options matches the resolved + // view (#1618). Non-root scopes and the no-env-vars case are untouched + // (overlayRootEnvConfig is a no-op there). + return this.#isRootConfig ? overlayRootEnvConfig(parsed) : parsed; + } + + #applyParsed(parsed: unknown) { + this.#rootConfig = parsed && typeof parsed === 'object' ? (parsed as Config) : undefined; + // If the extension is in the config file + if (this.#rootConfig && this.#name in this.#rootConfig) { + // If a config object does not exist + if (!this.#scopedConfig) { + // set it + this.#scopedConfig = this.#rootConfig[this.#name]; + // and emit a ready event + this.emit('ready', this.#scopedConfig); + } else { + // Otherwise, merge the new config with the old config + this.#merge(this.#rootConfig[this.#name], this.#scopedConfig); + } + } else { + // Otherwise, if the extension is not in the config file + // This means the plugin was removed from the config file + if (this.#scopedConfig) { + // and a config exists, remove it + this.#scopedConfig = undefined; + this.emit('remove'); + } + // Otherwise do nothing - the user may add the config back in later + } + } + + #handleReadError(error: unknown) { + // If the config file does not exist + if (error instanceof Error && 'code' in error && error.code === 'ENOENT') { + // A readFile ENOENT here is the install window (file not written yet) or a + // transient read race — NOT a real deletion, which chokidar routes to + // `#handleUnlink`. Env config is file-independent, so when it provides this + // scope the missing file must not discard it (#1618). When it does not, fall + // through to the original ENOENT handling with #rootConfig untouched, so a + // first boot still emits `ready` (not `remove`, which nothing consumes at + // boot → `ready` would hang forever). + if (this.#applyEnvOnlyConfig()) return; + // And a config already exists, reset it to the default + if (this.#rootConfig) { + this.#resetConfig(); + this.emit('remove'); + } else { + // Otherwise, if no config exists, then just set to default and emit ready + this.#resetConfig(); + this.emit('ready'); + } + return; + } + this.emit('error', error); + } + #handleError(error: unknown) { if (isWatcherExhaustionError(error)) { // Swallow every exhaustion error — chokidar can emit several before the @@ -388,6 +448,14 @@ export class OptionsWatcher extends EventEmitter { this.emit('change', keys, value, this.#scopedConfig); } + // Test-only: run the change handler directly, since the read's timing relative to its caller + // is the behaviour under test and a chokidar event cannot be observed at that granularity. + // Resolves once the read has landed, which for the root config has already happened. + _handleChangeForTests(): Promise { + this.#handleChange(); + return Promise.allSettled([...this.#pendingReads]); + } + // Test-only: simulate the underlying chokidar watcher emitting an error. // Exposed so the polling-fallback path can be exercised without triggering a // real ENOSPC/EMFILE on the host. @@ -414,6 +482,7 @@ export class OptionsWatcher extends EventEmitter { */ close(): Promise { this.#closed = true; + this.#partialRead.cancel(); const pendingReads = [...this.#pendingReads]; const watcherClose = Promise.resolve(this.#watcher.close()).catch(() => {}); diff --git a/config/RootConfigWatcher.ts b/config/RootConfigWatcher.ts index ad247f14ac..6f05ebf7f8 100644 --- a/config/RootConfigWatcher.ts +++ b/config/RootConfigWatcher.ts @@ -1,9 +1,16 @@ import chokidar, { FSWatcher } from 'chokidar'; -import { readFile } from 'node:fs/promises'; +import { readFileSync } from 'node:fs'; import { getConfigFilePath } from './configUtils.ts'; import { EventEmitter, once } from 'node:events'; import { parse } from 'yaml'; -import { POLLING_FALLBACK_OPTIONS, isWatcherExhaustionError, warnWatcherFallback } from '../utility/watcherFallback.ts'; +import { + POLLING_FALLBACK_OPTIONS, + PartialReadRetry, + isPartialReadError, + isWatcherExhaustionError, + warnWatcherFallback, + warnWatcherListenerError, +} from '../utility/watcherFallback.ts'; import { resolveWatchTarget } from '../utility/watchPath.ts'; export class RootConfigWatcher extends EventEmitter { @@ -14,6 +21,7 @@ export class RootConfigWatcher extends EventEmitter { #usingPolling: boolean; #closed: boolean; #openCount: number = 0; + #partialRead: PartialReadRetry; ready: Promise; constructor() { @@ -21,6 +29,7 @@ export class RootConfigWatcher extends EventEmitter { this.#configFilePath = getConfigFilePath(); const watchTarget = resolveWatchTarget(this.#configFilePath); this.#watchPath = watchTarget.path; + this.#partialRead = new PartialReadRetry(this.#configFilePath); this.#usingPolling = watchTarget.mustPoll; this.#closed = false; this.ready = once(this, 'ready'); @@ -81,28 +90,47 @@ export class RootConfigWatcher extends EventEmitter { this.emit('error', error); } + // See the descriptor-lifetime invariant on atomicWriteFile (DESIGN.md). handleChange() { - readFile(this.#configFilePath, 'utf-8') - .then((data) => { - if (!data) return; - - const config = parse(data); + let config; + // Only the read and parse are guarded: a listener that throws must not be mistaken for a + // half-written file and replayed. + try { + config = parse(readFileSync(this.#configFilePath, 'utf-8')); + } catch (error) { + // A missing file needs no re-read; anything else may be the file being replaced. + if (isPartialReadError(error)) this.#scheduleReread(error); + return; + } + // A snapshot that does not parse to an object is the other shape a half-written file + // takes: `''`, `'\n'` and a truncated document all yield null, and adopting that would + // hand every consumer a config with nothing in it. + if (!config || typeof config !== 'object') { + this.#scheduleReread(); + return; + } + this.#partialRead.settled(); - if (!this.#config) { - this.#config = config; - this.emit('ready', this.#config); - return; - } + try { + if (!this.#config) { + this.#config = config; + this.emit('ready', this.#config); + return; + } + this.emit('change', (this.#config = config)); + } catch (error) { + warnWatcherListenerError(this.#configFilePath, error); + } + } - this.emit('change', (this.#config = config)); - }) - .catch((_error) => { - // if yaml parse error ignore? - }); + #scheduleReread(error?: unknown) { + if (this.#partialRead.schedule(() => this.handleChange())) return; + this.#partialRead.gaveUp(error); } close() { this.#closed = true; + this.#partialRead.cancel(); this.#watcher.close(); this.#config = undefined; this.emit('close'); diff --git a/config/configUtils.ts b/config/configUtils.ts index 135ada3dbf..5d485a33b4 100644 --- a/config/configUtils.ts +++ b/config/configUtils.ts @@ -91,14 +91,11 @@ export function getConfigPath(param: string) { // in the same millisecond can't collide on the temp name and then race the rename. // // Windows has no POSIX-style "replace an open file" semantics: rename() fails with -// EPERM/EACCES if another thread/process has the destination momentarily open for read. -// Every worker thread runs its own RootConfigWatcher (chokidar), so a write on one thread -// routinely races a hot-reload read on another; Windows Defender / AV real-time scanning can -// hold a similar transient handle. Retry with exponential backoff to ride out the race - -// callers are synchronous, so the wait is a synchronous sleep rather than an async one. -// The budget must outlast a single AV real-time scan pass (seconds, not hundreds of ms): -// the previous ~910ms budget was exhausted twice in a row by the same test on a CI runner -// (harper#2036), so the worst case is now ~3.6s. +// EPERM/EACCES while another descriptor is open on the destination. The sleep below blocks the +// calling thread, so this can only ride out a holder that releases without needing that +// thread's event loop. A holder on the calling thread would live exactly as long as the budget, +// which is why config readers must not keep a descriptor on this file open across an event-loop +// turn (RootConfigWatcher.handleChange, OptionsWatcher#handleChange). const RENAME_RETRY_MAX_ATTEMPTS = 12; const RENAME_RETRY_INITIAL_DELAY_MS = 10; const RENAME_RETRY_MAX_DELAY_MS = 500; @@ -115,30 +112,41 @@ export function atomicWriteFile( } = {} ) { const tempPath = `${filePath}.${process.pid}.${threadId}.${randomBytes(4).toString('hex')}.tmp`; - fs.writeFileSync(tempPath, content); let retries = maxRetries; let delayMs = initialDelayMs; - while (true) { - try { - fs.renameSync(tempPath, filePath); - break; - } catch (err) { - if (retries > 0 && (err.code === 'EPERM' || err.code === 'EACCES')) { - retries--; - // Sleep synchronously (all call sites are sync) to allow the holder to close the - // file. Atomics.wait yields the thread to the OS instead of spinning the CPU, - // which is what makes a multi-second worst-case budget affordable. - if (delayMs > 0) Atomics.wait(renameRetrySleepBuffer, 0, 0, delayMs); - delayMs = Math.min(delayMs * 2, maxDelayMs); - continue; + let attempts = 0; + const startedAt = Date.now(); + let renamed = false; + try { + // Inside the cleanup boundary: a write that fails partway leaves a partial temp behind. + fs.writeFileSync(tempPath, content); + while (!renamed) { + try { + attempts++; + fs.renameSync(tempPath, filePath); + renamed = true; + } catch (err) { + if (retries > 0 && (err.code === 'EPERM' || err.code === 'EACCES')) { + retries--; + if (delayMs > 0) Atomics.wait(renameRetrySleepBuffer, 0, 0, delayMs); + delayMs = Math.min(delayMs * 2, maxDelayMs); + continue; + } + // Attempts and elapsed distinguish a holder that never released from one that lost + // a race, and neither survives on the rethrown error. + if (err.code === 'EPERM' || err.code === 'EACCES') { + logger.warn( + `Could not replace ${filePath}: ${err.code} after ${attempts} attempts over ${Date.now() - startedAt}ms` + ); + } + throw err; } - // if it fails we should clean up the tmp file + } + } finally { + if (!renamed) { try { fs.unlinkSync(tempPath); - } catch { - // ignore cleanup errors - } - throw err; + } catch {} } } } diff --git a/integrationTests/apiTests/configuration.test.mjs b/integrationTests/apiTests/configuration.test.mjs index ba63039c1f..0a73183e33 100644 --- a/integrationTests/apiTests/configuration.test.mjs +++ b/integrationTests/apiTests/configuration.test.mjs @@ -16,6 +16,7 @@ */ import { suite, test, before, after } from 'node:test'; import assert from 'node:assert'; +import { readdirSync } from 'node:fs'; import request from 'supertest'; import { startHarper, teardownHarper } from '@harperfast/integration-testing'; import { createApiClient } from './utils/client.mjs'; @@ -343,6 +344,37 @@ suite('Configuration', (ctx) => { .expect(200); }); + test('back-to-back set_configuration calls all land', async () => { + // Every config write fans out a re-read to each thread's root-config watcher, and the root + // config is replaced by rename-over, which on Windows fails while any descriptor is open + // on it (harper#2313). + for (const maxSize of ['21M', '22M', '23M', '24M']) { + await client.req().send({ operation: 'set_configuration', logging_rotation_maxSize: maxSize }).expect(200); + } + let rootPath; + await client + .req() + .send({ operation: 'get_configuration' }) + .expect((r) => { + assert.strictEqual(r?.body?.logging?.rotation?.maxSize, '24M', r?.text); + rootPath = r?.body?.rootPath; + }) + .expect(200); + // Concurrent writes maximise the chance that a watcher read is still in flight when the + // next rename starts, which the sequential burst cannot guarantee. Only the status is + // asserted: interleaved read-modify-writes make the surviving value racy. + const concurrent = await Promise.all( + ['31M', '32M', '33M', '34M'].map((maxSize) => + client.req().send({ operation: 'set_configuration', logging_rotation_maxSize: maxSize }) + ) + ); + for (const response of concurrent) assert.strictEqual(response.status, 200, response.text); + assert.deepStrictEqual( + readdirSync(rootPath).filter((entry) => entry.startsWith('harper-config.yaml.') && entry.endsWith('.tmp')), + [] + ); + }); + // ── set_configuration + replicated (#660) ─────────────────────────────── // Real cluster fan-out lives in harper-pro; without it, the base server's // replication stub rejects a truthy `replicated`. These tests pin the diff --git a/unitTests/config/configReadHandleLifetime.test.js b/unitTests/config/configReadHandleLifetime.test.js new file mode 100644 index 0000000000..7b5525cbf2 --- /dev/null +++ b/unitTests/config/configReadHandleLifetime.test.js @@ -0,0 +1,262 @@ +const assert = require('node:assert'); +const { join } = require('node:path'); +const { tmpdir } = require('node:os'); +const { mkdtempSync, writeFileSync, rmSync, mkdirSync } = require('node:fs'); +const { once } = require('node:events'); +const { waitFor } = require('../waitFor'); +const { isPartialReadWarned, clearPartialReadWarning } = require('#src/utility/watcherFallback'); +const { stringify } = require('yaml'); +const { RootConfigWatcher } = require('#src/config/RootConfigWatcher'); +const { OptionsWatcher } = require('#src/components/OptionsWatcher'); +const { HARPER_CONFIG_FILE } = require('#src/utility/hdbTerms'); + +/** + * `atomicWriteFile` replaces the root config by rename-over and retries with a blocking sleep. + * On Windows that rename fails while any descriptor is open on the destination, and the sleep + * blocks the event loop that would close one — so a root-config read that outlives the turn it + * started in makes every retry fail and `set_configuration` return 500 (harper#2313). + * + * These tests pin the lifetime rather than the platform rule: a root-config read must be + * complete by the time the change handler returns. They fail on a `fsPromises.readFile` + * implementation on every platform. + */ +describe('root config read handle lifetime', () => { + let fixture; + let configFilePath; + let previousRootPath; + let previousSetConfig; + const openWatchers = []; + + beforeEach(() => { + fixture = mkdtempSync(join(tmpdir(), 'harper.unit-test.config-read-lifetime-')); + configFilePath = join(fixture, HARPER_CONFIG_FILE); + writeFileSync(configFilePath, stringify({ 'test-component': { enabled: true } })); + previousRootPath = process.env.ROOTPATH; + previousSetConfig = process.env.HARPER_SET_CONFIG; + process.env.ROOTPATH = fixture; + }); + + afterEach(async () => { + await Promise.all(openWatchers.splice(0).map((watcher) => watcher.close())); + if (previousRootPath === undefined) delete process.env.ROOTPATH; + else process.env.ROOTPATH = previousRootPath; + if (previousSetConfig === undefined) delete process.env.HARPER_SET_CONFIG; + else process.env.HARPER_SET_CONFIG = previousSetConfig; + rmSync(fixture, { recursive: true, force: true }); + }); + + it('RootConfigWatcher applies a change before handleChange returns', async () => { + const watcher = new RootConfigWatcher(); + openWatchers.push(watcher); + await watcher.ready; + + writeFileSync(configFilePath, stringify({ 'test-component': { enabled: false } })); + watcher.handleChange(); + + assert.deepStrictEqual( + watcher.config, + { 'test-component': { enabled: false } }, + 'the config must be re-read before control returns, or the descriptor outlives the turn' + ); + }); + + it('RootConfigWatcher swallows a read failure without throwing into the watcher callback', async () => { + const watcher = new RootConfigWatcher(); + openWatchers.push(watcher); + await watcher.ready; + + rmSync(configFilePath); + assert.doesNotThrow(() => watcher.handleChange()); + assert.deepStrictEqual(watcher.config, { 'test-component': { enabled: true } }); + + writeFileSync(configFilePath, ': not: valid: yaml:'); + assert.doesNotThrow(() => watcher.handleChange()); + assert.deepStrictEqual(watcher.config, { 'test-component': { enabled: true } }); + }); + + it('RootConfigWatcher recovers a change it first observed as a half-written file', async () => { + // A synchronous read can catch an in-place writer between its truncate and its write, and + // chokidar may emit nothing further for that write — so an unusable read must be retried + // rather than dropped, or the watcher serves stale config indefinitely. + const watcher = new RootConfigWatcher(); + openWatchers.push(watcher); + await watcher.ready; + + writeFileSync(configFilePath, ''); + watcher.handleChange(); + assert.deepStrictEqual(watcher.config, { 'test-component': { enabled: true } }, 'must not adopt an empty read'); + + const changes = []; + watcher.on('change', (config) => changes.push(config)); + writeFileSync(configFilePath, stringify({ 'test-component': { enabled: false } })); + await once(watcher, 'change'); + await new Promise((resolve) => setTimeout(resolve, 100)); + // The count is not pinned: the armed re-read and chokidar's own event for the same write + // race, and this watcher has never diffed. What must hold is that no emit carries the + // half-written snapshot. + assert.ok(changes.length > 0); + for (const config of changes) assert.deepStrictEqual(config, { 'test-component': { enabled: false } }); + assert.deepStrictEqual(watcher.config, { 'test-component': { enabled: false } }); + }); + + it('RootConfigWatcher stops re-reading a file that never becomes usable', async () => { + const watcher = new RootConfigWatcher(); + openWatchers.push(watcher); + await watcher.ready; + + writeFileSync(configFilePath, ''); + for (let attempt = 0; attempt < 20; attempt++) watcher.handleChange(); + await new Promise((resolve) => setTimeout(resolve, 400)); + + assert.deepStrictEqual(watcher.config, { 'test-component': { enabled: true } }); + }); + + it('OptionsWatcher recovers a root-config read that failed for a reason other than absence', async () => { + const watcher = new OptionsWatcher('test-component', configFilePath, undefined, true); + openWatchers.push(watcher); + await watcher.ready; + + const errors = []; + watcher.on('error', (error) => errors.push(error)); + // A directory in the file's place fails the read with EISDIR, standing in for the + // transient replace-under-us failures Windows produces; the change must not be dropped. + rmSync(configFilePath); + mkdirSync(configFilePath); + watcher._handleChangeForTests(); + assert.deepStrictEqual(errors, [], 'a recoverable read failure must not surface as an error'); + + rmSync(configFilePath, { recursive: true }); + writeFileSync(configFilePath, stringify({ 'test-component': { enabled: false } })); + await once(watcher, 'change'); + assert.strictEqual(watcher.get(['enabled']), false); + }); + + it('OptionsWatcher can still recover after an error-bearing read exhausted its budget', async () => { + const watcher = new OptionsWatcher('test-component', configFilePath, undefined, true); + openWatchers.push(watcher); + await watcher.ready; + watcher.on('error', () => {}); + + // An unreadable file drains the budget on its own: each re-read fails and arms the next. + clearPartialReadWarning(configFilePath); + rmSync(configFilePath); + mkdirSync(configFilePath); + await watcher._handleChangeForTests(); + await waitFor(() => isPartialReadWarned(configFilePath), { message: 'the error path never gave up' }); + + // The repair can be observed mid-write too, so the budget has to be back. + rmSync(configFilePath, { recursive: true }); + writeFileSync(configFilePath, ''); + await watcher._handleChangeForTests(); + assert.strictEqual(watcher.get(['enabled']), true, 'the half-written repair must not be adopted'); + + writeFileSync(configFilePath, stringify({ 'test-component': { enabled: false } })); + await once(watcher, 'change'); + assert.strictEqual(watcher.get(['enabled']), false); + }); + + it('OptionsWatcher applies a root-config change before the change handler returns', async () => { + const watcher = new OptionsWatcher('test-component', configFilePath, undefined, true); + openWatchers.push(watcher); + await watcher.ready; + + writeFileSync(configFilePath, stringify({ 'test-component': { enabled: false } })); + watcher._handleChangeForTests(); + + assert.strictEqual(watcher.get(['enabled']), false); + }); + + it('OptionsWatcher recovers an application config observed mid-write instead of removing it', async () => { + const appConfigPath = join(fixture, 'config.yaml'); + writeFileSync(appConfigPath, stringify({ 'test-component': { enabled: true } })); + const watcher = new OptionsWatcher('test-component', appConfigPath, undefined, false); + openWatchers.push(watcher); + await watcher.ready; + + const removes = []; + watcher.on('remove', () => removes.push(true)); + writeFileSync(appConfigPath, ''); + // Awaited, or the assertions below would also pass against a build with no partial-read + // handling at all on this path, having asserted on a read that had not happened. + await watcher._handleChangeForTests(); + assert.deepStrictEqual(removes, [], 'a half-written read must not read as the scope being removed'); + assert.strictEqual(watcher.get(['enabled']), true); + + writeFileSync(appConfigPath, stringify({ 'test-component': { enabled: false } })); + await once(watcher, 'change'); + assert.strictEqual(watcher.get(['enabled']), false); + }); + + it('RootConfigWatcher treats a document that parses to nothing as incomplete', async () => { + const watcher = new RootConfigWatcher(); + openWatchers.push(watcher); + await watcher.ready; + + // A truncated write can leave a document that reads fine and parses to null. + writeFileSync(configFilePath, '\n'); + watcher.handleChange(); + assert.deepStrictEqual(watcher.config, { 'test-component': { enabled: true } }); + }); + + it('OptionsWatcher does not let an env overlay launder a half-written root config', async () => { + // overlayRootEnvConfig turns any parse into a non-null object whenever a config env var is + // set — the norm in containers — so completeness has to be judged on the file's own parse + // or an empty read is adopted as an env-only config and the file's options are wiped. + process.env.HARPER_SET_CONFIG = JSON.stringify({ 'other-component': { enabled: true } }); + const watcher = new OptionsWatcher('test-component', configFilePath, undefined, true); + openWatchers.push(watcher); + await watcher.ready; + assert.strictEqual(watcher.get(['enabled']), true); + + const removes = []; + watcher.on('remove', () => removes.push(true)); + writeFileSync(configFilePath, ''); + await watcher._handleChangeForTests(); + + assert.deepStrictEqual(removes, [], 'the env overlay must not stand in for the half-written file'); + assert.strictEqual(watcher.get(['enabled']), true); + }); + + it('OptionsWatcher reports a file it gave up on once, not once per scope', async () => { + clearPartialReadWarning(configFilePath); + // Both scopes must be present in the file, or their `ready` never fires. + writeFileSync( + configFilePath, + stringify({ 'test-component': { enabled: true }, 'other-component': { enabled: true } }) + ); + const watchers = ['test-component', 'other-component'].map((name) => { + const watcher = new OptionsWatcher(name, configFilePath, undefined, true); + openWatchers.push(watcher); + return watcher; + }); + await Promise.all(watchers.map((watcher) => watcher.ready)); + + writeFileSync(configFilePath, ''); + for (const watcher of watchers) { + // Drive each watcher past its own retry budget, as a real unusable file would. + for (let attempt = 0; attempt <= 12; attempt++) await watcher._handleChangeForTests(); + await waitFor(() => isPartialReadWarned(configFilePath), { message: 'the give-up was never reported' }); + } + // The per-file gate that suppresses the duplicate report is pinned directly in + // unitTests/utility/partialReadRetry.test.js; this covers both scopes reaching it at all. + assert.strictEqual(isPartialReadWarned(configFilePath), true); + }); + + it('OptionsWatcher still reads an application config without blocking', async () => { + // Application configs are written in place, never by rename-over, so they must keep the + // non-blocking read — a slow or stalled component-config volume must not stall the thread. + const appConfigPath = join(fixture, 'config.yaml'); + writeFileSync(appConfigPath, stringify({ 'test-component': { enabled: true } })); + const watcher = new OptionsWatcher('test-component', appConfigPath, undefined, false); + openWatchers.push(watcher); + await watcher.ready; + + writeFileSync(appConfigPath, stringify({ 'test-component': { enabled: false } })); + const changed = once(watcher, 'change'); + watcher._handleChangeForTests(); + + assert.strictEqual(watcher.get(['enabled']), true, 'application config reads must not be synchronous'); + await changed; + assert.strictEqual(watcher.get(['enabled']), false); + }); +}); diff --git a/unitTests/config/rootConfigWatcher.test.js b/unitTests/config/rootConfigWatcher.test.js index 3aa48aa7b2..66a8ab24ff 100644 --- a/unitTests/config/rootConfigWatcher.test.js +++ b/unitTests/config/rootConfigWatcher.test.js @@ -39,9 +39,12 @@ describe('RootConfigWatcher', () => { expected.foo = 'baz'; + // Subscribe before writing: the watcher re-reads the root config synchronously, so the + // change event can be emitted before this writer's own await resolves. + const changed = once(configWatcher, 'change'); await writeFile(this.configFilePath, stringify(expected)); - const [updated] = await once(configWatcher, 'change'); + const [updated] = await changed; assert.deepEqual(updated, expected, 'RootConfigWatcher should emit a change event with the updated config'); diff --git a/unitTests/utility/partialReadRetry.test.js b/unitTests/utility/partialReadRetry.test.js new file mode 100644 index 0000000000..e28d1cb395 --- /dev/null +++ b/unitTests/utility/partialReadRetry.test.js @@ -0,0 +1,159 @@ +const assert = require('node:assert'); +const { + PartialReadRetry, + warnPartialReadGaveUp, + isPartialReadWarned, + clearPartialReadWarning, + describeReadFailure, +} = require('#src/utility/watcherFallback'); +const { parse } = require('yaml'); +const { waitFor } = require('../waitFor'); + +// The retry is a timer, so "it fired" is a condition to wait for; "it fired only once" is a +// non-event, which is the one case AGENTS.md reserves a fixed settle for. +const settle = () => new Promise((resolve) => setTimeout(resolve, 100)); + +describe('describeReadFailure', () => { + it('reports where a config file failed to parse, never what it contains', () => { + let description; + try { + parse('operationsApi:\n password: hunter2-super-secret\n port: [unclosed\n'); + assert.fail('the fixture must not parse'); + } catch (error) { + description = describeReadFailure(error); + } + + // The parser's own message quotes the offending source lines, which is why it is not used. + assert.match(description, /line \d+, column \d+/); + assert.doesNotMatch(description, /hunter2|password|unclosed/); + }); + + it('reports a read error by its code', () => { + assert.strictEqual(describeReadFailure(Object.assign(new Error('nope'), { code: 'EACCES' })), 'EACCES'); + }); +}); + +describe('PartialReadRetry', () => { + it('re-reads once for a burst of unusable reads, not once per event', async () => { + const retry = new PartialReadRetry('/nonexistent/config.yaml'); + let rereads = 0; + + assert.strictEqual( + retry.schedule(() => rereads++), + true + ); + assert.strictEqual( + retry.schedule(() => rereads++), + true, + 'a second event joins the armed re-read' + ); + + await waitFor(() => rereads > 0, { message: 'the re-read never fired' }); + await settle(); + assert.strictEqual(rereads, 1); + }); + + it('cancels an armed re-read once a usable read arrives, so it cannot replay', async () => { + const retry = new PartialReadRetry('/nonexistent/config.yaml'); + let rereads = 0; + + retry.schedule(() => rereads++); + retry.settled(); + + await settle(); + assert.strictEqual(rereads, 0); + }); + + it('reports exhaustion so the caller can fall back to its own error handling', async () => { + const retry = new PartialReadRetry('/nonexistent/config.yaml'); + let rereads = 0; + // Re-arm only after each timer has actually fired, so this counts budget rather than + // racing the timer that is still armed (schedule() reports true for both). + for (let attempt = 1; retry.schedule(() => rereads++); attempt++) { + assert.ok(attempt <= 50, 'the budget must be bounded'); + await waitFor(() => rereads === attempt, { message: `re-read ${attempt} never fired` }); + } + + assert.ok(rereads > 0, 'the budget must allow at least one re-read'); + assert.strictEqual( + retry.schedule(() => rereads++), + false + ); + + // A usable read restores the budget for the next incident. + retry.settled(); + assert.strictEqual( + retry.schedule(() => rereads++), + true + ); + }); + + it('re-arms the give-up warning once the file recovers', async () => { + const retry = new PartialReadRetry('/nonexistent/recovering.yaml'); + // The warning is throttled per file so one bad config cannot produce one line per scope, + // but a file that recovers and later breaks again is a new incident. + warnPartialReadGaveUp('/nonexistent/recovering.yaml'); + assert.strictEqual(isPartialReadWarned('/nonexistent/recovering.yaml'), true); + + retry.settled(); + assert.strictEqual(isPartialReadWarned('/nonexistent/recovering.yaml'), false); + }); + + it('keeps the report standing when it gives up, and withdraws it only on recovery', async () => { + // The gate is shared per file, so treating a give-up like a recovery would let each of the + // N scopes watching one root config report the same file in turn. + const path = '/nonexistent/shared.yaml'; + clearPartialReadWarning(path); + const retry = new PartialReadRetry(path); + + assert.strictEqual(retry.gaveUp(), true, 'the first give-up is the one that reports'); + assert.strictEqual( + new PartialReadRetry(path).gaveUp(), + false, + 'another scope giving up on the same file must be suppressed, not reported again' + ); + + retry.settled(); + assert.strictEqual(isPartialReadWarned(path), false, 'a usable read is what withdraws the report'); + assert.strictEqual(new PartialReadRetry(path).gaveUp(), true, 'so the next incident reports again'); + }); + + it('restores the budget when it gives up, so a later repair is not missed', async () => { + // The repair can itself be observed mid-write, which is the case the retry exists for — a + // watcher left with no budget would drop it and chokidar may emit nothing further. + const retry = new PartialReadRetry('/nonexistent/repaired.yaml'); + let rereads = 0; + for (let attempt = 1; retry.schedule(() => rereads++); attempt++) { + assert.ok(attempt <= 50, 'the budget must be bounded'); + await waitFor(() => rereads === attempt, { message: `re-read ${attempt} never fired` }); + } + retry.gaveUp(); + + assert.strictEqual( + retry.schedule(() => rereads++), + true, + 'the next incident needs its own budget' + ); + }); + + it('stops re-reading after close', async () => { + const retry = new PartialReadRetry('/nonexistent/config.yaml'); + let rereads = 0; + + retry.schedule(() => rereads++); + retry.cancel(); + + await settle(); + assert.strictEqual(rereads, 0); + assert.strictEqual( + retry.schedule(() => rereads++), + false + ); + // Close is terminal: giving up restores the budget, and must not do so after close. + assert.strictEqual(retry.gaveUp(), false); + assert.strictEqual( + retry.schedule(() => rereads++), + false + ); + }); +}); diff --git a/utility/watcherFallback.ts b/utility/watcherFallback.ts index 7afdf43da3..01daf64eb8 100644 --- a/utility/watcherFallback.ts +++ b/utility/watcherFallback.ts @@ -10,6 +10,7 @@ import { loggerWithTag } from './logging/harper_logger.ts'; // One-time process-wide warning so a thundering herd of failing watchers doesn't // produce hundreds of identical log lines. let exhaustionWarned = false; +const partialReadWarned = new Set(); const fallbackLogger = loggerWithTag('watcher'); @@ -72,3 +73,124 @@ export function warnWatcherFallback(watchedPath: string): void { export function _resetForTests(): void { exhaustionWarned = false; } + +/** + * A config file replaced in place (truncate, then write) can be read back empty or + * half-written, and chokidar may emit nothing further for that write — so a watcher that + * simply drops the unusable read would serve stale config until something else touched the + * file. Re-read on a later turn instead, bounded so a genuinely empty or corrupt file cannot + * spin. Callers read synchronously, so the descriptor still never outlives a single turn. + */ +const PARTIAL_READ_REREAD_DELAY_MS = 20; +const PARTIAL_READ_MAX_REREADS = 10; + +export class PartialReadRetry { + #filePath: string; + #timer?: ReturnType; + #remaining: number = PARTIAL_READ_MAX_REREADS; + #closed = false; + + constructor(filePath: string) { + this.#filePath = filePath; + } + + /** False once the budget is spent, so the caller can fall back to its own error handling. */ + schedule(reread: () => void): boolean { + if (this.#closed) return false; + if (this.#timer) return true; + if (this.#remaining <= 0) return false; + this.#remaining--; + this.#timer = setTimeout(() => { + this.#timer = undefined; + reread(); + }, PARTIAL_READ_REREAD_DELAY_MS); + this.#timer.unref?.(); + return true; + } + + /** A usable read arrived, so any re-read still armed for the previous one would duplicate it. */ + settled() { + if (this.#timer) clearTimeout(this.#timer); + this.#timer = undefined; + this.#remaining = PARTIAL_READ_MAX_REREADS; + // The file recovered, so the next time it breaks is a new incident and has to be reported + // again rather than silenced by the warning it emitted weeks ago. + partialReadWarned.delete(this.#filePath); + } + + /** + * The budget is spent. Distinct from `settled()` in that the report stands — the file has not + * recovered, and it is shared with every other watcher of it. The budget itself is restored, + * because the next event may be the repair, and that repair can be observed mid-write too. + * Returns whether this give-up was the one reported. + */ + gaveUp(error?: unknown): boolean { + if (this.#closed) return false; + this.#remaining = PARTIAL_READ_MAX_REREADS; + return warnPartialReadGaveUp(this.#filePath, error); + } + + /** Terminal: the watcher is closing, so nothing may re-arm the re-read or report on it. */ + cancel() { + if (this.#timer) clearTimeout(this.#timer); + this.#timer = undefined; + this.#closed = true; + } +} + +/** + * ENOENT is excluded not because it cannot be transient, but because it already has an answer: + * `OptionsWatcher` routes it to `remove` (env-only fallback at boot, then removal), and + * `RootConfigWatcher` keeps its last config rather than tearing down core features on a file + * that may just be mid-replace. Re-reading would only delay a decision already made. + */ +export function isPartialReadError(error: unknown): boolean { + return !(typeof error === 'object' && error !== null && (error as { code?: string }).code === 'ENOENT'); +} + +/** + * A watcher that exhausts its re-read budget serves stale config from then on, so the give-up + * has to be visible — otherwise the only symptom is a config change that silently did nothing. + * Warned once per file: every root-config scope watches the same one and would otherwise report + * a single bad file once each, on every event. + */ +export function warnPartialReadGaveUp(filePath: string, error?: unknown): boolean { + if (partialReadWarned.has(filePath)) return false; + partialReadWarned.add(filePath); + // The cause matters to whoever has to fix it: a file that never parses is a typo to correct, + // while one that reads empty is a writer that never finished. Report the kind and position + // only — a YAML parse error's message quotes the offending source, and this file holds + // credentials. + const cause = error ? `: ${describeReadFailure(error)}` : ' that were empty or incomplete'; + fallbackLogger.warn(`Gave up re-reading ${filePath} after ${PARTIAL_READ_MAX_REREADS} unusable reads${cause}`); + return true; +} + +/** + * The kind and position of a failed config read, never its content: a YAML parse error's message + * quotes the offending source lines, and these files hold credentials. + */ +export function describeReadFailure(error: unknown): string { + if (typeof error !== 'object' || error === null) return 'unusable'; + const { name, code, linePos } = error as { name?: string; code?: string; linePos?: { line: number; col: number }[] }; + const at = linePos?.[0] ? ` at line ${linePos[0].line}, column ${linePos[0].col}` : ''; + return `${code ?? name ?? 'unusable'}${at}`; +} + +/** Test-only: whether a give-up warning for this file is currently suppressed as a duplicate. */ +export function isPartialReadWarned(filePath: string): boolean { + return partialReadWarned.has(filePath); +} + +/** Test-only: forget that this file was reported, so a suite can start from a known state. */ +export function clearPartialReadWarning(filePath: string) { + partialReadWarned.delete(filePath); +} + +/** + * A listener that throws while applying new config is a bug in that listener, not evidence the + * file was half-written — the watcher's own state is already updated, so it keeps going. + */ +export function warnWatcherListenerError(filePath: string, error: unknown) { + fallbackLogger.warn(`Error applying a configuration change from ${filePath}`, error); +}