fs.watch has double change events for file writes

[andy-hanson]

Run these commands:

echo "require('fs').watch(__dirname).on('change', console.log)" > watch.js
node watch.js &
echo "" > watch.js

To get this output:

change watch.js
change watch.js

I'm running node v4.1.1 on Linux Mint 17.

[targos]

I cannot reproduce on OSX

[silverwind]

Also cannot reproduce on two Linux boxes.

[nwoltman]

I was able to reproduce this consistently on Windows 7.
Tested on several versions all the way back to v0.10.0 and it was still there.

[nwoltman]

Looks like the root of the problem is in libuv. Most likely this line is getting called twice.
Of course, it's quite possible that there's nothing wrong with libuv and it's just Windows/Mint emitting two events for the same thing.

[bnoordhuis]

Might be an artifact of the file system or the kernel. I can't reproduce on 4.0.4-301.fc22.x86_64 with ext4.

Can you run strace -o trace.log node watch.js and gist the contents of trace.log? Please post the output of uname -a as well.

[andy-hanson]

uname -a: Linux andy-Inspiron-3647 3.13.0-24-generic #47-Ubuntu SMP Fri May 2 23:30:00 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux
For trace.log, I had to modify the command to strace -o ../trace.log node watch.js to avoid an infinite loop. Then I got this: https://gist.github.com/andy-hanson/ca73a470707ff023786e

[bnoordhuis]

@andy-hanson Thanks. The salient bits:

epoll_wait(5, {{EPOLLIN, {u32=9, u64=9}}}, 1024, -1) = 1
read(9, "\1\0\0\0\2\0\0\0\0\0\0\0\20\0\0\0watch.js\0\0\0\0\0\0\0\0"..., 4096) = 64
write(10, "change watch.js\n", 16)      = 16
write(10, "change watch.js\n", 16)      = 16

The kernel is returning two 32 byte inotify events. The second one got cut off here but I'm willing to bet that if you pass -s 256 to strace, you're going to see watch.js in there twice.

[andy-hanson]

@bnoordhuis Your were right. I've ran with -s 256 and updated the gist.

[bnoordhuis]

Thanks. I don't think there is much we can do here, it's the kernel that delivers two distinct IN_MODIFY events.

Libuv could coalesce them but then it has to pick a completely arbitrary time window to coalesce them in. It won't prevent duplicate events, just make them less prevalent. I suggest we leave well enough alone.

[jasnell]

Assuming this one is safe to close.