System State Failing on all domain controllers

[Terry_Bates]

Hi All

After reconfiguring how backups operate here from D2T to D2D2T I'm running into a very strange problem. All of the System State backups for all the domain controllers are failing when trying to backup C:\Windows\NTDS with:

Completed status: Failed
Final error: 0xe0008488 - Access is denied.
Final error category: Security Errors

For additional information regarding this error refer to link V-79-57344-33928

Which immediatly makes you think the account it's using to backup doesn't have Domain Admin rights, except it does, and if I go to the NTDS folders manually and look at the permissions and ask the OS (via effective permissions) if the user I'm using to backup this folder it claims the user has full access.

This is the full error from the Job Log:

Directory \
Shadow Copy Writer COM+ Class Registration Database
Shadow Copy Writer Internet Information Services
Shadow Copy Writer Registry
Shadow Copy Writer System Files
Shadow Copy Writer SYSVOL
Shadow Copy Logical Directory SYSVOL\SYSVOL
Shadow Copy Writer Active Directory
Shadow Copy Logical Directory Active Directory\C:_WINDOWS_NTDS
V-79-57344-33928 - Access Denied. Cannot backup directory  and its subdirectories.

I enabled debug mode thinking something would jump out at me and give me something more to go on but as far as I can tell the debug log indicates everythign succeded. It's a 7MB file but the pertenant information I think is here,

[5956] 03/10/08 11:22:47 Writer Active Directory include file list:
[5956] 03/10/08 11:22:47 Writer Active Directory exclude file list:
[5956] 03/10/08 11:22:47 Informational: Opening Writer 'System?State\Active Directory'
[5956] 03/10/08 11:22:47 Informational: Writer System?State\Active Directory has no files present to protect in SHADOW::OpenWriter
[5956] 03/10/08 11:22:47 Informational: Closing Writer 'System?State\Active Directory'
[5956] 03/10/08 11:22:47 Component ntds file list:
[5956] 03/10/08 11:22:47   o: C:\WINDOWS\NTDS\ntds.dit
[5956] 03/10/08 11:22:47   o: C:\WINDOWS\NTDS\edb*.log
[5956] 03/10/08 11:22:47   o: C:\WINDOWS\NTDS\edb.chk
[5956] 03/10/08 11:22:47 Component ntds Writer's exclude file list:
[5956] 03/10/08 11:22:47 Informational: Opening Component 'ntds'
[5956] 03/10/08 11:22:47 Generating Component: ntds exclusion list:
[5956] 03/10/08 11:22:47 Generating Component: ntds file list:
[5956] 03/10/08 11:22:47    Adding C:\WINDOWS\NTDS\ntds.dit to the backup file list
[5956] 03/10/08 11:22:47    Adding C:\WINDOWS\NTDS\edb.log to the backup file list
[5956] 03/10/08 11:22:47    Adding C:\WINDOWS\NTDS\edb00049.log to the backup file list
[5956] 03/10/08 11:22:47    Adding C:\WINDOWS\NTDS\edbtmp.log to the backup file list
[5956] 03/10/08 11:22:47    Adding C:\WINDOWS\NTDS\edb.chk to the backup file list
[5956] 03/10/08 11:22:47 brUtil::SetupDLE Succesfully set up to read the object 'C:' '\WINDOWS\NTDS\' 'ntds.dit' 'C:\WINDOWS\NTDS\ntds.dit'
[5956] 03/10/08 11:22:47 brUtil::SetMetaDataStream - Metadata Stream Header (260)
[5956] 03/10/08 11:22:47 brUtil::OpenActiveObject Information: Active Object is a Directory C:\
[5956] 03/10/08 11:22:47 brUtil::OpenActiveObject Information: Active Object is a Directory C:\WINDOWS\
[5956] 03/10/08 11:22:47 brUtil::OpenActiveObject Information: Active Object is a Directory C:\WINDOWS\NTDS\
[5956] 03/10/08 11:22:47 brUtil::OpenActiveObject Information: Active Object is a File C:\WINDOWS\NTDS\ntds.dit
[5956] 03/10/08 11:22:49 brUtil::SetupDLE Succesfully set up to read the object 'C:' '\WINDOWS\NTDS\' 'edb.log' 'C:\WINDOWS\NTDS\edb.log'
[5956] 03/10/08 11:22:49 brUtil::OpenActiveObject Information: Active Object is a File C:\WINDOWS\NTDS\edb.log
[5956] 03/10/08 11:22:50 brUtil::SetupDLE Succesfully set up to read the object 'C:' '\WINDOWS\NTDS\' 'edb00049.log' 'C:\WINDOWS\NTDS\edb00049.log'
[5956] 03/10/08 11:22:50 brUtil::OpenActiveObject Information: Active Object is a File C:\WINDOWS\NTDS\edb00049.log
[5956] 03/10/08 11:22:50 brUtil::SetupDLE Succesfully set up to read the object 'C:' '\WINDOWS\NTDS\' 'edbtmp.log' 'C:\WINDOWS\NTDS\edbtmp.log'
[5956] 03/10/08 11:22:50 brUtil::OpenActiveObject Information: Active Object is a File C:\WINDOWS\NTDS\edbtmp.log
[5956] 03/10/08 11:22:51 brUtil::SetupDLE Succesfully set up to read the object 'C:' '\WINDOWS\NTDS\' 'edb.chk' 'C:\WINDOWS\NTDS\edb.chk'
[5956] 03/10/08 11:22:51 brUtil::OpenActiveObject Information: Active Object is a File C:\WINDOWS\NTDS\edb.chk
[5956] 03/10/08 11:22:51 brUtil:: 0x00000001 Could not get the next object to read. Probably end of list.
[5956] 03/10/08 11:22:51 Informational: Closing Component 'ntds'
[5956] 03/10/08 11:22:51 Informational: calling IVssBackupComponents::SetBackupSucceeded with status 'SUCCESS (0x00000000)' for Component 'ntds' in SHADOW::CloseComponent
[5956] 03/10/08 11:22:51 brUtil::GetSpecialObjectStream() - Getting special object from (C:)
[5956] 03/10/08 11:22:51 brUtil::GetSpecialObjectStream() - End of special object
[5956] 03/10/08 11:22:51 TF xfer time = 138 seconds.
[5956] 03/10/08 11:22:51 WRITE:  tpreceive_fail_count = 3063
[5956] 03/10/08 11:22:51 WRITE:  waiting_on_buffers_count = 3054
[5956] 03/10/08 11:22:51 WRITE:  buffers_written_count = 48292
[5956] 03/10/08 11:22:51 LP_ENV::TransportIPCObject() IPC Object: SATURN-SYSSTATE-{63869706-4598-4823-967F-B703431582E1}
[5956] 03/10/08 11:22:51 LP_ENV::TransportIPCObject( ) State - (9) IPC Object - (SATURN-SYSSTATE-{63869706-4598-4823-967F-B703431582E1}) Byte count - (128).
[5956] 03/10/08 11:22:51 TF_CloseSet()
[5956] 03/10/08 11:22:51 FreeFormatEnv( cur_fmt=0 )
[5956] 03/10/08 11:22:51 Detach from \\saturn.insite.co.nz\System?State
[5956] 03/10/08 11:22:51 Detach from Shadow?Copy?Components
[5956] 03/10/08 11:22:51 brUtil::brUtil Destructor
[5956] 03/10/08 11:22:51 Detach from C:
[5956] 03/10/08 11:22:51 TF_FreeDriveContext( 4F71010 )
[5956] 03/10/08 11:22:51 TF_FreeTapeBuffers: from 10 to 0 buffers
[5956] 03/10/08 11:22:51 @@@@@@@MyCloseSocket called with sockfd = 2540(0x9ec)    retval = -1
[5956] 03/10/08 11:22:51 Backup Job Stop(0)  - Mon Mar 10 11:22:51 2008
[5956] 03/10/08 11:23:01 VSS BackupComplete called with success.
[5956] 03/10/08 11:23:01 VssSnapshotVolume::GetFailedWriterStatus() - waiting for IVssBackupComponents::GatherWriterMetadata to complete.
[5956] 03/10/08 11:23:01 VssSnapshotVolume::GetFailedWriterStatus() - IVssBackupComponents::GatherWriterStatus complete.
[5956] 03/10/08 11:23:01 VssSnapshotVolume::GetFailedWriterStatus() - Issuing Async QueryStatus check.
[5956] 03/10/08 11:23:01 Attempting to delete VSS snapshot set: {f82ced7b-2292-4391-a260-b35f6621aef1}
[5956] 03/10/08 11:23:01 VSS snapshot set deleted. Snapshot SetID = {f82ced7b-2292-4391-a260-b35f6621aef1}
[5956] 03/10/08 11:23:01 @@@@@@@MyCloseSocket called with sockfd = 1268(0x4f4)    retval = 0
[5956] 03/10/08 11:23:01 @@@@@@@MyCloseSocket called with sockfd = -1(0xffffffff)    retval = -1
[0892] 03/10/08 11:24:40 @@@@@@@MyCloseSocket called with sockfd = 820(0x334)    retval = 0
[0892] 03/10/08 11:24:40 FS_RemoveFileSys


Can anyone suggest something I've missed or point me in the right direction? All this was working fine when backing up straight to tape but now, even if I enable the old job I still get the errors and even a job to only backup the System State gets these errors. I _can_ successfully use NTBackup to backup the system state to a file so I don't think it's a VSS issue. Also there are no errors or warnings in Event Viewer

Thanks




Message Edited by Dave Watkins on 03-09-2008 08:27 PM

[Greg_Meister]

Hi Dave,

Two questions... Are you using encryption on your backup jobs? Have you tried backing up the Shadow Copy Components separately? If not, set up a new job to back up just the SCC of a single server, and let me know the results.

[Terry_Bates]

Hi Greg

Thanks for the reply, no, we don't use any encryption on any of our backups, and yes, this happens with my default policy backups for each machine and if I just create a system state backup only (the log I pasted was from just a SS backup). I assume you meant System state and not Shadow Copy Components? Shadow Copy Components backup ok both from a single job and from my default policy based backup for each machine

I should mention this is a fully updated 7170 SP2 with hotfixes (31 thru 39 minus 37) install. Also if I check the resource credentials in the jobs affected they all come back ok against System State

In fact I'm wondering if this might be something to do with one of the hotfixes as I did a liveupdate when I started reconfiguring to D2D2T which from memory installed 4 hotfixes.

Dave