Error backing up Sharepoint 2010 using DPM 2012, VSS in a bad state

I can't get DPM 2012 to backup our Sharepoint 2010 databases properly. When trying to create a new recovery point, I get:

The VSS application writer or the VSS provider is in a bad state. Either it was already in a bad state or it entered a bad state during the current operation. (ID 30111 Details: VssError:The writer experienced a non-transient error.  If the backup process is retried,
the error is likely to reoccur.
 (0x800423F4))

Running "vssadmin list writers" on the sql server returns:

...

Writer name: 'SqlServerWriter'
   Writer Id: {a65faa63-5ea8-4ebc-9dbd-a0c4db26912a}
   Writer Instance Id: {bc7df3df-24b4-4432-99fb-8d316c02f3b7}
   State: [11] Failed
   Last error: Non-retryable error

...

This error perists even after a restart. Before manually trying to create a recovery point, DPM seems to occasionally be able to take partial backups. These backups can consist of one or more of: mysite database, the main intranet-content database, the Config database or the AdminContentDB. Each of these recovery points have a warning message:  

"Some of the databases were not available when the selected recovery point was created. For farm recovery ensure that Config and AdminContent databases are available in the recovery point"

We are using a non-clustered setup of:

Sharepoint 2010 Std (14.0.6029.1000)

SQL Server 2008 Std (10.0.5826)

DPM 2012 SP1 (4.1.3333.0)

 Any ideas what could be causing this error?

 

June 4th, 2013 12:47pm

The root appears to be something with the SQL writer as you have figured out.  You say that the failed state persists after reboot and yet sometimes DPM does get a backup.  That's very odd as if that is failed, we won't do any backups of SQL.

If you manually restart the SQL writer service on that server and then list writers, does the writer show up in a good state?

The information we would most likely want is going to be in the errlog files on the SQL box. 

If you can get the writer stable, open up the DPM\Temp directory on the SQL box and sort the errlog files by time/date.  Then attempt a consistency check against the SP farm.  As soon as it fails, refresh that folder and look for files that were written to during that time.  Open it in notepad, scroll to the bottom and then search up for Warning.  This will likely give a little more insight into what is happening.  Make sure the warning section has information as you will sometimes see a false warning about reading a registry key or something.

Review for domain specific or personal identifying information, strip that out and replace with fillers and post that here.

Free Windows Admin Tool Kit Click here and download it now
June 14th, 2013 8:17pm

Thank you for the reply!

I followed your instructions and here are the warnings from the log file.

1FCC 1AF0 06/28 07:28:08.164 31 vsssessioncontext.cpp(143) [000000000404A3E0]  WARNING <VSS_CONTEXT><COMPONENTS><COMPONENT><WriterId>{A65FAA63-5EA8-4EBC-9DBD-A0C4DB26912A}</WriterId><WriterName></WriterName><LogicalPath>SQLSRV01</LogicalPath><ComponentName>sp2010_intranet_content</ComponentName><ComponentType>2</ComponentType></COMPONENT></COMPONENTS><SNAPSHOT_CONTEXT>          SelectComponent = 1,          PartialFileSupport = 0,          BootableState = 0,          BackupType = 1,          SnapshotContext = 8388608,          SnapshotAttributes = VSS_CTX_BACKUP          </SNAPSHOT_CONTEXT><SnapShotVolumes><Volume>              <Name>\\?\Volume{1d4f16ec-9e47-45af-a029-d344f2196305}\</Name>              <SnapshotPath>(null)</SnapshotPath>              <MountPoint>D:\</MountPoint>              <MountPointArray></MountPointArray>              <SnapshotId>{00000000-0000-0000-0000-000000000000}</SnapshotId>              <ProviderId>{00000000-0000-0000-0000-000000000000}</ProviderId>              <IsHardwareProvider>0</IsHardwareProvider>              </Volume></SnapShotVolumes>
1FCC 1AF0 06/28 07:28:08.164 31 vsssessioncontext.cpp(143) [000000000404A3E0]  WARNING </VSS_CONTEXT>
...
1FCC 182C 06/28 07:28:38.349 31 vsssnapshotrequestor.cpp(560) [00000000002C2D10]  WARNING Failed: Hr: = [0x80042316] : Encountered Failure: : lVal : m_apVssBackupComponents->StartSnapshotSet(&snapshotSetId)
1FCC 182C 06/28 07:28:38.349 31 createsnapshotsubtask.cpp(1527) [0000000004044360]  WARNING Failed: Hr: = [0x80042316] : Encountered Failure: : lVal : pSnapshotRequestor->StartPrepareForBackup(snapshotSetId, m_fUseSystemSoftwareProviderOnly)
1FCC 182C 06/28 07:28:38.349 05 fsmstate.cpp(167) [0000000004046080]  WARNING Failed: Hr: = [0x80042316] : Encountered Failure: : lVal : pTransition->Execute(pEvent)
1FCC 182C 06/28 07:28:38.349 05 genericfsm.cpp(225) [0000000004044720]  WARNING Failed: Hr: = [0x80042316] : Encountered Failure: : lVal : m_pCurrentState->SendEvent(pEvent, pNextState)
...
1FCC 182C 06/28 07:28:39.263 20 nativeutils.hpp(42)  B363B46E-DFED-4D7A-9A92-212B144C32BC WARNING Failed: Hr: = [0x80070002] : Encountered Failure: : lVal : r.GetValue(pszKey, pT)
(three times)
...
1FCC 182C 06/28 07:28:44.550 31 filtercommandhandler.cpp(412) [000000000404C820] B363B46E-DFED-4D7A-9A92-212B144C32BC WARNING Failed: Hr: = [0x800700ea] : Encountered Failure: : lVal : DeviceIoControl(m_hVolume, dwIoctlCode, pInput, dwInputSize, pOutput, dwOutputSize, &dwBytes, 0)
...
1FCC 182C 06/28 07:28:49.559 03 miscellaneousutils.cpp(669)  B363B46E-DFED-4D7A-9A92-212B144C32BC WARNING Failed: Hr: = [0x80070002] Could not open HKEY_LOCAL_MACHINE\Software\Microsoft\Microsoft Data Protection Manager\Agent\2.0
...
1FCC 182C 06/28 07:28:49.644 18 fsutils.cpp(4055)  B363B46E-DFED-4D7A-9A92-212B144C32BC WARNING Failed: Hr: = [0x80070002] : GetFileAttributes failed for \\?\D:\Shared\DB\MSSQL\MSSQL10.MSSQLSERVER\MSSQL\DATA\DPM_SQL_PROTECT\SQLSRV01\sp2010_mysite_content_1.LDF
1FCC 182C 06/28 07:28:49.644 18 fsutils.cpp(626)  B363B46E-DFED-4D7A-9A92-212B144C32BC WARNING Failed: Hr: = [0x80070002] : Failed to get attributes for \\?\D:\Shared\DB\MSSQL\MSSQL10.MSSQLSERVER\MSSQL\DATA\DPM_SQL_PROTECT\SQLSRV01\sp2010_mysite_content_1.LDF
1FCC 182C 06/28 07:28:49.644 18 fsutils.cpp(4055)  B363B46E-DFED-4D7A-9A92-212B144C32BC WARNING Failed: Hr: = [0x80070002] : GetFileAttributes failed for \\?\D:\Shared\DB\MSSQL\MSSQL10.MSSQLSERVER\MSSQL\DATA\DPM_SQL_PROTECT\SQLSRV01\sp2010_mysite_content_1.LDF
...
1FCC 182C 06/28 07:28:49.647 18 fsutils.cpp(4055)  B363B46E-DFED-4D7A-9A92-212B144C32BC WARNING Failed: Hr: = [0x80070002] : GetFileAttributes failed for \\?\D:\Shared\DB\MSSQL\MSSQL10.MSSQLSERVER\MSSQL\DATA\DPM_SQL_PROTECT\SQLSRV01\sp2010_mysite_content_1.LDF\TempLog
1FCC 182C 06/28 07:28:49.647 18 fsutils.cpp(626)  B363B46E-DFED-4D7A-9A92-212B144C32BC WARNING Failed: Hr: = [0x80070002] : Failed to get attributes for \\?\D:\Shared\DB\MSSQL\MSSQL10.MSSQLSERVER\MSSQL\DATA\DPM_SQL_PROTECT\SQLSRV01\sp2010_mysite_content_1.LDF\TempLog
1FCC 182C 06/28 07:28:49.647 18 fsutils.cpp(4055)  B363B46E-DFED-4D7A-9A92-212B144C32BC WARNING Failed: Hr: = [0x80070002] : GetFileAttributes failed for \\?\D:\Shared\DB\MSSQL\MSSQL10.MSSQLSERVER\MSSQL\DATA\DPM_SQL_PROTECT\SQLSRV01\sp2010_mysite_content_1.LDF\TempLog
...
1FCC 1AF0 06/28 07:29:19.803 31 vssbaserequestor.cpp(1140) [00000000002C2D10]  WARNING Failed: Hr: = [0x800423f4] CVssBaseRequestor: CheckWritersStatus -                                                         Writer instance - {CBE443F6-5992-4ED4-B0DA-91C14A431318} writer id - {A65FAA63-5EA8-4EBC-9DBD-A0C4DB26912A} writer name - SqlServerWriter                                                         writer state - 11
1FCC 1AF0 06/28 07:29:19.803 05 fsmtransition.cpp(111) [0000000004048DD0]  WARNING Failed: Hr: = [0x800423f4] HasEventErrorCode: completion: 0xa10c, signature: 0xaabbcc00
1FCC 1AF0 06/28 07:29:19.803 31 aasubtask.cpp(1373) [0000000004044360]  WARNING Updating task status with hr: 40bd8b08x, dls error code:536900994
1FCC 182C 06/28 07:29:19.804 31 aasubtask.cpp(906) [0000000004044360]  WARNING <?xml version="1.0"?>
1FCC 182C 06/28 07:29:19.804 31 aasubtask.cpp(906) [0000000004044360]  WARNING <Status xmlns="http://schemas.microsoft.com/2003/dls/StatusMessages.xsd" StatusCode="-2147212300" Reason="Error" CommandID="RAPreBackup" CommandInstanceID="a638fd40-d4d7-4c85-a21b-d6195b78f151" GuidWorkItem="fee0fe4d-8d7a-4aee-9aa3-d5dab18203b0" TETaskInstanceID="d0a5bf2e-a627-46e8-8f36-be3c36f00526"><ErrorInfo xmlns="http://schemas.microsoft.com/2003/dls/GenericAgentStatus.xsd" ErrorCode="998" DetailedCode="-2147212300" DetailedSource="2"/><RAStatus><RAPreBackup xmlns="<BackupTime>130168781265003539</BackupTime><DSStatus><ComponentName>sp2010_intranet_content</ComponentName><LogicalPath>SQLSRV01</LogicalPath><BackupStamp></BackupStamp><Metadata></Metadata></DSStatus></RAPreBackup></RAStatus></Status">http://schemas.microsoft.com/2003/dls/ArchiveAgent/StatusMessages.xsd"><BackupTime>130168781265003539</BackupTime><DSStatus><ComponentName>sp2010_intranet_content</ComponentName><LogicalPath>SQLSRV01</LogicalPath><BackupStamp></BackupStamp><Metadata></Metadata></DSStatus></RAPreBackup></RAStatus></Status>
1FCC 182C 06/28 07:29:19.805 03 runtime.cpp(1376) [00000000002092F0]  FATAL Subtask failure, sending status response XML=[<?xml version="1.0"?>
1FCC 182C 06/28 07:29:19.805 03 runtime.cpp(1376) [00000000002092F0]  FATAL <Status xmlns="http://schemas.microsoft.com/2003/dls/StatusMessages.xsd" StatusCode="-2147212300" Reason="Error" CommandID="RAPreBackup" CommandInstanceID="a638fd40-d4d7-4c85-a21b-d6195b78f151" GuidWorkItem="fee0fe4d-8d7a-4aee-9aa3-d5dab18203b0" TETaskInstanceID="d0a5bf2e-a627-46e8-8f36-be3c36f00526"><ErrorInfo xmlns="http://schemas.microsoft.com/2003/dls/GenericAgentStatus.xsd" ErrorCode="536900994" DetailedCode="-2147212300" DetailedSource="2"><Parameter Name="AgentTargetServer" Value="sqlsrv01"/></ErrorInfo><RAStatus><RAPreBackup xmlns="<BackupTime>130168781265003539</BackupTime><DSStatus><ComponentName>sp2010_intranet_content</ComponentName><LogicalPath>SQLSRV01</LogicalPath><BackupStamp></BackupStamp><Metadata></Metadata></DSStatus></RAPreBackup></RAStatus></Status">http://schemas.microsoft.com/2003/dls/ArchiveAgent/StatusMessages.xsd"><BackupTime>130168781265003539</BackupTime><DSStatus><ComponentName>sp2010_intranet_content</ComponentName><LogicalPath>SQLSRV01</LogicalPath><BackupStamp></BackupStamp><Metadata></Metadata></DSStatus></RAPreBackup></RAStatus></Status>
1FCC 182C 06/28 07:29:19.805 03 runtime.cpp(1376) [00000000002092F0]  FATAL ]
...
1FCC 182C 06/28 07:29:19.856 31 createsnapshotsubtask.cpp(2394) [0000000004044360] D0A5BF2E-A627-46E8-8F36-BE3C36F00526 WARNING Failed: Hr: = [0x800423f4] : Encountered Failure: : lVal : pSnapshotRequestor->CheckWriterStatus()
1FCC 182C 06/28 07:29:19.856 05 fsmstate.cpp(167) [0000000004046740] D0A5BF2E-A627-46E8-8F36-BE3C36F00526 WARNING Failed: Hr: = [0x800423f4] : Encountered Failure: : lVal : pTransition->Execute(pEvent)
1FCC 182C 06/28 07:29:19.856 05 genericfsm.cpp(225) [0000000004044720] D0A5BF2E-A627-46E8-8F36-BE3C36F00526 WARNING Failed: Hr: = [0x800423f4] : Encountered Failure: : lVal : m_pCurrentState->SendEvent(pEvent, pNextState)
...
1FCC 1AF0 06/28 07:29:23.162 31 vssbaserequestor.cpp(1140) [00000000002C2D10]  WARNING Failed: Hr: = [0x800423f4] CVssBaseRequestor: CheckWritersStatus -                                                         Writer instance - {CBE443F6-5992-4ED4-B0DA-91C14A431318} writer id - {A65FAA63-5EA8-4EBC-9DBD-A0C4DB26912A} writer name - SqlServerWriter                                                         writer state - 11
...
1FCC 1AF0 06/28 07:29:23.200 05 fsmtransition.cpp(111) [00000000002C90E0]  WARNING Failed: Hr: = [0x800423f4] HasEventErrorCode: completion: 0xa10c, signature: 0xaabbcc00
...
1FCC 1AF0 06/28 07:29:23.200 31 aasubtask.cpp(1373) [00000000040C3480]  WARNING Updating task status with hr: 40bd8608x, dls error code:536900994
...
1FCC 182C 06/28 07:29:23.203 31 aasubtask.cpp(906) [00000000040C3480]  WARNING <?xml version="1.0"?>
1FCC 182C 06/28 07:29:23.203 31 aasubtask.cpp(906) [00000000040C3480]  WARNING <Status xmlns="http://schemas.microsoft.com/2003/dls/StatusMessages.xsd" StatusCode="-2147212300" Reason="Error" CommandID="RAPostBackup" CommandInstanceID="84c79b52-bef1-4872-a4ca-c706e290e308" GuidWorkItem="fee0fe4d-8d7a-4aee-9aa3-d5dab18203b0" TETaskInstanceID="d0a5bf2e-a627-46e8-8f36-be3c36f00526"><ErrorInfo xmlns="http://schemas.microsoft.com/2003/dls/GenericAgentStatus.xsd" ErrorCode="998" DetailedCode="-2147212300" DetailedSource="2"/><RAStatus><RAPostBackup xmlns="<DSCloneStatus><ComponentName></ComponentName><LogicalPath>sp2010_intranet_content</LogicalPath><BackupSize>0</BackupSize><CloneStatus><MsSqlStatus">http://schemas.microsoft.com/2003/dls/ArchiveAgent/StatusMessages.xsd"><DSCloneStatus><ComponentName></ComponentName><LogicalPath>sp2010_intranet_content</LogicalPath><BackupSize>0</BackupSize><CloneStatus><MsSqlStatus xmlns="<WriterId>a65faa63-5ea8-4ebc-9dbd-a0c4db26912a</WriterId><Lsn>0000000000000000000000000</Lsn><LogBackupTime>0.0000000000000</LogBackupTime><VolumeStatus><StartUsn>2134110752</StartUsn><StartUsnBeforeSnapshot>2134101192</StartUsnBeforeSnapshot><VolumeName>D:\</VolumeName></VolumeStatus></MsSqlStatus></CloneStatus></DSCloneStatus></RAPostBackup></RAStatus></Status">http://schemas.microsoft.com/2003/dls/ArchiveAgent/CommonTypes.xsd"><WriterId>a65faa63-5ea8-4ebc-9dbd-a0c4db26912a</WriterId><Lsn>0000000000000000000000000</Lsn><LogBackupTime>0.0000000000000</LogBackupTime><VolumeStatus><StartUsn>2134110752</StartUsn><StartUsnBeforeSnapshot>2134101192</StartUsnBeforeSnapshot><VolumeName>D:\</VolumeName></VolumeStatus></MsSqlStatus></CloneStatus></DSCloneStatus></RAPostBackup></RAStatus></Status>
1FCC 182C 06/28 07:29:23.204 03 runtime.cpp(1376) [00000000002092F0]  FATAL Subtask failure, sending status response XML=[<?xml version="1.0"?>
1FCC 182C 06/28 07:29:23.204 03 runtime.cpp(1376) [00000000002092F0]  FATAL <Status xmlns="http://schemas.microsoft.com/2003/dls/StatusMessages.xsd" StatusCode="-2147212300" Reason="Error" CommandID="RAPostBackup" CommandInstanceID="84c79b52-bef1-4872-a4ca-c706e290e308" GuidWorkItem="fee0fe4d-8d7a-4aee-9aa3-d5dab18203b0" TETaskInstanceID="d0a5bf2e-a627-46e8-8f36-be3c36f00526"><ErrorInfo xmlns="http://schemas.microsoft.com/2003/dls/GenericAgentStatus.xsd" ErrorCode="536900994" DetailedCode="-2147212300" DetailedSource="2"><Parameter Name="AgentTargetServer" Value="sqlsrv01"/></ErrorInfo><RAStatus><RAPostBackup xmlns="<DSCloneStatus><ComponentName></ComponentName><LogicalPath>sp2010_intranet_content</LogicalPath><BackupSize>0</BackupSize><CloneStatus><MsSqlStatus">http://schemas.microsoft.com/2003/dls/ArchiveAgent/StatusMessages.xsd"><DSCloneStatus><ComponentName></ComponentName><LogicalPath>sp2010_intranet_content</LogicalPath><BackupSize>0</BackupSize><CloneStatus><MsSqlStatus xmlns="<WriterId>a65faa63-5ea8-4ebc-9dbd-a0c4db26912a</WriterId><Lsn>0000000000000000000000000</Lsn><LogBackupTime>0.0000000000000</LogBackupTime><VolumeStatus><StartUsn>2134110752</StartUsn><StartUsnBeforeSnapshot>2134101192</StartUsnBeforeSnapshot><VolumeName>D:\</VolumeName></VolumeStatus></MsSqlStatus></CloneStatus></DSCloneStatus></RAPostBackup></RAStatus></Status">http://schemas.microsoft.com/2003/dls/ArchiveAgent/CommonTypes.xsd"><WriterId>a65faa63-5ea8-4ebc-9dbd-a0c4db26912a</WriterId><Lsn>0000000000000000000000000</Lsn><LogBackupTime>0.0000000000000</LogBackupTime><VolumeStatus><StartUsn>2134110752</StartUsn><StartUsnBeforeSnapshot>2134101192</StartUsnBeforeSnapshot><VolumeName>D:\</VolumeName></VolumeStatus></MsSqlStatus></CloneStatus></DSCloneStatus></RAPostBackup></RAStatus></Status>
1FCC 182C 06/28 07:29:23.204 03 runtime.cpp(1376) [00000000002092F0]  FATAL ]

 

June 28th, 2013 12:07pm

Well, nothing is jumping out in there to indicate what is happening.  All I can tell in this is that the SQL writer is in a bad state, but it appears to either already be there or it happens almost immediately.

If you reset the SQL writer and then try to just protect one or two of the databases in that same instance (master and model for example), I wonder what would happen there.

Outside of that, it looks like you will need to get a VSS trace from the time the writer is listed as stable to when it fails.  That is not something we can easily do in the forums and you would likely want to open a ticket with Microsoft for it.  Please be sure to post your findings if you do though.  Thanks.

Free Windows Admin Tool Kit Click here and download it now
June 28th, 2013 3:54pm

This topic is archived. No further replies will be accepted.

Other recent topics Other recent topics