Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Closed
joyeecheung opened this issue Oct 29, 2024 · 4 comments · Fixed by #55605
Closed

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

joyeecheung opened this issue Oct 29, 2024 · 4 comments · Fixed by #55605
Labels
flaky-test Issues and PRs related to the tests with unstable failures on the CI. fs Issues and PRs related to the fs subsystem / file system. macos Issues and PRs related to the macOS platform / OSX. test Issues and PRs related to the tests.

Comments

@joyeecheung
Copy link
Member

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
@joyeecheung joyeecheung added test Issues and PRs related to the tests. flaky-test Issues and PRs related to the tests with unstable failures on the CI. fs Issues and PRs related to the fs subsystem / file system. labels Oct 29, 2024
@joyeecheung
Copy link
Member Author

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

@avivkeller avivkeller added the macos Issues and PRs related to the macOS platform / OSX. label Oct 29, 2024
@pmarchini
Copy link
Member

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

@targos
Copy link
Member

targos commented Oct 30, 2024

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();
+}

@joyeecheung
Copy link
Member Author

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.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
flaky-test Issues and PRs related to the tests with unstable failures on the CI. fs Issues and PRs related to the fs subsystem / file system. macos Issues and PRs related to the macOS platform / OSX. test Issues and PRs related to the tests.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants