Gary K. Griffey wrote:Ok...followed your list

Almost. I also wanted you to perform a capture, open your VM, close it, and immediately capture the drive again without restarting; and then do the same again with a restart in between stopping the VM and capturing. (And, of course, send a diagnostic report when you're done.)

You stated that when running FSEventer you saw change event being logged for your VM image package. I wanted to see if you could catch OS X reporting a change event for something that happened very recently, but then not report something that should have been saved between restarts.

By the way, what is the path to your VM file—the one that should be in the events history?

So...it appears that OSX and FSEvenetsd are at fault here...your thoughts?

It would appear so, which is disappointing. I can fix QRecall, I can't fix OS X...

It seems that if this was a common issue there would be a lot of "long faces" out there come restore time.

This is the first instance that I've ever seen where file system events didn't record a change event.

I just don't see how Finder could "know" about the directory update but evidently not FSEventsd...

Like I said, there are two sources of file system change events: The live event stream that is broadcast to procsses as events occur and the historic events recorded on the volume. The Finder subscribes to the live stream. QRecall, Time Machine, and so on request historic change events. (Actually, that's not entirely true; Both Time Machine and QRecall request historic events, and then switch to the live stream during the backup so they can catch additional changes as they happen.)

But the point is, just because file system events detects and broadcast a change event doesn't (apparently) guarantee that it's also getting saved and replayed in the future.

Also, any suggestions or thoughts as to why FSEventsd is not working?

I'd like to stick with the theory that the fseventsd process is receiving change events, but failing to record them permanently for some reason. So after running the experiment that I mentioned above, try this experiment:

In the Terminal, issue this commands:
$ sudo mv /.fseventsd /fseventsd-suspect
(you'll be prompted for your password)
$ sudo chown -R $UID /fseventsd-suspect

Restart your computer.

Now perform the "capture, run VM, restart, capture" sequence again and see if it works any differently.

If that works, then there may have been something weird with the records stored in your .fseventsd folder. Please archive the fseventsd-suspect folder you'll find at the root of your hard drive and e-mail that to me. I'd like to include it my bug report to Apple.

could the VMWare Fusion application somehow be suppressing this from FSEventsd?

There's no official API for doing this. An application can flush (erase) all of the history on a volume and there's a means for disabling file system events on a volume, but there's no API for selectively deleting or suppressing change events for an individual folder.

Apple does provide an API for excluding individual items from a Time Machine backup, but that shouldn't interfere with file system events. If it is, then that's a bug.

But as I mentioned very early on, it might have something to do with the nature of the VMWare system. Virtual machines interface with the operating system at a very low level. It's entirely possible that VMWare is making changes to the file system in such a way that the operating system isn't seeing it, or doesn't believe that it's significant enough to record for posterity. It's also possible that VMWare doesn't like Time Machine trying to copy its VM image and has figured out how to "hack" the file system events service into not recording specific changes.

Out of curiosity, does the VMWare system provide any means of automatically running a script, ideally when the VM shutsdown? It might be possible to work around this problem by adding a script that touches the VM image whenever you shut down.

Another thing you might try is create a second capture action the captures just the VM Image package. Assuming the package doesn't have subfolders, QRecall always captures the items that are in its capture set. It only consults the file system events to determine if subfolders need to be captured. In essence, this would ignore file system events for the one VM image folder.

James,

Ok...will do...

I will retry the VM start/stop, then recapture without the system restart...but I know that this worked before...so, I believe that the issue is related to persisting the events through a restart...but I will retest just to make sure...

I will also give the Terminal commands a shot and let you know...

Thanks,

Gary

Whoops I forgot...


The VM Directory is:

USERS/Gary/Documents/Virtual Machines


GKG

James,

I can now confirm...it is the system restart which causes the event to be dropped. If you start/stop the VM...and then run the Capture without a system restart...it captures the VM as expected every time. If you do perform the restart...even waiting 3 or 4 minutes after closing down the VM...the VM is not captured.

So it seems there is no event persistence through a system restart...I will try your Terminal commands and see if that makes a difference.

Gary

James,

Ok...I entered your Terminal commands to rename the .fseventsd folder...

I then cycled the VM...rebooted....and ran a Capture. The Capture used the "deep traversal"...even though QRAuditFileSystemHistoryDays was set to the default value....I guess because .fsevenetsd was recreated?

I then, however, cycled the VM again...restarted the computer...and ran another capture...this one missed the VM...so it still does not work correctly. I am attaching the .fseventsd-suspect folder as a single zip file.

I hope this provides the info you need to supply Apple with a bug report. I guess for now...I will have to run all my captures using QRAuditFileSystemHistoryDays = 0.0...just to be sure everything is backed-up.

Thanks,

Let me know if you need any more info...

Gary

Gary K. Griffey wrote:I then cycled the VM...rebooted....and ran a Capture. The Capture used the "deep traversal"...even though QRAuditFileSystemHistoryDays was set to the default value....I guess because .fsevenetsd was recreated?

That's correct. When QRecall requests historic file system event information for a date earlier than what's in the database, it receives a message that basically says "there's no history for that period, you're on your own," so QRecall has to do it the hard way.

I then, however, cycled the VM again...restarted the computer...and ran another capture...this one missed the VM...so it still does not work correctly. I am attaching the .fseventsd-suspect folder as a single zip file.

Thanks. I'll also ask that you send another diagnostic report (Help > Send Report) so I can report the actual events it did receive and what was expected.

I hope this provides the info you need to supply Apple with a bug report.

I'll report this to Apple, and I thank you for your patience and perseverance in isolating this problem. I would also suggest that you bring this to the attention of VMWare, or I'll be happy to do so on your behalf. I strongly suspect that this has something to do with VMWare. As I've mentioned, software that hosts a virtual operating system do not interact with OS X the way normal software does, which may result in side-effects like the one you're seeing.

I guess for now...I will have to run all my captures using QRAuditFileSystemHistoryDays = 0.0...just to be sure everything is backed-up.

Have you tried some of the other workarounds (shutdown script, separate capture)? I'd be really surprised if this was a fundamental flaw in file system events. I've been working intimately with the FSEvents API since Leopard and this is the first time I've ever seen it miss or forget a change event (at least outside the reasons that are known to trip it up).

James,

Ok...I have sent the report from the test laptop.

I guess as far as running incremental captures with QRAuditFileSystemHistoryDays = 0.0 is concerned...my concern is that there could be other folders/files that are also being inadvertently "missed" by FSEventsd...it just seems odd to me that a virtual machine folder is the only one that could experience this issue...although I have no proof, of course, that other folders are not being backed-up...

Certainly, the overhead for performing the full deep system scan each time can be huge...no doubt...possibly, if you believe this to be isolated to virtual machine folders only...I will take your advice and split this into 2 backup actions...one for the entire volume that specifically excludes the single VM directory...and another that only includes the VM directory...since you stated that the named target directory itself is always "deep scanned"...and only sub-directories employ the FSEventsd logic.

Thanks...If you need any more info or testing...please let me know...

Gary

Gary K. Griffey wrote:I guess as far as running incremental captures with QRAuditFileSystemHistoryDays = 0.0 is concerned...my concern is that there could be other folders/files that are also being inadvertently "missed" by FSEventsd...it just seems odd to me that a virtual machine folder is the only one that could experience this issue...although I have no proof, of course, that other folders are not being backed-up...

As I've mentioned, virtual machines do not interact with the file system the way other software does. It's been my experience that file system events is reliable, which is why I was initially very reluctant to implicate it as the source of your problems. If it weren't I'd have a lot of complaints from other QRecall users, and thousands of Time Machine users would be tearing up Apple's support forums; neither of which have happened.

Certainly, the overhead for performing the full deep system scan each time can be huge...no doubt...possibly, if you believe this to be isolated to virtual machine folders only...

It's not horrendous, but it will add 10-20 minutes to each capture.

I will take your advice and split this into 2 backup actions...one for the entire volume that specifically excludes the single VM directory...and another that only includes the VM directory...since you stated that the named target directory itself is always "deep scanned"...and only sub-directories employ the FSEventsd logic.

Don't exclude the VM directory from the full capture. Excluding an item treats the item as if it didn't exist, which will create a layer where your VM folder doesn't exist at all. Keep your current action that captures the entire volume, then create a second action that captures just the VM folder. Schedule the new action to run immediately after the first.

And please keep me posted on any future developments...

James,

Thanks for the update...

I will setup the two actions per your instructions and give it a try.

I am also a bit puzzled by the lack of "noise" from Time Machine users. I certainly know that Time Machine is an "ugly" way of backing-up virtual machines...since their virtual disks are very large and change constantly if the VM is running...still, many of my clients use Windows VM's...and, they use Time Machine to back them up.

I have, however, confirmed, that as you would expect...if you perform the same test plan that we used with QRecall...i.e., Start/Stop the VM...shutdown system...upon system restart...Time Machine does NOT capture the VM either...

Thanks,

GKG

James,

I believe that I may have stumbled across the reason for my VM's not being backed-up using FSEventsd...possibly, you have already deduced this from the sent reports, etc....but I thought it may be worth recapping.

It seems that the directory that contains the VM package files is not being updated when a virtual machine inside of it has been updated (i.e., started and stopped). This can be easily observed directly in Finder...normally, when you update, say an individual text document inside of the Documents folder...both the Documents folder and the specific text document reflect the new updated timestamp.

This is not true when it comes to VMWare virtual machines...when a virtual machine is started and stopped...the virtual machine's specific package folder does reflect the updated time stamp as seen in Finder...but the enclosing folder does not.

For example, right now I have a virtual machine in a folder...the virtual machine's package has a Finder time stamp of 13:37 today...however, its enclosing folder has a time stamp of 13:15...meaning the enclosing folder did not get notified that one of its component objects has been updated.

And obviously, when you create a QRecall action that points directly at the enclosing folder...the VM package(s) are backed up...if they have been updated.

So...it looks like, as you so stated...the virtual machine process is somehow updating the individual package folder but not updating the enclosing folder...how VMWare Fusion is accomplishing this is not at all clear to me. I would think the OS should not allow this at all.

Any comments?

Thanks,

GKG

Gary K. Griffey wrote:It seems that the directory that contains the VM package files is not being updated when a virtual machine inside of it has been updated...

I might have explained this earlier, if not ...

Modifying a file in a folder (directory) does not change the modification data of the directory. The modification date of a directory indicates that the contents of that directory "file" has changed. (In UNIX, a directory is conceptually a file containing metadata about other files.) If you create, delete, or rename an item in a directory this changes the logical contents of the directory "file", which in turn updates it's modification date.

Merely changing the contents of a file within that directory does not change the directory, and thus does not change the directory's modification date. It only changes the modification date of the file that changed.

There are a variety of reasons it works this way, some abstract (UNIX's "everything's a file" philosophy) and some practical (the less that has to change the faster changes can be made).

Now, I'm sure you're wondering why sometimes when you save a file the modification date of the enclosing folder changes. The reason is that many applications use a technique called a "safe save" to write documents. The contents of the document are written to some temporary, often invisible, location on the drive. When the document has been completely saved, the original document is deleted and the new document is moved into its place. This avoids the possibility of destroying the only good copy you had of the document if the save operation failed to complete successfully. The acts of deleting and renaming the document files are a directory changes, which naturally update the modification date of the enclosing folder.

Really huge files, like VM images and QRecall archives, can't be updated in this manor; it's just not practical. Updates to those kinds of files only change the data within the file and don't touch the enclosing folder. Now you may notice that the last modified date of a QRecall archive changes when it's updated, and that's because QRecall goes out of its way to update (touch) the enclosing package folder when its done. This is so that both you and Spotlight see that the contents of the archive have changed. However, software is not obligated to do this and a folder's modification date can remain unchanged for months, even though its contents are changing constantly.

If you're curious, you can see this in the Finder too. Create a folder and save a small text file (e.g. TestFile.txt) inside that folder. In the Terminal, use a command like "echo 'hi' >> TestFile.txt" to append some new data to that file. The modification date of the file will change, but the modification date of the folder will not.

James,

Thanks for the explanation...makes sense...

So far...the 2 separate capture actions seem to be doing the job well...

Thanks again for all your help on this issue.

Thanks,

GKG