Solved

Error Code: [28:344] Exchange VSS writer reported an error. Please check the Windows event log and log files for more information.

  • 9 September 2021
  • 9 replies
  • 81 views

Userlevel 2
Badge +9

Hi guys, 
 

I have a problem with restoring the Exchange database under a different name (i.e. as an overwriting of another database) - the task ends after several seconds with an error:

Error Code: [28:344]
Description: Exchange VSS writer reported an error. Please check the Windows event log and log files for more information.
Source: msp-kle-ex61.mbms.com.pl, Process: CvExchDatabaseRestor

Greetings, 
K.

icon

Best answer by Mike Struening 22 September 2021, 16:51

View original

9 replies

Userlevel 7
Badge +21

Happy to assist @kszaf !

Can you share the contents of the CvExchDatabaseRestore.log file for this job ID?

Userlevel 2
Badge +9

CvExchDatabaseRestore.log:

10088 29bd4 09/08 09:50:27 89384 Entering [CsVSSClientExchange2010Restore::GatherRestoreTargetMetadata]
10088 29bd4 09/08 09:50:27 89384 CsVSSClientExchange2010Restore::GatherRestoreTargetMetadata() - Initializing restore target current live writer metadata.
10088 29bd4 09/08 09:50:27 89384 Entering [CsVSSClientExchange2010Shadow::GatherExchangeWriterMetadata]
10088 29bd4 09/08 09:50:27 89384 Entering [CsVSSClientExchange2010Shadow::GatherExchangeWriterMetadata]
10088 29bd4 09/08 09:50:27 89384 CsVssAsync::WaitUntilDone() - Waiting asynchronously for [VSS-Wait_69fe4934-cfb2-44e6-bf77-0e36337bfd24]
10088 29bd4 09/08 09:50:28 89384 CsVssAsync::WaitUntilDone() - Async status for event [VSS-Wait_69fe4934-cfb2-44e6-bf77-0e36337bfd24] returned final code = 0x0004230a, Description = VSS_S_ASYNC_FINISHED.
10088 29bd4 09/08 09:50:28 89384 CsVssBackupComponents::GatherWriterMetadata() - Writer Metadata gathered
10088 29bd4 09/08 09:50:28 89384 CsVssBackupComponents::GatherWriterMetadata() - Gathered all writer metadata
10088 29bd4 09/08 09:50:29 89384 CVSSClientBase::DebugPrintMetadata() - Global Metadata Info
10088 29bd4 09/08 09:50:29 89384 Entering [CsVSSClientExchange2010Shadow::BuildExchangeInfo]
10088 29bd4 09/08 09:50:29 89384 CsVSSClientExchange2010Base::GetDatabaseIter() - Internal Exchange metadata empty.
10088 29bd4 09/08 09:50:29 89384 CvExchDbRestore::OutOfPlaceRestoreWithRecovery() - In OutOfPlaceRestore Destination MB :[Microsoft Information Store\NOT_USED6_DB3]
10088 29bd4 09/08 09:50:34 89384 Adding alt restore mapping Src [Microsoft Information Store\NOT_USED6_DB3] to Dest [NOT_USED6_DB4] with GUIDs [\c5dc66ef-8f2c-426a-a2df-a17d69ea94ee]
10088 29bd4 09/08 09:50:34 89384 CVSSClientRestore::SetRestoreOptionsForComponent() - Flagging [Microsoft Exchange Server\Microsoft Information Store\MSP-KLE-EX61 -> f41b4cc0-42a1-4271-b020-71ea2d8fd18b] to use restore options [<DATABASE_RESTORE_OPTIONS><DATABASE_GUID_ORIGINAL>f41b4cc0-42a1-4271-b020-71ea2d8fd18b</DATABASE_GUID_ORIGINAL><DATABASE_GUID_TARGET>c5dc66ef-8f2c-426a-a2df-a17d69ea94ee</DATABASE_GUID_TARGET></DATABASE_RESTORE_OPTIONS>].
10088 29bd4 09/08 09:50:34 89384 CsVSSClientExchange2010Restore::SetAlternateExchangeDatabaseRestoreTargets() - Exported Exchange restore options XML [C:\Windows\TEMP\ExchRestoreOptions_2021-09-08-09-50-34.xml].
10088 29bd4 09/08 09:50:34 89384 Relocating Log File Path due to logical move: F:\MTD\NOT_USED6_DB4\_restoredLogs
10088 29bd4 09/08 09:50:34 89384 Current DB Destination Path :[D:\EX16DB\MTD\NOT_USED6_DB4.edb]
10088 29bd4 09/08 09:50:34 89384 Calling SetAlternateRestorePathForDatabase() with Destination Path :[D:\EX16DB\MTD\NOT_USED6_DB4.edb],  Database Name :[Microsoft Information Store\NOT_USED6_DB3]
10088 29bd4 09/08 09:50:34 89384 CVSSClientRestore::SetAdditionalRestoresForComponent() - Flagging [Microsoft Exchange Server\Microsoft Information Store\MSP-KLE-EX61 -> f41b4cc0-42a1-4271-b020-71ea2d8fd18b] for additional restores state [true].
10088 29bd4 09/08 09:50:34 89384 Entering [CsVssBackupComponentsEx2::CsVssBackupComponentsEx2]
10088 29bd4 09/08 09:50:34 89384 Entering [CsVssBackupComponentsEx2::Delete]
10088 29bd4 09/08 09:50:34 89384 Entering [CsVssBackupComponentsEx2::Create]
10088 29bd4 09/08 09:50:34 89384 Entering [CsVssBackupComponentsEx2::Delete]
10088 29bd4 09/08 09:50:34 89384 Entering [CsVssBackupComponents::SetSelectedForRestoreEx]
10088 29bd4 09/08 09:50:34 89384 CsVssBackupComponents::SetSelectedForRestoreEx() - Set select flag [1] for writer [76fe1ac4-15f7-4bcd-987e-8e1acb462fb7], instance [6bec2dc7-5fc7-4755-801e-9b338799b0c1], component [Microsoft Exchange Server\Microsoft Information Store\MSP-KLE-EX61, f41b4cc0-42a1-4271-b020-71ea2d8fd18b].
10088 29bd4 09/08 09:50:34 89384 Entering [CsVssBackupComponentsEx2::~CsVssBackupComponentsEx2]
10088 29bd4 09/08 09:50:34 89384 Entering [CsVssBackupComponentsEx2::Delete]
10088 29bd4 09/08 09:50:34 89384 CsRestoreRequestor::SetSelectedForRestoreEx() - Component [f41b4cc0-42a1-4271-b020-71ea2d8fd18b] from writer [76fe1ac4-15f7-4bcd-987e-8e1acb462fb7], instance [6bec2dc7-5fc7-4755-801e-9b338799b0c1] added to restore.
10088 29bd4 09/08 09:50:34 89384 CsRestoreRequestor::IsWriterIDInRestoreWriterList() - No writers engaged in this restore.
10088 29bd4 09/08 09:50:34 89384 CsRestoreRequestor::SetSelectedForRestoreEx() - Adding writer [76fe1ac4-15f7-4bcd-987e-8e1acb462fb7], instance [6bec2dc7-5fc7-4755-801e-9b338799b0c1] to included writer list.
10088 29bd4 09/08 09:50:34 89384 CsRestoreRequestor::SetVSSRestoreOptions() - Component [f41b4cc0-42a1-4271-b020-71ea2d8fd18b] from writer [76fe1ac4-15f7-4bcd-987e-8e1acb462fb7] added restore options [<DATABASE_RESTORE_OPTIONS><DATABASE_GUID_ORIGINAL>f41b4cc0-42a1-4271-b020-71ea2d8fd18b</DATABASE_GUID_ORIGINAL><DATABASE_GUID_TARGET>c5dc66ef-8f2c-426a-a2df-a17d69ea94ee</DATABASE_GUID_TARGET></DATABASE_RESTORE_OPTIONS>] to restore.
10088 29bd4 09/08 09:50:34 89384 CsRestoreRequestor::SetAdditionalRestores() - Set additional restores for component [f41b4cc0-42a1-4271-b020-71ea2d8fd18b - Microsoft Exchange Server\Microsoft Information Store\MSP-KLE-EX61] from writer [76fe1ac4-15f7-4bcd-987e-8e1acb462fb7]
10088 29bd4 09/08 09:50:34 89384 CsRestoreRequestor::AddRestoreSubcomponent() - Subcomponent [File] from writer [76fe1ac4-15f7-4bcd-987e-8e1acb462fb7] added to restore.
10088 29bd4 09/08 09:50:34 89384 CVSSClientRestore::SubmitRestoreMetadata() - No files in component found needing alternate path set. Supplied alternate path same as original path. Ignoring option.
10088 29bd4 09/08 09:50:34 89384 CsRestoreRequestor::AddRestoreSubcomponent() - Subcomponent [Logs] from writer [76fe1ac4-15f7-4bcd-987e-8e1acb462fb7] added to restore.
10088 29bd4 09/08 09:50:34 89384 CVSSClientRestore::SubmitRestoreMetadata() - Setting alternate path [F:\MTD\NOT_USED6_DB4\_restoredLogs] for writer [76fe1ac4-15f7-4bcd-987e-8e1acb462fb7] component [Microsoft Exchange Server\Microsoft Information Store\MSP-KLE-EX61->f41b4cc0-42a1-4271-b020-71ea2d8fd18b], type [2], orig path [F:\MTD\NOT_USED6_DB3\], file mask [E11*.log], recursive [0].
10088 29bd4 09/08 09:50:34 89384 CsRestoreRequestor::SetAlternateTarget() - Component [f41b4cc0-42a1-4271-b020-71ea2d8fd18b] from writer [76fe1ac4-15f7-4bcd-987e-8e1acb462fb7] added alternate path [F:\MTD\NOT_USED6_DB4\_restoredLogs] to restore.
10088 29bd4 09/08 09:50:34 89384 CVSSClientRestore::SubmitRestoreMetadata() - Setting alternate path [F:\MTD\NOT_USED6_DB4\_restoredLogs] for writer [76fe1ac4-15f7-4bcd-987e-8e1acb462fb7] component [Microsoft Exchange Server\Microsoft Information Store\MSP-KLE-EX61->f41b4cc0-42a1-4271-b020-71ea2d8fd18b], type [2], orig path [F:\MTD\NOT_USED6_DB3], file mask [E11.chk], recursive [0].
10088 29bd4 09/08 09:50:34 89384 CsRestoreRequestor::SetAlternateTarget() - Component [f41b4cc0-42a1-4271-b020-71ea2d8fd18b] from writer [76fe1ac4-15f7-4bcd-987e-8e1acb462fb7] added alternate path [F:\MTD\NOT_USED6_DB4\_restoredLogs] to restore.
10088 29bd4 09/08 09:50:34 89384 CsVssAsync::WaitUntilDone() - Waiting asynchronously for [VSS-Wait_a152828f-9393-43f1-9198-d2df5f990cbc]
10088 29bd4 09/08 09:50:34 89384 CsVssAsync::WaitUntilDone() - Async status for event [VSS-Wait_a152828f-9393-43f1-9198-d2df5f990cbc] returned final code = 0x0004230a, Description = VSS_S_ASYNC_FINISHED.
10088 29bd4 09/08 09:50:34 89384 CsVssAsync::WaitUntilDone() - Waiting asynchronously for [VSS-Wait_1fe0ec01-f710-4ce3-a3c2-88497ebf00ff]
10088 29bd4 09/08 09:50:34 89384 CsVssAsync::WaitUntilDone() - Async status for event [VSS-Wait_1fe0ec01-f710-4ce3-a3c2-88497ebf00ff] returned final code = 0x0004230a, Description = VSS_S_ASYNC_FINISHED.
10088 29bd4 09/08 09:50:34 89384 CollectWritersStatus() - Status ::AsyncPreRestore (16 writers)
10088 29bd4 09/08 09:50:34 89384 CollectWritersStatus() - Signaling bad state returned for writer [Microsoft Exchange Writer] engaged in restore.
10088 29bd4 09/08 09:50:34 89384 CsRestoreRequestor::AsyncPreRestore() - Call CollectWritersStatus(CS_RP_PRE_RESTORE, "::AsyncPreRestore")  [FAILED, throwing CV exception] - Code = 0x80004005, Description = E_FAIL
10088 29bd4 09/08 09:50:34 89384 CsRestoreRequestor::AsyncPreRestore() - Caught -2147467259=E_FAIL exception
10088 29bd4 09/08 09:50:34 89384 CsVSSClientExchange2010Restore::ExchangePreRestore() - Failed to execute VSS prerestore for Exchange.
10088 29bd4 09/08 09:50:34 89384 [CvExchDbRestore::RestoreDbWithVss]: Function ExchangePreRestore() failed.
10088 29bd4 09/08 09:50:34 89384 CsVssBackupComponents::FreeWriterMetadata() - Free'd all writer metadata
10088 29bd4 09/08 09:50:34 89384 CsVssBackupComponents::FreeWriterMetadata() - Free'd all writer metadata
10088 29bd4 09/08 09:50:34 89384 CvExchDbRestore::Restore() - Failed to restore database [Microsoft Information Store\NOT_USED6_DB3]
10088 29bd4 09/08 09:50:34 89384 EvEvent::setMsgEventArguments() - [MsgId[0x1b000025][]: [0] Args Pushed, [1] Args expected.
10088 2a2fc 09/08 09:50:36 89384 Worker [2a2fc]: No more data items to process in queue. Exiting..
10088 33100 09/08 09:50:42 89384 StreamThreadPool<class RestoreDataItem>::ExDbRestoreStream::Run() - Sent stream status success
10088 33100 09/08 09:50:42 89384 Stream thread [2a2fc:33100] exiting..
10088 2a2fc 09/08 09:50:42 89384 ~CVArchive() - Destroying CVArchive. This=000001F8DEEEED30
10088 3099c 09/08 09:50:44 89384 Worker [3099c]: No more data items to process in queue. Exiting..
10088 2a1b8 09/08 09:50:44 89384 Stream thread [3099c:2a1b8] exiting..
10088 3099c 09/08 09:50:44 89384 ~CVArchive() - Destroying CVArchive. This=000001F8DEEA2090
10088 3099c 09/08 09:50:44 89384 CVArchive::ClosePipeline() - Shutting down head session
10088 3099c 09/08 09:50:44 89384 CCVAPipelayer::ClosePipeline() - About to shut down RESTORE pipeline
10088 3099c 09/08 09:50:44 89384 CPipelayer::ShutdownPipeline() - stat- SDT [000001F8DEF0C990] [duration - 24 seconds]
10088 3099c 09/08 09:50:44 89384 CPipelayer::ShutdownPipeline() - SDT [000001F8DEF0C990] Shutdown completed.
10088 485c  09/08 09:50:44 89384 SdtBase::setLastErr: Setting last err [98][Services on the tail side of the SDT pipe are going down.] RCId [9]
10088 3c84  09/08 09:50:44 89384 SdtTailSrv::DropClientWorker: Removing Client [SDTPipe_msp-kle-ex61.mbms.com.pl_msp-kle-bkp1_89384_1631087420_10088_172472_000001F8DEF0C990], Id [1380] from the list. RCId [9]
10088 3c84  09/08 09:50:44 89384 SdtTail::onDisconnect: Sending error [98][Services on the tail side of the SDT pipe are going down.] to the head. RCId [9]
10088 3c84  09/08 09:50:44 89384 SdtTail::onDisconnect: Sent error code to the head RCId [9]

Userlevel 2
Badge +9

Hi :) 

Small update 

After viewing EventViewer on the Exchange, it was possible to identify an error that prevented the task from starting and now there is progress in that the data is restored, but the whole task crashes on 94% - the messages on the exchange show that the process is failing approving reconstructed logs. 

 

 

Userlevel 7
Badge +21

That’s interesting (and progress)!

I just checked out ticket history and don’t see that error anywhere.

Is that in Exchange itself or in the Job ID details?

Can you share the logs for the failure time period?  Also curious what error you saw in Event Viewer if you can share :nerd:

Userlevel 7
Badge +21

Hey @kszaf , following up on this one.  Can you share the event viewer details?

Userlevel 2
Badge +9

@Mike Struening thanks for your time. So I check EventViewer and we fix errors. Once there is progress, as the data is restored, but the whole task crashes on 94% - the messages on the exchange show that the process of approving reconstructed logs is crashing. Full restore is working properly. 

 

Maybe is restor for another serwer can be solution?

 

 

Userlevel 7
Badge +21

Maybe, but preferably it should just work :grinning:

At this point, I would suggest opening a support case.  Let them analyze the whole thing and find the issue.

Can you open and share the case number here so I can track it?

Userlevel 2
Badge +9

@Mike Struening thanks for your time. We change the server and now it s work properly, it s some problem with server. 

Have nice weekend! 

Userlevel 7
Badge +21

Glad to hear it!

Reply