Solved Suddenly, VSS mis-behaving

[dsperber]

I run both (a) Macrium Reflect Standard and (b) NovaBackup, as my normal everyday/everyweek backup scheme. Reflect is used for weekly "system image" backups (for my Win7 boot partition) and Novabackup is used for daily "data backups".

Both products make use of VSS (volume shadow copy), taking one before beginning their function.

For some reason, after years of no VSS-related problem whatsoever starting on Monday of this week the VSS function from Novabackup has started failing. This in turn causes subsequent errors trying to backup about 30 Windows-related files which are "client file busy".

However the VSS function from Reflect is still working perfectly.

I'm not overly concerned with the Novabackup errors, since I would use the weekly Reflect system image to restore from if I ever really did have a disaster justifying going back to a recent system image. But I'm still trying to figure out what exactly is at the root of this sudden VSS failure, and only for its use as invoked by NovaBackup.

I've done lots of hunting around, and the Event Viewer shows nothing related to VSS itself. But when I run VSSADMIN LIST WRITERS right after trying one of these problematic Novabackup jobs, it shows "timed out" for a number of the writers:

Microsoft Windows [Version 6.1.7601]
Copyright (c) 2009 Microsoft Corporation.  All rights reserved.

C:\Users\Darryl Sperber>vssadmin list writers
vssadmin 1.1 - Volume Shadow Copy Service administrative command-line tool
(C) Copyright 2001-2005 Microsoft Corp.

Writer name: 'Task Scheduler Writer'
   Writer Id: {d61d61c8-d73a-4eee-8cdd-f6f9786b7124}
   Writer Instance Id: {1bddd48e-5052-49db-9b07-b96f96727e6b}
   State: [1] Stable
   Last error: No error

Writer name: 'VSS Metadata Store Writer'
   Writer Id: {75dfb225-e2e4-4d39-9ac9-ffaff65ddf06}
   Writer Instance Id: {088e7a7d-09a8-4cc6-a609-ad90e75ddc93}
   State: [1] Stable
   Last error: No error

Writer name: 'Performance Counters Writer'
   Writer Id: {0bada1de-01a9-4625-8278-69e735f39dd2}
   Writer Instance Id: {f0086dda-9efc-47c5-8eb6-a944c3d09381}
   State: [1] Stable
   Last error: No error

Writer name: 'System Writer'
   Writer Id: {e8132975-6f93-4464-a53e-1050253ae220}
   Writer Instance Id: {4c6b9d28-8e43-4eab-88be-b022acf9f414}
   State: [7] Failed
   Last error: Timed out

Writer name: 'ASR Writer'
   Writer Id: {be000cbe-11fe-4426-9c58-531aa6355fc4}
   Writer Instance Id: {89281613-e9c2-4058-be5f-6f6edf7b7412}
   State: [7] Failed
   Last error: Timed out

Writer name: 'MSSearch Service Writer'
   Writer Id: {cd3f2362-8bef-46c7-9181-d62844cdc0b2}
   Writer Instance Id: {8fa7840e-7a9c-4324-bf56-4feeaf88138b}
   State: [7] Failed
   Last error: Timed out

Writer name: 'Shadow Copy Optimization Writer'
   Writer Id: {4dc3bdd4-ab48-4d07-adb0-3bee2926fd7f}
   Writer Instance Id: {62ce75d3-5394-47e7-b6f4-381984435efa}
   State: [7] Failed
   Last error: Timed out

Writer name: 'Registry Writer'
   Writer Id: {afbab4a2-367d-4d15-a586-71dbb18f8485}
   Writer Instance Id: {691d6cc1-a6da-43d8-92bb-b47a2d162b13}
   State: [7] Failed
   Last error: Timed out

Writer name: 'WMI Writer'
   Writer Id: {a6ad56c2-b509-4e6c-bb19-49d8f43532f0}
   Writer Instance Id: {3bc72bbf-43a2-491f-a4dd-1b3055f408af}
   State: [7] Failed
   Last error: Timed out

Writer name: 'COM+ REGDB Writer'
   Writer Id: {542da469-d3e1-473c-9f4f-7847f01fc64f}
   Writer Instance Id: {f39c4785-e877-473b-acac-d192024257a5}
   State: [7] Failed
   Last error: Timed out

Writer name: 'BITS Writer'
   Writer Id: {4969d978-be47-48b0-b100-f328f07ac1e0}
   Writer Instance Id: {0d8822d1-41da-46ea-929e-eb2576184218}
   State: [7] Failed
   Last error: Timed out


C:\Users\Darryl Sperber>

I have no idea what "timed out" means, and would like some assistance from others who might know.

I've checked VSSADMIN LIST SHADOWSTORAGE, which originally showed only about 3.5GB max size on C. Well, that seemed small, although I've never changed it from however it got allocated originally and VSS for NovaBackup has been working just fine until this week. And besides, VSS still works fine for Reflect, even with that same 3.5GB setting.

Anyway, I enlarged it with VSSADMIN RESIZE SHADOWSTORAGE /FOR=C: /ON=C" /MAXSIZE=18GB and tried the Novabackup job again. Still no luck. Still "timed out" on those same writers.

So, either 18GB is still too small (but again, 3.5GB was fine for Reflect) or there's something else responsible for this failure.


To try and figure out what's going on I really do need to know what "timed out" means. Is there some external drive location which is being looked for? I don't think so.

Anybody have any insight? Remember, this is Win7 x64 Pro, not Windows Server of any flavor.

Also, I have a second machine which is essentially identical conceptually, running all the same software. And no problem at all with VSS and NovaBackup on that machine. Again, I never had a problem with VSS at all on this machine for years, until suddenly this week when it started failing.

Anybody help?? TIA.


Just for reference, Reflect happened to have run its weekly "system image" just last night, and it's VSS function ran fine.

Here's the VSS log from Reflect:

(Gathering writer metadata...)
(Waiting for the asynchronous operation to finish...)
Initialize writer metadata ...
- Get exclude files
- Enumerate components
- Get file list descriptors
- Get database descriptors
- Get log descriptors
- Get exclude files
- Enumerate components
- Get file list descriptors
- Get database descriptors
- Get log descriptors
- Get exclude files
- Enumerate components
- Get file list descriptors
- Get database descriptors
- Get log descriptors
- Get exclude files
- Enumerate components
- Get file list descriptors
- Get database descriptors
- Get log descriptors
- Get exclude files
- Enumerate components
- Get exclude files
- Enumerate components
- Get file list descriptors
- Get database descriptors
- Get log descriptors
- Get exclude files
- Enumerate components
- Get file list descriptors
- Get database descriptors
- Get log descriptors
- Get exclude files
- Enumerate components
- Get exclude files
- Enumerate components
Discover directly excluded components ...
- Excluding writer '' since it has no selected components for restore.
- Excluding writer '' since it has no selected components for restore.
- Excluding writer 'BITS Writer' since it has no selected components for restore.
- Excluding writer 'Shadow Copy Optimization Writer' since it has no selected components for restore.
- Excluding writer 'MSSearch Service Writer' since it has no selected components for restore.
Discover components that reside outside the shadow set ...
Discover all excluded components ...
Discover excluded writers ...
Discover explicitly included components ...
Verifying explicitly specified writers/components ...
Select explicitly included components ...
 * Writer 'Task Scheduler Writer':
   - Add component \TasksStore
 * Writer 'VSS Metadata Store Writer':
   - Add component \WriterMetadataStore
 * Writer 'Performance Counters Writer':
   - Add component \PerformanceCounters
 * Writer 'WMI Writer':
   - Add component \WMI
 * Writer 'Registry Writer':
   - Add component \Registry
 * Writer 'COM+ REGDB Writer':
   - Add component \COM+ REGDB
Creating shadow set {1556deec-d030-42ba-b148-965d4dca2745} ...
- Adding volume \\?\Volume{f6fd8606-4ee6-11e1-afd0-806e6f6e6963}\ [C:\] to the shadow set...
- Adding volume \\?\Volume{f6fd8609-4ee6-11e1-afd0-806e6f6e6963}\ [O:\] to the shadow set...
Preparing for backup ... 
(Waiting for the asynchronous operation to finish...)
(Waiting for the asynchronous operation to finish...)
Creating the shadow (DoSnapshotSet) ... 
(Waiting for the asynchronous operation to finish...)
(Waiting for the asynchronous operation to finish...)
Shadow copy set succesfully created.

List of created shadow copies: 


Querying all shadow copies with the SnapshotSetID {1556deec-d030-42ba-b148-965d4dca2745} ...

* SNAPSHOT ID = {ee8e7922-4890-4983-abe5-d05a101562d6} ...
   - Shadow copy Set: {1556deec-d030-42ba-b148-965d4dca2745}
   - Original count of shadow copies = 2
   - Original Volume name: \\?\Volume{f6fd8609-4ee6-11e1-afd0-806e6f6e6963}\ [O:\]
   - Creation Time: 9/21/2012 9:30:52 PM
   - Shadow copy device name: \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy5
   - Originating machine: MDR
   - Service machine: MDR
   - Not Exposed
   - Provider id: {b5946137-7b9f-4925-af80-51abd60b20d5}
   - Attributes:  Auto_Release Differential

* SNAPSHOT ID = {e16c474f-9b43-4342-aaac-de14ee8831a5} ...
   - Shadow copy Set: {1556deec-d030-42ba-b148-965d4dca2745}
   - Original count of shadow copies = 2
   - Original Volume name: \\?\Volume{f6fd8606-4ee6-11e1-afd0-806e6f6e6963}\ [C:\]
   - Creation Time: 9/21/2012 9:30:52 PM
   - Shadow copy device name: \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy4
   - Originating machine: MDR
   - Service machine: MDR
   - Not Exposed
   - Provider id: {b5946137-7b9f-4925-af80-51abd60b20d5}
   - Attributes:  Auto_Release Differential

 

[dsperber]

Still not solved, I'm afraid.

I've done quite a bit of research, discovering a common "re-register VSS" recipe provided by Microsoft as well as other tech support sites (from various Backup software products, as well as general tech support forums). Tonight I tried that approach, but to no avail I'm afraid. Still the same writers shows "timed out" when VSS is initiated by NovaBackup.

And again, VSS initiated by Macrium Reflect still works perfectly... at least it does not complain. I forgot to run VSSADMIN LIST WRITERS after the system image backup I took tonight before trying the re-register VSS strategy, so I can't report whether any of the writers showed "timed out" or if they all appear normal. I should do it again, just to find out. But I suspect the writers utilized by Macrium Reflect may be different than those used by NovaBackup, and that may explain why one works while the other fails.


Anyway, I suspect my only true recourse is to restore a system image taken by Macrium Reflect on the evening of 9/14. Since the last valid VSS use by NovaBackup was Sunday morning 9/16, and the next morning's log (i.e. 9/17 at 9AM) showed the first VSS failure, I'm confident that restoring my system to 9/14 will get me back in business.

I have some things I must preserve before running that image restore, but should be able to do it in the next day or two. I won't lose any data or programs in this restore and can easily re-apply whatever I might have installed or updated in the past 10 days or so.

Very frustrating, not to be able to repair things.

 

[dsperber]

Just to be helpful to others, the "full re-register of VSS" for Windows 2008 and Windows 7 (as provided by this other web site, seemingly echoing a Microsoft article) is attached.

Run it as "administrator" from an elevated command prompt, and then re-boot.

It may or may not resolve your VSS problem. It didn't help me.

 

[alan10]

Create a Macrium Backup BEFORE you restore the system.
After restore has reverted the system and your documents,
you can mount the backup to retrieve your latest documents.

 

[dsperber]

Well, much to my chagrin, even after restoring the Sept 14 system image (which according to the NovaBackup logs was not exhibiting the VSS failure until 3 days later), I am now still experiencing the VSS error when running NovaBackup.

And I still do NOT have any VSS error when running Macrium Reflect.

I am at a loss to explain this, other than to now ascribe the problem to something in the environment itself... outside of Win7... since the restored system image still fails.

 

[alan10]

since the restored system image still fails.

So far as I am aware, Macrium NEVER fails to restore a VALID system image due to a VSS failure.
I really doubt that Novabackup needs VSS for a restore operation.

The ability to restore a system image should NOT depend upon the CURRENT state of VSS

 

[dsperber]

since the restored system image still fails.

So far as I am aware, Macrium NEVER fails to restore a VALID system image due to a VSS failure.
I really doubt that Novabackup needs VSS for a restore operation.

The ability to restore a system image should NOT depend upon the CURRENT state of VSS

I honestly don't understand what you just said.

The system image restore by Macrium worked perfectly from the 9/14 image it had taken. Actually even the original C-partition size had been returned as a result of the restore (although I had tried enlarging my C-partition since that time to provide more space, for VSS's use I thought).

It's not that the Macrium restore didn't restore a usable of valid system. It DID. The system imaged back on 9/14 from which the image was created was, itself, a perfectly working and usable valid system. The image taken was fine, and yesterday's restore of that image was fine.

What was NOT fine was the functionality of VSS even after restoring that image! Even though everything on C was back to how it looked on 9/14 when the image was taken, VSS still failed to work today in that restored system from 9/14... even though VSS was absolutely working properly on 9/14.


NovaBackup's use of VSS is during the BACKUP process (just as with any backup software, including Macrium). It is to be able to backup "busy files" while they are currently open. VSS isn't relevant to a RESTORE discussion.

And the restore of a system image by Macrium likewise has no relevance to an VSS discussion. There are no "busy files" concepts during RESTORE. VSS is not meaningful during RESTORE, it is only relevant during BACKUP. In fact, VSS isn't even active or possible during RESTORE of a system image by Macrium, as it's only WinPE (or even Linux, if you use the Free product and choose that approach!) which is active under which the RESTORE IMAGE function is working.


Anyway, I was not reporting any problem with Macrium Reflect during RESTORE of the 9/14 system image, which was taken on 9/14 when the system itself still had proof positive that VSS was working successfully at that time.

I was only reporting that even after restoring the 9/14 "VSS still working" system image, that VSS is STILL NOT WORKING TODAY even though the 9/14 image version of my "VSS still working" system was restored.

That's the mystery.

 

[alan10]

I have no experience of NovaBackup but I assume that it can restore the files it has backed up.

Since you appeared to indicate that Macrium worked O.K.
and then you said
"since the restored system image still fails"
I did not know if you were complaining about NovaBackup failing to restore,
or if you had changed your mind about the quality of Macrium Restore.

I thought you were under the impression that VSS was needed to achieve a restore.

I think you have said that VSS is now working for Macrium,
and you consider VSS to be failing with NovaBackup.
Perhaps you should post either here or at NovaBackup support your log files that show VSS failure.

 

[dsperber]

I have no experience of NovaBackup but I assume that it can restore the files it has backed up.

Of course it can. It has both BACKUP and RESTORE functionality.

Since you appeared to indicate that Macrium worked O.K. and then you said "since the restored system image still fails" I did not know if you were complaining about NovaBackup failing to restore, or if you had changed your mind about the quality of Macrium Restore.

My English of "the restored image still fails" should be interpreted as "VSS still fails today for NovaBackup at the beginning of its BACKUP process today, even after restoring a system image of Windows 7 from 9/14 in which VSS originally worked perfectly for NovaBackup on that date".

I thought you were under the impression that VSS was needed to achieve a restore.

Not at all. As I've stated, VSS is part of the BACKUP process, not part of any RESTORE process.

I think you have said that VSS is now working for Macrium

Yes. The Macrium system image backup process also begins with VSS, and that still works perfectly. Always has, always does, still does.

It is only VSS for Novabackup which used to work perfectly for years, until 9/17 when it stopped working. And even after restoring a Win7 system from 9/14 (when VSS was still working for NovaBackup), VSS now continues to fail for NovaBackup... while continuing to work perfectly for Macrium.

and you consider VSS to be failing with NovaBackup.

I've said that several times, but only since 9/17. It worked perfectly on 9/16 and for years before that, and has not worked ever since 9/17, neither with my ongoing Win7 system nor even with a Win7 restored from a system image of 9/14.

Perhaps you should post either here or at NovaBackup support your log files that show VSS failure.

Well, couple of problems here...

(1) NovaBackup "support" is virtually nonexistent. They are not the world's best software company, nor is their product worthy of its "rankings". Macrium Reflect's "data" backup capability is certainly equal to that of NovaBackup's, but I actually prefer the user interface of NovaBackup.

Plus, Macrium Reflect does not support backups to tape and that's one of my prerequistes... otherwise I'd probably be using Macrium Reflect for both "data" and "system image" backups and throw out NovaBackup entirely.

(2) Whereas Macrium Reflect generates and captures a VSS log for you to look at, there is no such object produced from NovaBackup. The net total sum of the fact that there was a "failure of VSS" is the following mention in the LOG from the backup job:

--- Warnings -------------------------------------------------------------------
Open File Backup    : Failed to create a volume snapshot
                    : The operation will continue without VSS support

--- Errors ---------------------------------------------------------------------
Backup Failed       : C:\ProgramData\Microsoft\eHome\SharedSBE\{3A859FE4-1BE4-4C52-9E11-8DFC83260585}.TmpSBE
                          Error e0010010: Client file is busy, retry
Backup Failed       : C:\ProgramData\Microsoft\eHome\SharedSBE\{3BC9633D-5B6B-489C-B710-50888B69F515}.TmpSBE
                          Error e0010010: Client file is busy, retry

That's it... "failed to create a volume snapshot". And when I do VSSADMIN LIST WRITERS after that, it shows most of the writers as "timed out".

In contrast, VSSAMIN LIST WRITERS after Macrium Reflect runs do not show "timed out".

Now what does that tell you??

 

[alan10]

I suspect that although you restored your system to the previous state where VSS was working for NovaBackup,
you may have since received Microsoft updates that alter how things work.

Recently Microsoft have decided that 256 bit certificates lack security and are requiring 1024 bit certificates.
Perhaps NovaBackup is no longer granted full admin privileges, possibly for that reason, so is blocked from using VSS.
I think Microsoft have published work-arounds involving registry hacks.

 

[dsperber]

I suspect that although you restored your system to the previous state where VSS was working for NovaBackup, you may have since received Microsoft updates that alter how things work.

I suppose this is possible.

But my problem diagnosis and speculation is made all that much more difficult because there are NO ENTRIES IN THE WIN7 EVENT LOG INDICATING ANY PROBLEM WHATSOEVER!

If I had an event code with an ID, that would be helpful. But all I have is VSSADMIN LIST WRITERS showing most of the writers "timed out", to support NovaBackup's mention that "VSS failed".

Again, in contrast there is ZERO such nonsense from Macrium Reflect's use of VSS, which appears to still be working perfectly.


I'm just going to turn off VSS in my NovaBackup jobs. They start faster, and no files other than those 30 or so Microsoft Security Essentials and EHOME files on C which have been producing "client file is busy". So I'll also un-check those files (or parent folders), as I have no interest in backing them up anyway... since I use Macrium Reflect's system image (taken weekly) as my true recovery from a genuine Win7 C-partition disaster.

No other files off of C (on my other normal "data" backups using NovaBackup) have ever been involved with "client file is busy". So turning VSS off for those other partitions will have nothing but positive beneficial speeding-up effect on the backup for that partition.


I'm giving up.

 

[dsperber]

Apparently, the problem was insufficient space on one drive!

Well, I do believe I have now resolved my VSS failure problem.

Because of a motherboard that died on one of my two machines, I was forced to rebuild that machine entirely. This included a new motherboard, CPU and memory, and a fresh install of Windows.

Because the new machine was "bigger and stronger" than my other still operating machine which was currently in use as my HTPC and primary work computer, I decided to swap the "bodies" of the two machines... i.e. reverse the physical locations of the two machines, double-transplanting the two "brains" into the opposite location cases while leaving the two "bodies" at the original locations.

Because the HTPC machine "brain" had a large number of copy-protected WTV recordings on its hard drives, I had to bring the existing C-drive and installed Win7 along with its hard drives containing recordings to the other location where I would then be able to continue WMC playback of those copy-once recordings using WMC on that machine. In the meantime, the newly built and installed HTPC would inherit all of the copy-freely recordings from the old HTPC, as well as start all over with a whole new set of copy-protected content.


Anyway, in the process I once again used NovaBackup extensively, including creating a whole new set of initial backups taken after the new machine was finally completely constructed and installed.

And imagine my surprise when VSS again failed (but only intermittently), even on this brand new system!

However it did give me an opportunity to pause and examine things, and finally understand what was causing the problem:

I had insufficient "free space" on one of my partitions for the shadow copy to be taken
​

That's all it was! One of my small partitions (J, about 4GB) had been loaded full of data, so that there was maybe only 100MB left of free space. And in fact it was THIS partition which was causing my "daily incremental" backup's VSS usage to fail, since J was part of the partitions scanned by the backup.

In fact, even the standalone [monthly] FULL backup of J failed its VSS usage, which is what really tipped me off as to what was the very likely cause of the VSS failure on my "daily incremental" backup covering all my partitions.

So I experimented by removing J from the "daily incremental" definition, and sure enough the "daily incremental" backup's VSS usage NOW WORKED AGAIN! Put J back in the backup job definition, and VSS usage NOW FAILED AGAIN!


Ok. The solution was now easy. Just enlarge the J partition (by a few GB probably would have been enough, but I just doubled it in size as it was small to begin with)! Now I had about 4GB free space on that partition, and VSS now was able to run normally!

So, by increasing the free space on that one partition its FULL backup now runs with VSS working, and its participation in the daily INCREMENTAL backup now causes no problem and VSS also works.

Apparently, the space used for VSS shadow copies are on the partition itself... not in some other available place.

Now I'm not sure if this is available in Win7, but in Windows Server there is a "VSSADMIN ADD SHADOWSTORAGE" command whose purpose I believe is to define shadow storage for VSS that is on a different volume than the volume being shadowed:

vssadmin add shadowstorage /for=<ForVolumeSpec> /on=<OnVolumeSpec> [/maxsize=<MaxSizeSpec>]
​

So perhaps theoretically if this also is available in Win7 I could have solved the "no free space on J" problem this way.

Anyway, doubling the size of J in order to add 4GB of free space is far simpler to understand, and that also solved the problem.

Apparently, this case is now closed.