Shadow Copy Puzzle Partly Deciphered

In yesterday’s blog, I reported on the appearance of reports for numerous (9 one day, 10 the next) “corrupt and unusable” VolumeShadowCopyXX entries in the System Log in Event Viewer. All of these originated from source Ntfs, the Vista file system manager.

As I researched the matter, it looked like the best way to fix the problem would be to disable automatic daily restore point generation (which creates a volume shadow copy as part of its operation) for my primary C: and D: hard drives. This automatically deletes all existing volume shadow copies related to restore points from the volume shadow store. After that, of course, I re-enabled automatic restore points because I didn’t want to lose this functionality altogether. I also captured an image backup of my system before conducting this operation, in case I should ever need access to one of the older Restore Points about to be wiped out.

Much to my surprise, I observed reports about the same shadow copies in the System Log for the next day as well. This led me to imagine that perhaps the old volume shadow copies really hadn’t been deleted after all, or that perhaps the corrupt entries were related to recent backups (which also result in the generation of volume shadow copies for drives being backed up as well).

I’m happy to report that the next day’s batch of log entries were not really from the next day after all. Although they appeared to be, their appearance is a function of how the Reliability Monitor and Event Viewer work. As it happens, my system generates automatic volume shadow copies and restore points at the stroke of midnight, and Reliability Monitor always lags one day behind the actual calendar date in the data sets it makes visible.

This means that onĀ  a Monday, the automatic volume shadow copy started in the first hour of that day. But because I can’t see what’s going on for Monday in Reliability Monitor until Tuesday morning, the information lags a day behind. Thus, what I saw in Reliability Monitor on Tuesday reflected log entries from Monday, before I went through the disable/re-enable dance with Automatic restore points on the System Protection tab in the System Properties window. Automatic restore points are working as expected, as the following screenshot shows.

New automatic restore points working successfully

The first automatic restore points created under the new regime were created yesterday.

A different look at Event Viewer shows that the last Ntfs error reports occurred on Monday, 9/2, before the disable/re-enable operation took place. This really means that there haven’t been any such reports since the manuever was completed, and in turn indicates that there are no more corrupt volume shadow copies to report. Thus, the cause of the problem appears to have been removed, so in a certain sense the problem has beenĀ  solved.

Filters on System log show last NTFS error reported on 9/29

The most recent NTFS error reports about corrupt, unusable Volume Shadow Copies pre-date the automatic restore point manuever.

Now, if I could only figure out what caused those shadow copies to go south in the first place. I do have a theory, however, and the lack of new complaints may indicate my theory is correct, or it may indicate it’s irrelevant. My theory is that because I had the Carbonite backup program scheduled to run at about the same time as the automatic restore point capture was running, the two processes were getting in each other’s way, and causing volume shadow copy contention and possibly corruption (remember, backup also reads from and writes to shadow copy files as well). I’ve rescheduled Carbonite to run at 10:30 PM at night, and the automatic restore points get generated at 2:05 PM in the afternoon, more than 8 hours earlier. This should keep them from stepping on each other’s toes from here on out.

Case closed? I certainly hope so!


Leave a Reply

Your email address will not be published. Required fields are marked *