test-fs-watch-recursive-add-* tests fail intermittently on macOS

I am not sure exactly when but at least since this week I am seeing intermittent failures of test-fs-watch-recursive-add-* tests on the main branch. Trying to run with -j1 or simply re-running them directly doesn't seem to make a difference either.

❯ tools/test.py -j1 "test/parallel/test-fs-watch-recursive-add*"
=== release test-fs-watch-recursive-add-file ===
Path: parallel/test-fs-watch-recursive-add-file
node:assert:90
  throw new AssertionError(obj);
  ^

AssertionError [ERR_ASSERTION]: Expected values to be strictly equal:
+ actual - expected

+ 'change'
- 'rename'

    at FSWatcher.<anonymous> (/Users/joyee/projects/node/test/parallel/test-fs-watch-recursive-add-file.js:34:10)
    at FSWatcher.emit (node:events:507:28)
    at FSWatcher._handle.onchange (node:internal/fs/watchers:215:12) {
  generatedMessage: true,
  code: 'ERR_ASSERTION',
  actual: 'change',
  expected: 'rename',
  operator: 'strictEqual'
}

Node.js v24.0.0-pre
Command: out/Release/node /Users/joyee/projects/node/test/parallel/test-fs-watch-recursive-add-file.js


=== release test-fs-watch-recursive-add-file-to-existing-subfolder ===
Path: parallel/test-fs-watch-recursive-add-file-to-existing-subfolder
node:assert:90
  throw new AssertionError(obj);
  ^

AssertionError [ERR_ASSERTION]: Expected values to be strictly equal:
+ actual - expected

+ 'change'
- 'rename'

    at FSWatcher.<anonymous> (/Users/joyee/projects/node/test/parallel/test-fs-watch-recursive-add-file-to-existing-subfolder.js:43:10)
    at FSWatcher.emit (node:events:507:28)
    at FSWatcher._handle.onchange (node:internal/fs/watchers:215:12) {
  generatedMessage: true,
  code: 'ERR_ASSERTION',
  actual: 'change',
  expected: 'rename',
  operator: 'strictEqual'
}

Node.js v24.0.0-pre
Command: out/Release/node /Users/joyee/projects/node/test/parallel/test-fs-watch-recursive-add-file-to-existing-subfolder.js


=== release test-fs-watch-recursive-add-file-with-url ===
Path: parallel/test-fs-watch-recursive-add-file-with-url
node:assert:90
  throw new AssertionError(obj);
  ^

AssertionError [ERR_ASSERTION]: Expected values to be strictly equal:
+ actual - expected

+ 'change'
- 'rename'

    at FSWatcher.<anonymous> (/Users/joyee/projects/node/test/parallel/test-fs-watch-recursive-add-file-with-url.js:38:12)
    at FSWatcher.emit (node:events:507:28)
    at FSWatcher._handle.onchange (node:internal/fs/watchers:215:12) {
  generatedMessage: true,
  code: 'ERR_ASSERTION',
  actual: 'change',
  expected: 'rename',
  operator: 'strictEqual'
}

Node.js v24.0.0-pre
Command: out/Release/node /Users/joyee/projects/node/test/parallel/test-fs-watch-recursive-add-file-with-url.js


=== release test-fs-watch-recursive-add-folder ===
Path: parallel/test-fs-watch-recursive-add-folder
node:assert:90
  throw new AssertionError(obj);
  ^

AssertionError [ERR_ASSERTION]: Expected values to be strictly equal:
+ actual - expected

+ 'change'
- 'rename'

    at FSWatcher.<anonymous> (/Users/joyee/projects/node/test/parallel/test-fs-watch-recursive-add-folder.js:36:12)
    at FSWatcher.emit (node:events:507:28)
    at FSWatcher._handle.onchange (node:internal/fs/watchers:215:12) {
  generatedMessage: true,
  code: 'ERR_ASSERTION',
  actual: 'change',
  expected: 'rename',
  operator: 'strictEqual'
}

Node.js v24.0.0-pre
Command: out/Release/node /Users/joyee/projects/node/test/parallel/test-fs-watch-recursive-add-folder.js


[00:00|% 100|+   1|-   4]: Done

Failed tests:
out/Release/node /Users/joyee/projects/node/test/parallel/test-fs-watch-recursive-add-file.js
out/Release/node /Users/joyee/projects/node/test/parallel/test-fs-watch-recursive-add-file-to-existing-subfolder.js
out/Release/node /Users/joyee/projects/node/test/parallel/test-fs-watch-recursive-add-file-with-url.js
out/Release/node /Users/joyee/projects/node/test/parallel/test-fs-watch-recursive-add-folder.js

@mcollina

Take test-fs-watch-recursive-add-file-with-url.js for example, it seems instead of emitting just rename for file-8.txt, fs.watch also emits change for test-5 first. I am not sure if this is expected behavior, if it is expected that adding files would also incur a change event for the directory, then I think it's the tests that should be updated. cc @mcollina @anonrig

@Ceres6

I don't know if it's related, but @Ceres6 reported that after updating macOS from 14.x to 15.x, this behaviour has been happening almost all the time.
We will investigate, as we're working together on a fix related to the file watcher: #55565

@santigimeno

I also reported it on Slack: https://openjs-foundation.slack.com/archives/C019Y2T6STH/p1728922765557729

@santigimeno Suggested to try this patch (I didn't have the time to test it):

diff --git a/test/parallel/test-fs-watch-recursive-add-file.js b/test/parallel/test-fs-watch-recursive-add-file.js
index 27b933871c..68c17890fc 100644
--- a/test/parallel/test-fs-watch-recursive-add-file.js
+++ b/test/parallel/test-fs-watch-recursive-add-file.js
@@ -28,22 +28,32 @@ fs.mkdirSync(testDirectory);
 
 const testFile = path.join(testDirectory, 'file-1.txt');
 
-const watcher = fs.watch(testDirectory, { recursive: true });
-let watcherClosed = false;
-watcher.on('change', function(event, filename) {
-  assert.strictEqual(event, 'rename');
-
-  if (filename === path.basename(testFile)) {
-    watcher.close();
-    watcherClosed = true;
-  }
-});
-
-// Do the write with a delay to ensure that the OS is ready to notify us.
-setTimeout(() => {
-  fs.writeFileSync(testFile, 'world');
-}, common.platformTimeout(200));
-
-process.once('exit', function() {
-  assert(watcherClosed, 'watcher Object was not closed');
-});
+function doWatch() {
+  const watcher = fs.watch(testDirectory, { recursive: true });
+  let watcherClosed = false;
+  watcher.on('change', function(event, filename) {
+    assert.strictEqual(event, 'rename');
+
+    if (filename === path.basename(testFile)) {
+      watcher.close();
+      watcherClosed = true;
+    }
+  });
+
+  // Do the write with a delay to ensure that the OS is ready to notify us.
+  setTimeout(() => {
+    fs.writeFileSync(testFile, 'world');
+  }, common.platformTimeout(200));
+
+  process.once('exit', function() {
+    assert(watcherClosed, 'watcher Object was not closed');
+  });
+}
+
+if (common.isMacOS) {
+  // On macOS delay watcher start to avoid leaking previous events.
+  // Refs: https://github.com/libuv/libuv/pull/4503
+  setTimeout(doWatch, common.platformTimeout(100));
+} else {
+  doWatch();
+}

If it's working as expected and it's the test that needs to be fixed, #55592 (comment) still doesn't seem very reliable with the 200 timeout, it could just be adjusted to tolerate that change event emitted for the directory instead of only expecting one single rename event emitted for the changed file.

fix(autotest+app): repair the 10 failing regression runners (root-cau…

Navigation Menu

Repository navigation

test-fs-watch-recursive-add-* tests fail intermittently on macOS #55592

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

test-fs-watch-recursive-add-* tests fail intermittently on macOS #55592

Description

Activity

joyeecheung commented on Oct 29, 2024

pmarchini commented on Oct 30, 2024

targos commented on Oct 30, 2024

joyeecheung commented on Oct 30, 2024

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions