Test failures on 32bit node - issues with timestamps

[CurryKitten]

Running the test suite via npm test on 32bit node versions is failing on -

1. .dest() with custom times calls futimes when an mtime is provided on the vinyl stat:
2. .dest() with custom times calls futimes when provided mtime on the vinyl stat is valid but provided atime is invalid:
3. .dest() with custom times writes file atime and mtime using the vinyl stat:
4. updateMetadata updates times on fs and vinyl object if there is a diff:
5. updateMetadata updates the mode & times on fs and vinyl object if there is a diff:

They all fail in a similar way - which is a difference in the expected vs the actual timestamp, for example -

Uncaught Error: Expected 1472731813622 to equal 1472731813519
      + expected - actual

      -1472731813622
      +1472731813519

Running the 64bit version of node on the same machine passes the tests. Is this expected to pass on 32bit ?

[phated]

That's weird. When you say 32bit node versions, what do you mean exactly? Is that on a 32-bit OS? What is the filesystem type? Etc.

[CurryKitten]

The test machines are running 64 bit OS's, I'm running the 32-bit and 64-bit node binaries, i.e -

https://nodejs.org/dist/v4.5.0/node-v4.5.0-linux-x86.tar.xz
https://nodejs.org/dist/v4.5.0/node-v4.5.0-linux-x64.tar.xz

Filesystems are ext4. As I say I can run both versions of node on the same machine/environment and the 32bit version throws up this odd error.

[OpenGG]

For updated tests, see #208 (comment)

Test enviroment:

• Debian 8
• ext4 file system

Tested Node.js versions:

• 0.10.48-x86
• 4.5.0-x86
• 8.1.2-x86

Results:

• The test cases @CurryKitten mentioned fail in v4.5.0-x86. The mtime passed to fs.futimes() and the one read from fs.statsSync() drift by a few hunderds of milliseconds, less than a second.
• But the cases pass in v0.10.48-x86 and v8.1.2-x86.

Conclusion:

0. Maybe an old bug in Node.js, and now fixed? Needs further investigation. Maybe I will do a test with major Node.js versions.
1. It is not likely a bug in vinyl-fs.

I suggest rewriting the test cases, change

expect(futimesSpy.calls.length).toEqual(1);
expect(stats.mtime.getTime())
  .toEqual(mtime.getTime());  // stats.mtime drifts in Node.js@v4.5.0-x86

into

expect(futimesSpy.calls.length).toEqual(1);
expect(futimesSpy.calls[0].arguments[2].getTime())
  .toEqual(mtime.getTime());  // check args instead

[phated]

Linked @OpenGG's research to citgm.

[OpenGG]

After digging a little more, and put up a test across major Node.js versions, conclusion:

1. atime and mtime read from fs.lstats() do not guarantee to be the same with the ones written by fs.futimes() and fs.utimes().
2. The current implementation of fs.futimes() and fs.utimes() divides timestamp by a 1000, i.e. milliseconds to seconds. This int-to-float operation loses precision. https://github.com/nodejs/node/blob/master/lib/fs.js#L1182
3. These conclusions can be applied to all major Node.js versions, x64 and x86, Linux and Windows. Maybe x86 are easier to encounter this issue.

This issue roots in fs implementation of Node.js and there is nothing vinyl-fs can do to maintain the mtime and atime precision.

As for the testing code, rewriting the cases as I mentioned above should be fine.

[OpenGG]

Also related: jprichardson/node-fs-extra#269 (comment)

[erikkemperman]

@OpenGG Just to be clear, this might happen on x64 archs but only when node is running 32-bit, correct? Otherwise the division by 1000 should not cause loss of precision (on the order of milliseconds).

I think your suggested changes to vfs tests make sense, checking the arguments is enough to establish that we're at least asking futimes to do the right thing. Having said that, perhaps this quirk warrants a little note in the documentation is well.

@phated Does this sound reasonable?

[phated]

@erikkemperman both of those things sound completely reasonable. Want to tackle it?

[phated]

Thanks again @OpenGG!