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-watchfile failure on OSX - intermittent ? #13248

Closed
mhdawson opened this issue May 26, 2017 · 9 comments
Closed

test-fs-watchfile failure on OSX - intermittent ? #13248

mhdawson opened this issue May 26, 2017 · 9 comments
Labels
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

@mhdawson
Copy link
Member

  • Version: master
  • Platform: OSX
  • Subsystem: fs

Failure in CI testing PR with changes unrelated to fs watch

https://ci.nodejs.org/job/node-test-commit-osx/10086/nodes=osx1010/console

not ok 664 parallel/test-fs-watchfile
  ---
  duration_ms: 60.45
  severity: fail
  stack: |-
    timeout
  ...
@mhdawson
Copy link
Member Author

@Trott
Copy link
Member

Trott commented May 26, 2017

I can replicate this locally with this command:

tools/test.py --repeat 100 -j 64 test/parallel/test-fs-watchfile.js 

It doesn't trigger failures every time, but often enough that I haven't had to run it more than 5 times to get a failure yet.

This suggests that the issue is triggered by high load. Simple solution could be to move the test to sequential so it is not competing for resources with other tests.

One curiosity: When it times out with the above command line, it is always starting after the 36th or 37th successful run. Not sure what that means. But maybe someone more macOS savvy would. @nodejs/platform-macos

@mscdex mscdex added 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. labels May 26, 2017
@refack
Copy link
Contributor

refack commented May 26, 2017

Maybe #13111

@refack
Copy link
Contributor

refack commented May 26, 2017

Probably my fault, I said it would work without common.refreshTmpDir()

@refack
Copy link
Contributor

refack commented May 27, 2017

Have a PR borrowing

@chris--young
Copy link

chris--young commented May 27, 2017

@refack you had mentioned that having common.refreshTmpDir() in there could cause the test to fail on Windows. Is there anyway to avoid that?

Edit: After a quick test, it appears that this is still reproducible even after adding common.refreshTmpDir(). Still could be related to my changes though.

@refack
Copy link
Contributor

refack commented May 27, 2017

Yeah, make sure that you rmdir before.
Did it in #13251

@Trott
Copy link
Member

Trott commented May 27, 2017

I could be wrong, but I don't think removing files plays a part here.

I think the issue is that (on macOS at least) this is a race condition:

    fs.watch(dir, common.mustCall(function(eventType, filename) {
      this._handle.close();
      assert.strictEqual(filename, 'foo.txt');
    }));

    fs.writeFile(`${dir}/foo.txt`, 'foo', common.mustCall(function(err) {
      if (err) assert.fail(err);
    }));

My recollection is that (on macOS at least) you are not guaranteed to start receiving events write after fs.watch() returns.

Wrapping the fs.writeFile() in a setTimeout() for 100ms makes the test reliable on my machine. I'm going to test more, but if it holds up, I'll experiment a bit more with process.nextTick(), setImmediate(), etc. before opening a PR.

Trott added a commit to Trott/io.js that referenced this issue May 27, 2017
On macOS, a watcher created with fs.watch() does not necessarily
start receiving events immediately. So it can miss a change by
fs.writefile() if it comes very soon after the watcher is created. Fix
test flakiness caused by this by using `setInterval()` to repeat the
write action.

Fixes: nodejs#13248
@Trott
Copy link
Member

Trott commented May 27, 2017

Proposed fix in #13252

@Trott Trott closed this as completed in 3b12a8d May 30, 2017
jasnell pushed a commit that referenced this issue Jun 5, 2017
On macOS, a watcher created with fs.watch() does not necessarily
start receiving events immediately. So it can miss a change by
fs.writefile() if it comes very soon after the watcher is created. Fix
test flakiness caused by this by using `setInterval()` to repeat the
write action.

PR-URL: #13252
Fixes: #13248
Reviewed-By: Refael Ackermann <[email protected]>
Reviewed-By: Luigi Pinca <[email protected]>
Reviewed-By: Benjamin Gruenbaum <[email protected]>
Reviewed-By: Colin Ihrig <[email protected]>
Reviewed-By: Michael Dawson <[email protected]>
Reviewed-By: James M Snell <[email protected]>
refack added a commit to refack/node that referenced this issue Jun 7, 2017
PR-URL: nodejs#13411
Refs: nodejs#13385
Refs: nodejs#13248
Refs: nodejs#13377
Reviewed-By: Anna Henningsen <[email protected]>
Reviewed-By: James M Snell <[email protected]>
jasnell pushed a commit that referenced this issue Jun 7, 2017
PR-URL: #13411
Refs: #13385
Refs: #13248
Refs: #13377
Reviewed-By: Anna Henningsen <[email protected]>
Reviewed-By: James M Snell <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
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
5 participants