Fix NativeWatcher missing changes made straight after startup

packages/metro-file-map/src/Watcher.js

@@ -42,6 +42,11 @@ const debug = debugModule('Metro:Watcher');
 
 const MAX_WAIT_TIME = 240000;
 
+// For a backend that isn't live as soon as it starts, how long to wait for each
+// health check that confirms a watch, and for the watch overall.
+const LIVE_CHECK_TIMEOUT = 200;
+const MAX_LIVE_WAIT_TIME = 10000;
+
 type InternalCrawlOptions = Readonly<{
   previousState: CrawlerOptions['previousState'],
   roots: ReadonlyArray<string>,
@@ -92,6 +97,9 @@ export class Watcher extends EventEmitter {
   #bufferedEvents: Array<WatcherBackendChangeEvent> = [];
   #closed: boolean = false;
   #createBackend: ?(root: Path) => Promise<WatcherBackend>;
+  // Whether a started backend's watches need confirming before they are
+  // relied on.
+  #confirmWatches: boolean = false;
   readonly #instanceId: number;
   #nextHealthCheckId: number = 0;
   #onChange: ?(change: WatcherBackendChangeEvent) => void;
@@ -364,6 +372,42 @@ export class Watcher extends EventEmitter {
         createWatcherBackend(root, watchmanClocks),
       ),
     );
+    // Confirmed only once every backend has started, because starting one may
+    // restart the others' watches (NativeWatchers share one FSEvents stream).
+    this.#confirmWatches = !WatcherImpl.isLiveOnStart();
+    if (this.#confirmWatches) {
+      await Promise.all(
+        this.#options.roots.map(root => this.#waitUntilLive(root)),
+      );
+    }
+  }
+
+  /**
+   * Check the health of a root's watch until it reports a change, so that
+   * changes made from now on aren't missed. Warns if it can't be confirmed.
+   */
+  async #waitUntilLive(root: Path): Promise<void> {
+    const deadline = Date.now() + MAX_LIVE_WAIT_TIME;
+    let result;
+    do {
+      result = await this.#checkHealth(root, LIVE_CHECK_TIMEOUT);
+    } while (
+      result.type === 'timeout' &&
+      Date.now() < deadline &&
+      !this.#closed &&
+      !this.#options.abortSignal.aborted
+    );
+    debug('Confirming the watch of %s: %s', root, result.type);
+    if (
+      result.type !== 'success' &&
+      !this.#closed &&
+      !this.#options.abortSignal.aborted
+    ) {
+      this.#options.console.warn(
+        `metro-file-map: Could not confirm that ${root} is being watched ` +
+          `(${result.type}). Changes made during startup may be missed.`,
+      );
+    }
   }
 
   /**
@@ -379,8 +423,11 @@ export class Watcher extends EventEmitter {
     // `close()` may have been called while the backend was starting.
     if (this.#closed) {
       await backend.stopWatching();
-    } else {
-      this.#backends.push(backend);
+      return;
+    }
+    this.#backends.push(backend);
+    if (this.#confirmWatches) {
+      await this.#waitUntilLive(root);
     }
   }
 
@@ -399,6 +446,13 @@ export class Watcher extends EventEmitter {
   }
 
   async checkHealth(timeout: number): Promise<HealthCheckResult> {
+    return this.#checkHealth(this.#options.rootDir, timeout);
+  }
+
+  /**
+   * Write a health check file into `dir`, and wait for a backend to report it.
+   */
+  async #checkHealth(dir: Path, timeout: number): Promise<HealthCheckResult> {
     const healthCheckId = this.#nextHealthCheckId++;
     if (healthCheckId === Number.MAX_SAFE_INTEGER) {
       this.#nextHealthCheckId = 0;
@@ -412,7 +466,7 @@ export class Watcher extends EventEmitter {
       this.#instanceId +
       '-' +
       healthCheckId;
-    const healthCheckPath = path.join(this.#options.rootDir, basename);
+    const healthCheckPath = path.join(dir, basename);
     let result: ?HealthCheckResult;
     const timeoutPromise = new Promise(resolve =>
       setTimeout(resolve, timeout),

packages/metro-file-map/src/__tests__/Watcher-test.js

@@ -20,6 +20,7 @@ import type {
 
 import TreeFS from '../lib/TreeFS';
 import {Watcher} from '../Watcher';
+import * as fs from 'node:fs';
 import * as path from 'node:path';
 
 const mockWatchmanCrawl = jest.fn<[CrawlerOptions], Promise<CrawlResult>>();
@@ -40,6 +41,7 @@ type MockBackend = {
   emit: (event: WatcherBackendChangeEvent) => void,
 };
 const mockStartedBackends: Array<MockBackend> = [];
+let mockNativeLiveOnStart = true;
 function mockBackendClass(kind: MockBackend['kind']) {
   return class {
     #root: string;
@@ -48,6 +50,9 @@ function mockBackendClass(kind: MockBackend['kind']) {
     static isSupported(): boolean {
       return true;
     }
+    static isLiveOnStart(): boolean {
+      return kind !== 'native' || mockNativeLiveOnStart;
+    }
     constructor(root: string, opts: {clocks?: ?Map<string, string>, ...}) {
       this.#root = root;
       this.#clocks = opts.clocks;
@@ -64,6 +69,9 @@ function mockBackendClass(kind: MockBackend['kind']) {
       });
     }
     async stopWatching() {}
+    getPauseReason(): ?string {
+      return null;
+    }
   };
 }
 jest.mock('../watchers/NativeWatcher', () => ({
@@ -133,6 +141,7 @@ function createWatcher(
 
 beforeEach(() => {
   mockStartedBackends.length = 0;
+  mockNativeLiveOnStart = true;
   mockWatchmanCrawl.mockReset();
   mockNodeCrawl.mockReset();
   jest.spyOn(console, 'warn').mockImplementation(() => {});
@@ -273,6 +282,112 @@ describe('Watcher backend choice in watch mode', () => {
   });
 });
 
+describe('Watcher with a backend that is not live on start', () => {
+  const healthCheckFilePrefix = '.metro-file-map-health-check';
+  let writtenFiles: Array<string>;
+  // Health check files are reported only once this many have been written.
+  let liveAfterWrites: number;
+
+  beforeEach(() => {
+    // Health checks time out, and backends report changes asynchronously
+    jest.useRealTimers();
+    mockNativeLiveOnStart = false;
+    writtenFiles = [];
+    liveAfterWrites = 1;
+    jest
+      .spyOn(fs.promises, 'writeFile')
+      .mockImplementation(async (filePath: string) => {
+        writtenFiles.push(filePath);
+        if (writtenFiles.length < liveAfterWrites) {
+          return;
+        }
+        const backend = mockStartedBackends.find(
+          b => b.root === path.dirname(filePath),
+        );
+        // As a backend reports a change after the file is written
+        setImmediate(() =>
+          backend?.emit({
+            event: 'touch',
+            relativePath: path.basename(filePath),
+            root: backend.root,
+            metadata: {modifiedTime: 1, size: 0, type: 'f'},
+          }),
+        );
+      });
+    jest.spyOn(fs.promises, 'unlink').mockImplementation(async () => {});
+  });
+
+  afterEach(() => {
+    jest.useFakeTimers();
+  });
+
+  test('confirms the watch of each root before the crawl', async () => {
+    liveAfterWrites = 2;
+    let writesBeforeCrawl = 0;
+    mockNodeCrawl.mockImplementation(async () => {
+      writesBeforeCrawl = writtenFiles.length;
+      return crawlResult([]);
+    });
+    const watcher = createWatcher(false, null, true);
+    const warn = jest.spyOn(console, 'warn');
+
+    await watcher.crawl();
+
+    // The first health check went unreported, the second was reported.
+    expect(writesBeforeCrawl).toBe(2);
+    expect(writtenFiles.map(f => path.dirname(f))).toEqual([rootDir, rootDir]);
+    expect(
+      writtenFiles.every(f =>
+        path.basename(f).startsWith(healthCheckFilePrefix),
+      ),
+    ).toBe(true);
+    expect(warn).not.toHaveBeenCalled();
+  });
+
+  test('warns, and carries on, if a watch is never confirmed', async () => {
+    liveAfterWrites = Infinity;
+    mockNodeCrawl.mockImplementation(async () => crawlResult([]));
+    jest.useFakeTimers();
+    const watcher = createWatcher(false, null, true);
+    const warn = jest.spyOn(console, 'warn');
+
+    const crawled = watcher.crawl();
+    // $FlowFixMe[prop-missing] - in Jest 29.5+, missing from flow-typed's defs
+    await jest.advanceTimersByTimeAsync(11000);
+    await crawled;
+
+    expect(mockNodeCrawl).toHaveBeenCalledTimes(1);
+    expect(warn).toHaveBeenCalledWith(
+      expect.stringContaining(
+        `Could not confirm that ${rootDir} is being watched`,
+      ),
+    );
+  });
+
+  test('confirms the watch of a root added later', async () => {
+    mockNodeCrawl.mockImplementation(async () => crawlResult([]));
+    const watcher = createWatcher(false, null, true);
+    await watcher.crawl();
+    await watcher.watch(() => {});
+    writtenFiles = [];
+
+    const addedRoot = path.join(path.sep, 'other');
+    await watcher.watchRoot(addedRoot);
+
+    expect(writtenFiles.map(f => path.dirname(f))).toEqual([addedRoot]);
+  });
+
+  test('a backend that is live on start is not checked', async () => {
+    mockNativeLiveOnStart = true;
+    mockNodeCrawl.mockImplementation(async () => crawlResult([]));
+    const watcher = createWatcher(false, null, true);
+
+    await watcher.crawl();
+
+    expect(writtenFiles).toEqual([]);
+  });
+});
+
 describe('Watcher crawl option', () => {
   const stubCrawler =
     (canonicalPaths: ReadonlyArray<string>): Crawler =>

packages/metro-file-map/src/watchers/AbstractWatcher.js

@@ -32,6 +32,15 @@ export class AbstractWatcher implements WatcherBackend {
 
   #emitter: EventEmitter = new EventEmitter();
 
+  /**
+   * Whether a watch reports every change made after `startWatching` resolves.
+   * If not, `Watcher` confirms each watch with a change of its own before
+   * relying on it.
+   */
+  static isLiveOnStart(): boolean {
+    return true;
+  }
+
   constructor(dir: string, opts: WatcherBackendOptions) {
     const {ignored, included} = opts;
     this.ignored = ignored;

packages/metro-file-map/src/watchers/FallbackWatcher.js

@@ -57,6 +57,11 @@ export default class FallbackWatcher extends AbstractWatcher {
   readonly #watched: {[key: string]: FSWatcher, __proto__: null} =
     Object.create(null);
 
+  // Not live on darwin, though FallbackWatcher isn't currently used there.
+  static isLiveOnStart(): boolean {
+    return platform !== 'darwin';
+  }
+
   async startWatching(): Promise<void> {
     this.#watchdir(this.root);
 

packages/metro-file-map/src/watchers/NativeWatcher.js

@@ -59,6 +59,13 @@ export default class NativeWatcher extends AbstractWatcher {
     return platform() === 'darwin';
   }
 
+  // fs.watch can return before any changes are reported: libuv starts the
+  // FSEvents stream on another thread, and the stream reports only changes
+  // made after it starts.
+  static isLiveOnStart(): boolean {
+    return false;
+  }
+
   constructor(
     dir: string,
     opts: Readonly<{

packages/metro-file-map/src/watchers/__tests__/helpers.js

@@ -109,6 +109,38 @@ export const startWatching = async (
 
   await watcherInstance.startWatching();
 
+  // As Metro's Watcher does, confirm a watch that isn't live on start with a
+  // change of its own - a cookie file, matched by the `cookie-*` prefix.
+  // Watchers emit in order, so once the latest is reported, none of the
+  // earlier ones remain in flight to leak into a test.
+  if (!Watcher.isLiveOnStart()) {
+    const deadline = Date.now() + 10000;
+    for (let i = 1; ; i++) {
+      const cookie = `cookie-live-${i}`;
+      let unsubscribe: () => void = () => {};
+      const observed = new Promise<boolean>(resolve => {
+        unsubscribe = watcherInstance.onFileEvent(change => {
+          if (change.relativePath === cookie) {
+            resolve(true);
+          }
+        });
+      });
+      await writeFile(join(watchRoot, cookie), '');
+      const live = await Promise.race([
+        observed,
+        new Promise<boolean>(resolve => setTimeout(() => resolve(false), 200)),
+      ]);
+      unsubscribe();
+      if (live) {
+        break;
+      }
+      invariant(
+        Date.now() < deadline,
+        `${watcherName} watch never became live`,
+      );
+    }
+  }
+
   const eventHelpers: EventHelpers = {
     nextEvent: afterFn =>
       Promise.all([