Double modify events on Mac OS X

[paulhammond]

I've been seeing a few cases where a single modification to a file on Mac OS X causes two modification events to be sent over the chan. As first I assumed this was my editor doing something clever, but even a simple touch filename would trigger it.

I did some tests, altering TestFsnotifyAttrib to check if attribReceived.value() != 1 instead of checking for zero. This updated test case fails roughly half the time for me.

Digging even further it looks like the extra update update is being caused by mds (the daemon responsible for updating the file metadata used by spotlight). See lines 6 onwards from the output of fs_usage, which shows the name of any process performing file operations:

$ sudo fs_usage | grep TestFsnotifyAttrib.testfile
11:46:35  open              _test/TestFsnotifyAttrib.testfile                                                0.000065   fsnotify.tes
11:46:35  lstat64           _test/TestFsnotifyAttrib.testfile                                                0.000010   fsnotify.tes
11:46:35  open              _test/TestFsnotifyAttrib.testfile                                                0.000009   fsnotify.tes
11:46:35  chmod             _test/TestFsnotifyAttrib.testfile                                                0.000024   fsnotify.tes
11:46:35  access            /Users/ph/go/src/github.com/howeyc/fsnotify/_test/TestFsnotifyAttrib.testfile    0.000008   dbfseventsd 
11:46:35  getattrlist       /Users/ph/go/src/github.com/howeyc/fsnotify/_test/TestFsnotifyAttrib.testfile    0.000192   mds         
11:46:35  lstat64           /Users/ph/go/src/github.com/howeyc/fsnotify/_test/TestFsnotifyAttrib.testfile    0.000018   mdworker    
11:46:35  stat64            /Users/ph/go/src/github.com/howeyc/fsnotify/_test/TestFsnotifyAttrib.testfile    0.000013   mdworker    
11:46:35  lstat64           /Users/ph/go/src/github.com/howeyc/fsnotify/_test/TestFsnotifyAttrib.testfile    0.000009   mdworker    
11:46:35  getattrlist       /Users/ph/go/src/github.com/howeyc/fsnotify/_test/TestFsnotifyAttrib.testfile    0.000116   mdworker    
11:46:35  open              /Users/ph/go/src/github.com/howeyc/fsnotify/_test/TestFsnotifyAttrib.testfile    0.000024   mdworker    
11:46:35  getattrlist       /Users/ph/go/src/github.com/howeyc/fsnotify/_test/TestFsnotifyAttrib.testfile    0.000041   mdworker    
11:46:35  getattrlist       /Users/ph/go/src/github.com/howeyc/fsnotify/_test/TestFsnotifyAttrib.testfile    0.000116   mdworker    
11:46:35  getattrlist       go/src/github.com/howeyc/fsnotify/_test/TestFsnotifyAttrib.testfile/.DS_Store    0.000009   mdworker    
11:46:35  getattrlist       go/src/github.com/howeyc/fsnotify/_test/TestFsnotifyAttrib.testfile/.DS_Store    0.000006   mdworker    
11:46:35  getattrlist       go/src/github.com/howeyc/fsnotify/_test/TestFsnotifyAttrib.testfile/.DS_Store    0.000005   mdworker    
11:46:35  getattrlist       go/src/github.com/howeyc/fsnotify/_test/TestFsnotifyAttrib.testfile/.DS_Store    0.000005   mdworker    
11:46:35  getattrlist       /Users/ph/go/src/github.com/howeyc/fsnotify/_test/TestFsnotifyAttrib.testfile    0.000024   mds         
11:46:35  getattrlist       /Users/ph/go/src/github.com/howeyc/fsnotify/_test/TestFsnotifyAttrib.testfile    0.000010   mds         
11:46:35  unlink            _test/TestFsnotifyAttrib.testfile                                                0.000131   fsnotify.tes

(It's also worth noting that this test case consistently passes as of 2c4a662, because mds ignores temporary directories. But the problem is still there.)

I don't think this is a bug in fsnotify, but I do wonder if it's something you might want to document somewhere, possibly as part of the FAQ in the README? I'm happy to put together a pull request if you think that would be useful?

[howeyc]

I think you're right and that a mention in the README would be helpful. Others have noticed a similar issue with various editors doing fancy magic. I was unaware this mds process could be doing something as well.

[nathany]

I've also noticed modification events even when just looking at file in Tower. I'm working on a throttled watcher to mitigate the issue and hopefully #54 will help as well.

[paulhammond]

#54 is likely to change the behavior here, so I'm going to wait to see what happens there before proposing any new documentation on this...

[nathany]

@paulhammond #65 adds some rudimentary throttling

[nathany]

It turns out the throttling I implemented (or rather, borrowed from @remogatto) has limited utility in this case.

Spotlight will sometimes touch every file, whereas the throttling is for multiple events on the same file.

FSEventStream has it's own throttling behaviour built in, and presumably would get along with Spotlight better. Still, it would be nice to find a solution for mds+kqueue in the meantime.

[nathany]

@paulhammond So far our solution to this was to add a note to the README. I think we should reopen it, and perhaps create a new issue for go.exp/fsnotify over at https://code.google.com/p/go/issues/list?q=fsnotify.

Maybe we can come up with something better.