Skip to content

fix(server): clean up runtime config watcher on shutdown - #52

Open
nvanlaerebeke wants to merge 8 commits into
Euro-Office:mainfrom
nvanlaerebeke:fix/runtime-config-watcher-shutdown
Open

nvanlaerebeke wants to merge 8 commits into
Euro-Office:mainfrom
nvanlaerebeke:fix/runtime-config-watcher-shutdown

Conversation

@nvanlaerebeke

Copy link
Copy Markdown

Summary

Add lifecycle management for the runtime configuration watcher as a prerequisite for Euro-Office/server#46.

This existing problem was discovered while developing the Redis-backed editor-data implementation.
The change adds watcher cleanup, pending reload cancellation, initialization-race handling, and shutdown cleanup.

Problem

The Redis-backed editor-data implementation has a more involved shutdown path.

Redis stores and connected-editor work must be cleaned up before the process exits, including when a Redis topology or reconnect failure causes a fatal shutdown.

However, runtimeConfigManager starts a file watcher and may schedule a delayed configuration reload without providing a way to stop either resource.

As a result, the watcher or timer could keep the process alive after the Redis stores had been closed, or trigger a configuration reload during shutdown.
This made Redis process and topology tests prone to hanging or failing during cleanup.

The problem did not show up earlier because the watcher normally remains active for the lifetime of the document service, and regular operation does not close the Redis stores while the process is still shutting down.

The Redis work added controlled, asynchronous shutdown and failure-path testing for reconnects and topology changes, which exposed the leftover watcher and timer resources.

Changes

  • Keep track of the active runtime configuration watcher so it can be cleaned up later.
  • Add closeRuntimeConfigWatcher() to stop watching for changes and cancel pending reloads.
  • Ensure both native and polling watchers are closed correctly.
  • Safely handle cases where runtimeConfig.filePath is not configured.
  • Safely handle shutdown while a watcher is still being initialized.
  • Prevent an older watcher initialization from replacing a newer one.
  • Add unit tests covering watcher, timer, and shutdown cleanup.
  • Run the cleanup when the document service shuts down after an uncaught exception.

Testing

Added the following tests:

  • Added a test that verifies closing the runtime watcher also cancels a pending reload timer.
  • Added a test that verifies a watcher is closed when shutdown occurs during watcher initialization.
  • Added a test that verifies an older initialization cannot replace a newer watcher.
  • Added a test that verifies calling closeRuntimeConfigWatcher multiple times is safe.
  • Added a test that verifies reinitializing the watcher closes the previous watcher.
  • Added a test that verifies closing a polling watcher removes its file callback.

Scope

This change affects runtime configuration watcher lifecycle only.
It does not change runtime configuration behavior.

AI disclosure

Codex assisted with the implementation and test preparation

Prevent runtime configuration watchers and pending reload timers from
surviving fatal shutdowns. Handle initialization races and repeated watcher
setup, and add regression coverage for watcher cleanup.

Assisted-by: Codex:GPT-5
Signed-off-by: Nico Van Laerebeke <1520618+nvanlaerebeke@users.noreply.github.com>

@MonaAghili MonaAghili left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Blocking

1. The new tests are never run

tests/jest.config.js uses testMatch: ['**/?(*.)+(spec|tests).[tj]s?(x)'], so tests/unit/runtimeConfigManager.test.js is not collected, either in CI or by a local npm run "unit tests". npm run "unit tests" -- --listTests lists the other 7 unit files but not this one.

Please rename the file to runtimeConfigManager.tests.js. #46 has the same file name.

2. A stale initialization can stop the active polling watcher

On the polling path (for example NFS, SMB, FUSE, overlayfs, CephFS), fs.watchFile returns one StatWatcher per path, and every caller shares it. Suppose two initRuntimeConfigWatcher() calls overlap and the newer one resolves first. The older call gets the same StatWatcher back, finds it is stale, and calls watcher.stop() on it (line 182). That closes the handle the active watcher is using. fs.unwatchFile() then removes only one of the two listeners, so the stopped watcher stays in Node's per-path map, and any later fs.watchFile() on that path gets the dead watcher back.

The result: changes to the config file are no longer detected, and no error or warning is logged. For the default tenant, the merged config cache in operationContext has no TTL and is cleared only by this reload, so it keeps serving the old values until the process restarts.

Today each process calls initRuntimeConfigWatcher() once, so production doesn't hit this yet. But it is exactly the overlapping case the generation check and the "does not let an older initialization replace a newer watcher" test are meant to cover.

Suggested fix: remove both ?.stop?.() calls (lines 182 and 199). The code already calls fs.unwatchFile(configFilePath, handleConfigFileChange), which counts listeners and stops the StatWatcher once the last one is removed. StatWatcher.stop() is also not documented fs API; the docs list only ref() and unref().

// initRuntimeConfigWatcher, stale branch
watcher?.close?.();
if (configFilePath) {
  fsWatch.unwatchFile(configFilePath, handleConfigFileChange);
}

// closeRuntimeConfigWatcher
runtimeConfigWatcher?.close?.();
runtimeConfigWatcher = null;
if (configFilePath) {
  fsWatch.unwatchFile(configFilePath, handleConfigFileChange);
}

With this change, the process still exits on its own after closeRuntimeConfigWatcher() with a native watcher, a polling watcher, and a native watcher that errored and fell back to polling.

The "removes the file callback when closing a polling watcher" test asserts that watcher.stop is called (line 122), so it fails with this fix. Its unwatchFile assertion (line 123) also passes for any path and any listener. Suggested replacement:

test('removes the file callback when closing a polling watcher', async () => {
  let watchedFile;
  let changeListener;
  const unwatchFile = jest.spyOn(fsWatch, 'unwatchFile').mockImplementation(() => {});
  jest.spyOn(utils, 'watchWithFallback').mockImplementation(async (_ctx, _dir, file, listener) => {
    watchedFile = file;
    changeListener = listener;
    return {};
  });

  await runtimeConfigManager.initRuntimeConfigWatcher({logger: {info: jest.fn()}});
  runtimeConfigManager.closeRuntimeConfigWatcher();

  expect(unwatchFile).toHaveBeenCalledWith(watchedFile, changeListener);
});

The existing tests replace the watchers with mock objects, so none of them can catch the shared-watcher problem. This test uses the real fs.watchFile. It fails on the current code and passes with the fix:

test('a stale initialization does not stop the active polling watcher', async () => {
  const fsPromises = require('fs/promises');
  const pending = [];
  jest.spyOn(fsPromises, 'statfs').mockImplementation(() => new Promise(resolve => pending.push(() => resolve({type: 0x6969}))));
  const watchFile = jest.spyOn(fsWatch, 'watchFile');

  const older = runtimeConfigManager.initRuntimeConfigWatcher({logger: {info: jest.fn()}});
  const newer = runtimeConfigManager.initRuntimeConfigWatcher({logger: {info: jest.fn()}});
  pending[1]();
  await newer;
  const onStop = jest.fn();
  watchFile.mock.results[0].value.on('stop', onStop);

  pending[0]();
  await older;
  await new Promise(resolve => setImmediate(resolve));

  expect(onStop).not.toHaveBeenCalled();
});

#46 has an identical copy of runtimeConfigManager.js and of this test file, so it needs the same changes, or a rebase onto this PR.

Non-blocking

3. The cleanup is not called from #46's shutdown

The only caller is the uncaughtException handler in DocService/sources/server.js (line 484). That handler calls process.exit(1) once logger.shutdown() completes, so open watchers can't keep the process alive there anyway.

The scenario in the PR description is #46's graceful shutdown, but shutdownRedis() and closeLocalResources() in #46 never call closeRuntimeConfigWatcher(). #46 also replaces the uncaughtException block edited here; a 3-way merge of server.js gives one conflict on exactly that hunk. If #46's version wins, the cleanup has no production caller at all.

Suggest calling it from closeLocalResources() in #46 through the existing closeResource() wrapper, alongside the license and plugins watchers.

Signed-off-by: Nico Van Laerebeke <1520618+nvanlaerebeke@users.noreply.github.com>
Signed-off-by: Nico Van Laerebeke <1520618+nvanlaerebeke@users.noreply.github.com>
@nvanlaerebeke

Copy link
Copy Markdown
Author

Thanks for the detailed review.

I've addressed the points raised:

  1. Renamed the unit test to runtimeConfigManager.tests.js so it is picked up by the existing Jest testMatch.

  2. Removed the explicit StatWatcher.stop() handling from the polling watcher cleanup.
    Cleanup now relies on fs.unwatchFile() for the polling path, while still using close() for native watchers.
    I also added the coverage using a real fs.watchFile() watcher to verify that a stale initialization does not stop the active polling watcher.

  3. I had already done a rebase on this branch, did a new one and updated its shutdown path as well. closeLocalResources() now calls runtimeConfigManager.closeRuntimeConfigWatcher() through the existing closeResource() wrapper alongside the other local watcher/timer cleanup.
    So feat: add Redis-backed editor data storage for high availability #46 now contains the corresponding shutdown integration rather than relying only on the uncaughtException handling from this PR.

@MonaAghili MonaAghili left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Two items from a deeper pass, both at head 5e63cff.

  1. The stale-init cleanup still removes the active polling listener (distinct from the .stop() fix already landed)

The stale branch calls fs.unwatchFile(configFilePath, handleConfigFileChange) unconditionally. When the stale init created a native fs.watch watcher and the active (newer) init is polling, the stale cleanup runs watcher.close() (closes the native handle, no effect on polling) AND unwatchFile, which removes the active init's single polling listener from the shared StatWatcher. The live watcher then stops, config edits go undetected, and the default-tenant config cache (no TTL, cleared only here) serves stale values until restart.

The active init is polling while a stale one is native when statfs/fs.watch pick different paths across the two overlapping calls (e.g. the active one fell back to polling). The new test "a stale initialization does not stop the active polling watcher" forces both inits onto the polling path (statfs -> 0x6969 for both), so it does not exercise this asymmetric case.

Only remove the listener this init actually registered. StatWatcher has no close(), so the presence of close() distinguishes native from polling:

if (runtimeConfigWatcherClosed || generation !== runtimeConfigWatcherGeneration) {
  if (typeof watcher?.close === 'function') {
    watcher.close();
  } else {
    fsWatch.unwatchFile(configFilePath, handleConfigFileChange);
  }
  return;
}

Suggested test: stale init resolves native, active init resolves polling; assert the shared StatWatcher still has one change listener and a file edit still triggers one reload.

  1. A late native-watch error can resurrect a polling watcher after close (low; affects #46's graceful path)

utils.watchWithFallback's native error handler runs fs.watchFile(filePath, opts, listener) with no closed-state check. If a native watch error (ENOSPC, dir removed, EPERM) fires during or after closeRuntimeConfigWatcher(), it installs a new StatWatcher that the module holds no reference to and cannot remove. Reloads are still suppressed by runtimeConfigWatcherClosed, but the handle leaks and keeps the event loop alive.

This is harmless in this PR (the only caller is the uncaughtException handler, which force-exits via process.exit(1)), but in #46 closeLocalResources() has no forced exit and waits for the loop to drain, so this is a shutdown-hang path. Root cause is in watchWithFallback; the cleanest fix is for its error handler to stop re-arming once a shutdown/close flag is set, so closeRuntimeConfigWatcher() can fully neutralize it.

Use one watcher controller to handle native watchers, polling, and fallback.
This prevents an older watcher from stopping or removing the active watcher.

Add tests for overlapping watchers, fallback cleanup, shutdown races, and
config file changes.

Assisted-by: Codex:GPT-5
Signed-off-by: Nico Van Laerebeke <1520618+nvanlaerebeke@users.noreply.github.com>
@nvanlaerebeke

Copy link
Copy Markdown
Author

The watcher cleanup was changed so each initialization owns a single watcher controller, which knows whether it is using native watching or polling. When an older initialization becomes stale, it closes only its own native watcher or removes only its own polling listener, so it can no longer accidentally disable the active watcher. The controller also records when it has been closed. If a native watcher reports an error after shutdown has started, the error handler now stops instead of creating a new polling watcher, preventing leaked handles and shutdown hangs. Tests cover the native/polling race, real file changes after fallback, and late errors after close.

Apply Prettier formatting to the runtime watcher test literals.

Assisted-by: Codex:GPT-5
Signed-off-by: Nico Van Laerebeke <1520618+nvanlaerebeke@users.noreply.github.com>

@MonaAghili MonaAghili left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Re-checked at 3815454. Two tests are flaky, same root cause.

fs.watchFile records the file's baseline stat asynchronously on the libuv threadpool. Both tests write the file before that stat has necessarily run; when the write wins, the edit becomes the baseline and no change is ever reported. Local rates: about 1 in 8-10 Jest runs for the first test, 1/25 for the second. With UV_THREADPOOL_SIZE=1 and the thread kept busy for ~140 ms (pbkdf2 in a beforeEach), both fail every time. A fixed sleep before the write is not enough: a 50 ms wait fails the same way under that load.

  1. watchWithFallback.tests.js "polling fallback detects a subsequent file edit"

    Suggest growing the file until the watcher reports the change, instead of a single write:

    onError(new Error('native watcher failed'));
    
    await new Promise((resolve, reject) => {
      const timeout = setTimeout(() => {
        clearInterval(check);
        reject(new Error('polling watcher did not detect the file edit'));
      }, 1000);
      const check = setInterval(() => {
        if (listener.mock.calls.length > 0) {
          clearTimeout(timeout);
          clearInterval(check);
          resolve();
          return;
        }
        fsWatch.appendFileSync(filePath, ' ');
      }, 20);
    });
    
  2. runtimeConfigManager.tests.js "a stale native initialization does not remove the active polling listener"

    Same race: the write after await older only follows microtasks. Re-edit until the reload happens, spaced above the 200 ms reload debounce so the edits don't keep resetting it:

    let edits = 0;
    const edit = () => fsWatch.writeFileSync(runtimeFile, '{"changed":true}' + ' '.repeat(++edits));
    await new Promise((resolve, reject) => {
      edit();
      const rewrite = setInterval(edit, 300);
      const timeout = setTimeout(() => {
        clearInterval(rewrite);
        clearInterval(check);
        reject(new Error('active polling watcher did not reload the edited file'));
      }, 3000);
      const check = setInterval(() => {
        if (cleanRuntimeConfigCache.mock.calls.length > 0) {
          clearInterval(rewrite);
          clearTimeout(timeout);
          clearInterval(check);
          resolve();
        }
      }, 10);
    });
    

With both changes: 25/25 normal runs pass, both tests pass with the threadpool blocked for ~570 ms, and test 2 still fails when the old unconditional fs.unwatchFile from 5e63cff is restored.

Assisted-by: Codex:GPT-5
Signed-off-by: Nico Van Laerebeke <1520618+nvanlaerebeke@users.noreply.github.com>
Assisted-by: Codex:GPT-5
Signed-off-by: Nico Van Laerebeke <1520618+nvanlaerebeke@users.noreply.github.com>
@nvanlaerebeke

Copy link
Copy Markdown
Author

Thanks @MonaAghili , I've applied your suggestions

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants