2

Our C++ application is using FSEventStream to monitor the filesystem with file-level granularity (creating the stream with the kFSEventStreamCreateFlagFileEvents flag), with one listener per volume. However, there appears to be some bugs/misfeatures in the Apple FSEvent API, stemming from how they compress (remove duplicate) events from the stream before sending them to us:

  1. Minor, but annoying: when starting up the stream using a previous event id as a starting point (in order to capture changes to the filesystem since the last time we were monitoring), the order of the events provided is different from what we get if we're listening to the events as they occur, in that the events don't arrive in eventId order, but instead sorted alphanumerically by filename. We've worked around this issue by accumulating all the historical events in an id-sorted list before processing the set.

  2. Major: If rename events occur fast enough, the actual events being given to us in the callback function do not represent what has actually happened on the filesystem. Consider our test case where we swap dir names:

    a. change a file

    b. rename its parent dir to _temp

    c. rename another dir to name of previous parent

    d. rename _temp to the dir in step c.

If we put a 50 ms delay in between each of these steps (essentially, any delay which guarantees that a given event will not be in the same callback as another event), we get the correct sequence of events (with renames showing up as pairs of events):

fsEventsCallback: Received FSEvents callback with 1 events:
fsEventsCallback: ID=34303406 PATH= /Users/stebro/swaptest/subdir1/file_1.txt FLAGS=kFSEventStreamEventFlagItemInodeMetaMod, kFSEventStreamEventFlagItemIsFile, kFSEventStreamEventFlagItemModified
fsEventsCallback: Received FSEvents callback with 2 events:
fsEventsCallback: ID=34303436 PATH= /Users/stebro/swaptest/subdir1 FLAGS=kFSEventStreamEventFlagItemIsDir, kFSEventStreamEventFlagItemRenamed
fsEventsCallback: ID=34303437 PATH= /Users/stebro/swaptest/subdir1_temp FLAGS=kFSEventStreamEventFlagItemIsDir, kFSEventStreamEventFlagItemRenamed
fsEventsCallback: Received FSEvents callback with 2 events:
fsEventsCallback: ID=34303620 PATH= /Users/stebro/swaptest/subdir2 FLAGS=kFSEventStreamEventFlagItemIsDir, kFSEventStreamEventFlagItemRenamed
fsEventsCallback: ID=34303621 PATH= /Users/stebro/swaptest/subdir1 FLAGS=kFSEventStreamEventFlagItemIsDir, kFSEventStreamEventFlagItemRenamed
fsEventsCallback: Received FSEvents callback with 2 events:
fsEventsCallback: ID=34303741 PATH= /Users/stebro/swaptest/subdir1_temp FLAGS=kFSEventStreamEventFlagItemIsDir, kFSEventStreamEventFlagItemRenamed
fsEventsCallback: ID=34303742 PATH= /Users/stebro/swaptest/subdir2 FLAGS=kFSEventStreamEventFlagItemIsDir, kFSEventStreamEventFlagItemRenamed

However, with no delay (or a delay small enough that the multiple rename events will arrive in the same callback invocation), it appears that the OS is doing use the "favor" of removing what it sees as redundant events, resulting in this mess:

fsEventsCallback: Received FSEvents callback with 4 events:
fsEventsCallback: ID=34251572 PATH= /Users/stebro/swaptest/subdir1/file_1.txt FLAGS=kFSEventStreamEventFlagItemInodeMetaMod, kFSEventStreamEventFlagItemIsFile, kFSEventStreamEventFlagItemModified
fsEventsCallback: ID=34251580 PATH= /Users/stebro/swaptest/subdir1 FLAGS=kFSEventStreamEventFlagItemIsDir, kFSEventStreamEventFlagItemRenamed
fsEventsCallback: ID=34251583 PATH= /Users/stebro/swaptest/subdir1_temp FLAGS=kFSEventStreamEventFlagItemIsDir, kFSEventStreamEventFlagItemRenamed
fsEventsCallback: ID=34251584 PATH= /Users/stebro/swaptest/subdir2 FLAGS=kFSEventStreamEventFlagItemIsDir, kFSEventStreamEventFlagItemRenamed

Is there something we can do to suppress this compression? We're creating the stream using this call:

FSEventStreamCreateRelativeToDevice(kCFAllocatorDefault,
                                    &fsEventsCallback,
                                    &context,
                                    device,
                                    reinterpret_cast<CFArrayRef>(_monitoredPaths),
                                    lastEventId,
                                    0, // Latency - problem exists with values of 1, 0.1 and 3 as well
                                    kFSEventStreamCreateFlagFileEvents | kFSEventStreamCreateFlagNoDefer);
Steve Broberg
  • 4,255
  • 3
  • 28
  • 40
  • Well, it's not technically lying. Those 4 events did occur within an update period. It's true you can't look at them in isolation to tell that the user swapped subdir1<->subdir2, but you couldn't actually tell that in the first case, either (they could have been renamed to/from paths outside of your `_monitoredPaths` at just the same time). – Ssswift Apr 26 '17 at 18:03
  • It's lying by omission, though. And although you're technically correct about the first case involving moves outside the monitored area, it could be mitigated by simply monitoring "/" for the volume and receiving all events. As it stands, the current implementation may as well not even bother giving rename events, since they can never be trusted to be correct. – Steve Broberg Apr 26 '17 at 20:21

1 Answers1

1

The solution for overly aggressive event folding can be using kFSEventStreamCreateFlagUseExtendedData (available since OS X 10.13). A stream created with that flag will include the inode of the event file. That way you can detect "rename chains" that happened in a reported event batch.

P.S. I tried your scenario in my file monitor; the event sequence was correct.

Tomek Sowiński
  • 863
  • 5
  • 16