Investigate flaky test-regress-GH-4027 on Windows

[Trott]

• Version: 9.0.0-pre
• Platform: win2012r2,vs2015
• Subsystem: test

https://ci.nodejs.org/job/node-test-binary-windows/9310/RUN_SUBSET=1,VS_VERSION=vs2015,label=win2012r2/console

not ok 387 sequential/test-regress-GH-4027
  ---
  duration_ms: 5.421
  severity: fail
  stack: |-
    assert.js:60
      throw new errors.AssertionError({
      ^
    
    AssertionError [ERR_ASSERTION]: 0 === 1
        at StatWatcher.<anonymous> (c:\workspace\node-test-binary-windows\RUN_SUBSET\1\VS_VERSION\vs2015\label\win2012r2\test\sequential\test-regress-GH-4027.js:35:10)
        at StatWatcher.<anonymous> (c:\workspace\node-test-binary-windows\RUN_SUBSET\1\VS_VERSION\vs2015\label\win2012r2\test\common\index.js:517:15)
        at emitTwo (events.js:125:13)
        at StatWatcher.emit (events.js:213:7)
        at StatWatcher._handle.onchange (fs.js:1454:10)

/cc @nodejs/testing @nodejs/platform-windows

Perhaps a race condition triggered by system load, which probably explains why it's in sequential and not parallel in the first place?

[refack]

Perhaps a race condition triggered by system load, which probably explains why it's in sequential and not parallel in the first place?

Yes this is a timing balancing act, supposed to do

1. fs.writeFileSync
2. setTimeout(fs.unlinkSync, 100
3. fs.watchFile(filename, { interval: 50 }

[Trott]

Another one:

https://ci.nodejs.org/job/node-test-binary-windows/9429/RUN_SUBSET=3,VS_VERSION=vs2015,label=win2012r2/console

not ok 387 sequential/test-regress-GH-4027
  ---
  duration_ms: 6.187
  severity: fail
  stack: |-
    assert.js:60
      throw new errors.AssertionError({
      ^
    
    AssertionError [ERR_ASSERTION]: 0 === 1
        at StatWatcher.<anonymous> (c:\workspace\node-test-binary-windows\RUN_SUBSET\3\VS_VERSION\vs2015\label\win2012r2\test\sequential\test-regress-GH-4027.js:35:10)
        at StatWatcher.<anonymous> (c:\workspace\node-test-binary-windows\RUN_SUBSET\3\VS_VERSION\vs2015\label\win2012r2\test\common\index.js:520:15)
        at emitTwo (events.js:125:13)
        at StatWatcher.emit (events.js:213:7)
        at StatWatcher._handle.onchange (fs.js:1454:10)
  ...

[jaimecbernardo]

Investigated this issue. Managed to replicate it on a VM by capping the CPU. The issue seems to be that the watched file is getting deleted before the internals of watchFile are able to get the first state of the file, so watchFile behaves as if the file doesn't exist and calls the callback with prev.nlink and curr.nlink at 0.

Increasing the delay before unlinking to 300ms and calling setTimeout after watchFile caused it to stop reproducing.

Created a PR: #14010