I have the following:-
- sharepoint farm 2013 on-premises.
- i have the following
back.bat
file:-
"%SYSTEMROOT%\system32\windowspowershell\v1.0\powershell.exe" -Command Start-Process "$PSHOME\powershell.exe" -Verb RunAs -ArgumentList "'%~dp0\backup.ps1'"
- and the following
backup.ps1
file which is being referenced from the above.bat
file. and the .ps1 file will be doing a farm backup:-
Add-PSSnapin "Microsoft.SharePoint.PowerShell"
Remove-Item -recurse c:\Back*
Backup-SPFarm -Directory \***\Back -BackupMethod full -BackupThreads 10 -Force
- now using the windows task scheduler, i create a task which will run the above
.bat
file.
now i have noted when the tasks started a new folder is created under the c:\back
folder and the backup folder contain many .bak
files with sizes such as 500 MB,150 MB, etc..
but for more than 40 minutes the backup task is not doing anything, and when i checked the spbackup
file i find that it hangs on the following stage:-
Waiting for second phase backup for index SPd1f9d427e849.
here is the latest lines inside the spbackup
file:-
[25/07/2017 17:03:55] Progress: [Search_Service_Application_CrawlStoreDB_bf83ad956c814b1fae127f1ce44962d0] 84 percent complete.
[25/07/2017 17:03:55] Progress: [Search_Service_Application_CrawlStoreDB_bf83ad956c814b1fae127f1ce44962d0] 91 percent complete.
[25/07/2017 17:03:55] Progress: [Search_Service_Application_CrawlStoreDB_bf83ad956c814b1fae127f1ce44962d0] 98 percent complete.
[25/07/2017 17:03:55] Progress: [Search_Service_Application_LinksStoreDB_5777fdbc964c4ab28cb7b4a29f84fbae] 14 percent complete.
[25/07/2017 17:03:55] Verbose: [Search_Service_Application_CrawlStoreDB_bf83ad956c814b1fae127f1ce44962d0] SQL Server Message: Processed 112 pages for database 'Search_Service_Application_CrawlStoreDB_bf83ad956c814b1fae127f1ce44962d0', file 'Search_Service_Application_CrawlStoreDB_bf83ad956c814b1fae127f1ce44962d0' on file 2.
[25/07/2017 17:03:55] Progress: [Search_Service_Application_CrawlStoreDB_bf83ad956c814b1fae127f1ce44962d0] 100 percent complete.
[25/07/2017 17:03:55] Progress: [Search_Service_Application_LinksStoreDB_5777fdbc964c4ab28cb7b4a29f84fbae] 28 percent complete.
[25/07/2017 17:03:55] Progress: [Search_Service_Application_LinksStoreDB_5777fdbc964c4ab28cb7b4a29f84fbae] 42 percent complete.
[25/07/2017 17:03:55] Verbose: [Search_Service_Application_CrawlStoreDB_bf83ad956c814b1fae127f1ce44962d0] SQL Server Message: Processed 2 pages for database 'Search_Service_Application_CrawlStoreDB_bf83ad956c814b1fae127f1ce44962d0', file 'Search_Service_Application_CrawlStoreDB_bf83ad956c814b1fae127f1ce44962d0_log' on file 2.
[25/07/2017 17:03:55] Progress: [Search_Service_Application_LinksStoreDB_5777fdbc964c4ab28cb7b4a29f84fbae] 56 percent complete.
[25/07/2017 17:03:55] Progress: [Search_Service_Application_LinksStoreDB_5777fdbc964c4ab28cb7b4a29f84fbae] 70 percent complete.
[25/07/2017 17:03:55] Progress: [Search_Service_Application_LinksStoreDB_5777fdbc964c4ab28cb7b4a29f84fbae] 84 percent complete.
[25/07/2017 17:03:55] Progress: [Search_Service_Application_LinksStoreDB_5777fdbc964c4ab28cb7b4a29f84fbae] 98 percent complete.
[25/07/2017 17:03:55] Verbose: [Search_Service_Application_LinksStoreDB_5777fdbc964c4ab28cb7b4a29f84fbae] SQL Server Message: Processed 56 pages for database 'Search_Service_Application_LinksStoreDB_5777fdbc964c4ab28cb7b4a29f84fbae', file 'Search_Service_Application_LinksStoreDB_5777fdbc964c4ab28cb7b4a29f84fbae' on file 2.
[25/07/2017 17:03:55] Verbose: [Search_Service_Application_AnalyticsReportingStoreDB_e3be102b34884efbb8fada7b1169d759] SQL Server Message: BACKUP DATABASE WITH DIFFERENTIAL successfully processed 41 pages in 0.063 seconds (5.084 MB/sec).
[25/07/2017 17:03:55] Verbose: [Search_Service_Application_AnalyticsReportingStoreDB_e3be102b34884efbb8fada7b1169d759] SQL command completed at: 25/07/2017 17:03:55.
[25/07/2017 17:03:55] Progress: [Search_Service_Application_LinksStoreDB_5777fdbc964c4ab28cb7b4a29f84fbae] 100 percent complete.
[25/07/2017 17:03:55] Verbose: [Search_Service_Application_LinksStoreDB_5777fdbc964c4ab28cb7b4a29f84fbae] SQL Server Message: Processed 1 pages for database 'Search_Service_Application_LinksStoreDB_5777fdbc964c4ab28cb7b4a29f84fbae', file 'Search_Service_Application_LinksStoreDB_5777fdbc964c4ab28cb7b4a29f84fbae_log' on file 2.
[25/07/2017 17:03:55] Verbose: [Search_Service_Application_LinksStoreDB_5777fdbc964c4ab28cb7b4a29f84fbae] SQL Server Message: BACKUP DATABASE WITH DIFFERENTIAL successfully processed 57 pages in 0.038 seconds (11.718 MB/sec).
[25/07/2017 17:03:55] Verbose: [Search_Service_Application_LinksStoreDB_5777fdbc964c4ab28cb7b4a29f84fbae] SQL command completed at: 25/07/2017 17:03:55.
[25/07/2017 17:03:55] Verbose: [Search_Service_Application_CrawlStoreDB_bf83ad956c814b1fae127f1ce44962d0] SQL Server Message: BACKUP DATABASE WITH DIFFERENTIAL successfully processed 114 pages in 0.114 seconds (7.756 MB/sec).
[25/07/2017 17:03:55] Verbose: [Search_Service_Application_CrawlStoreDB_bf83ad956c814b1fae127f1ce44962d0] SQL command completed at: 25/07/2017 17:03:55.
[25/07/2017 17:03:55] Progress: [Search_Service_Application_DB_37e97f6ff2624e0fa193eac35ae8f97d] 8 percent complete.
[25/07/2017 17:03:55] Progress: [Search_Service_Application_DB_37e97f6ff2624e0fa193eac35ae8f97d] 11 percent complete.
[25/07/2017 17:03:55] Progress: [Search_Service_Application_DB_37e97f6ff2624e0fa193eac35ae8f97d] 20 percent complete.
[25/07/2017 17:03:56] Progress: [Search_Service_Application_DB_37e97f6ff2624e0fa193eac35ae8f97d] 26 percent complete.
[25/07/2017 17:03:56] Progress: [Search_Service_Application_DB_37e97f6ff2624e0fa193eac35ae8f97d] 31 percent complete.
[25/07/2017 17:03:56] Progress: [Search_Service_Application_DB_37e97f6ff2624e0fa193eac35ae8f97d] 37 percent complete.
[25/07/2017 17:03:56] Progress: [Search_Service_Application_DB_37e97f6ff2624e0fa193eac35ae8f97d] 40 percent complete.
[25/07/2017 17:03:56] Progress: [Search_Service_Application_DB_37e97f6ff2624e0fa193eac35ae8f97d] 46 percent complete.
[25/07/2017 17:03:56] Progress: [Search_Service_Application_DB_37e97f6ff2624e0fa193eac35ae8f97d] 52 percent complete.
[25/07/2017 17:03:56] Progress: [Search_Service_Application_DB_37e97f6ff2624e0fa193eac35ae8f97d] 55 percent complete.
[25/07/2017 17:03:56] Progress: [Search_Service_Application_DB_37e97f6ff2624e0fa193eac35ae8f97d] 61 percent complete.
[25/07/2017 17:03:56] Progress: [Search_Service_Application_DB_37e97f6ff2624e0fa193eac35ae8f97d] 66 percent complete.
[25/07/2017 17:03:56] Progress: [Search_Service_Application_DB_37e97f6ff2624e0fa193eac35ae8f97d] 72 percent complete.
[25/07/2017 17:03:56] Progress: [Search_Service_Application_DB_37e97f6ff2624e0fa193eac35ae8f97d] 75 percent complete.
[25/07/2017 17:03:56] Progress: [Search_Service_Application_DB_37e97f6ff2624e0fa193eac35ae8f97d] 87 percent complete.
[25/07/2017 17:03:56] Progress: [Search_Service_Application_DB_37e97f6ff2624e0fa193eac35ae8f97d] 90 percent complete.
[25/07/2017 17:03:56] Progress: [Search_Service_Application_DB_37e97f6ff2624e0fa193eac35ae8f97d] 95 percent complete.
[25/07/2017 17:03:56] Verbose: [Search_Service_Application_DB_37e97f6ff2624e0fa193eac35ae8f97d] SQL Server Message: Processed 272 pages for database 'Search_Service_Application_DB_37e97f6ff2624e0fa193eac35ae8f97d', file 'Search_Service_Application_DB_37e97f6ff2624e0fa193eac35ae8f97d' on file 2.
[25/07/2017 17:03:56] Progress: [Search_Service_Application_DB_37e97f6ff2624e0fa193eac35ae8f97d] 100 percent complete.
[25/07/2017 17:03:56] Verbose: [Search_Service_Application_DB_37e97f6ff2624e0fa193eac35ae8f97d] SQL Server Message: Processed 4 pages for database 'Search_Service_Application_DB_37e97f6ff2624e0fa193eac35ae8f97d', file 'Search_Service_Application_DB_37e97f6ff2624e0fa193eac35ae8f97d_log' on file 2.
[25/07/2017 17:03:56] Verbose: [Search_Service_Application_DB_37e97f6ff2624e0fa193eac35ae8f97d] SQL Server Message: BACKUP DATABASE WITH DIFFERENTIAL successfully processed 276 pages in 0.105 seconds (20.489 MB/sec).
[25/07/2017 17:03:56] Verbose: [Search_Service_Application_DB_37e97f6ff2624e0fa193eac35ae8f97d] SQL command completed at: 25/07/2017 17:03:56.
[25/07/2017 17:03:56] Verbose: [IndexController] Waiting for second phase backup for index SPd1f9d427e849.
so can anyone adivce what is causing this problem? second question. what i can do now? is there any harm if i force the task to end (if there is not any harm , how i can end the task?)? or it is better to wait till the backup fails or raise a timeout ?
here is how my backup folder looks like:-
here is the current running tasks inside the task manager:-
After around 2 hours the backup completed with 12 errors, here is part of the errors :-
[25/07/2017 18:50:07] Verbose: [IndexController] Aborting backup job for index SPd1f9d427e849.
[25/07/2017 18:50:07] Verbose: [Search Service Application] Resuming crawls and feeding.
[25/07/2017 18:52:38] Verbose: [Search Service Application] Resuming crawls and feeding completed in 2.5 minutes.
[25/07/2017 18:52:38] Verbose: [Search Service Application] Resuming master merge.
[25/07/2017 18:55:08] Verbose: [Search Service Application] Resuming master mergex completed in 2.5 minutes.
[25/07/2017 18:55:09] FatalError: Object Search Service Application failed in event OnBackup. For more information, see the spbackup.log or sprestore.log file located in the backup directory.
FaultException: Management called failed with System.InvalidOperationException: 'Second phase backup job SPd1f9d427e849->\\******1\Back\spbr0000\ does not exist. (The job is still in the first phase.)' at at Microsoft.Ceres.SearchCore.IndexController.BackupService.ProgressSecondPhase(String handle)
at Microsoft.Ceres.SearchCore.IndexController.IndexControllerManagementAgent.WrapCall[T](Func`2 original)
[25/07/2017 18:55:09] Debug:
Server stack trace:
at System.ServiceModel.Channels.ServiceChannel.HandleReply(ProxyOperationRuntime operation, ProxyRpc& rpc)
at System.ServiceModel.Channels.ServiceChannel.Call(String action, Boolean oneway, ProxyOperationRuntime operation, Object[] ins, Object[] outs, TimeSpan timeout)
at System.ServiceModel.Channels.ServiceChannelProxy.InvokeService(IMethodCallMessage methodCall, ProxyOperationRuntime operation)
at System.ServiceModel.Channels.ServiceChannelProxy.Invoke(IMessage message)
Exception rethrown at [0]:
at System.Runtime.Remoting.Proxies.RealProxy.HandleReturnMessage(IMessage reqMsg, IMessage retMsg)
at System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData& msgData, Int32 type)
at Microsoft.Ceres.SearchCore.Admin.IIndexControllerManagementAgent.ProgressSecondPhase(String handle)
at Microsoft.Office.Server.Search.Administration.BRIndexComponent.RetryWhileNoEndPoint[T](Func`2 action, SPBackupRestoreInformation args, Guid ssaId, TimeSpan retryTimeout)
at Microsoft.Office.Server.Search.Administration.BRIndexComponent.RetryWhileNoEndPoint[T](Func`2 action, SPBackupRestoreInformation args, Guid ssaId, TimeSpan retryTimeout)
at Microsoft.Office.Server.Search.Administration.BRIndexComponent.<>c__DisplayClass13`1.<RetryWhileNoEndPoint>b__12()
at Microsoft.SharePoint.SPSecurity.<>c__DisplayClass5.<RunWithElevatedPrivileges>b__3()
at Microsoft.SharePoint.Utilities.SecurityContext.RunAsProcess(CodeToRunElevated secureCode)
at Microsoft.SharePoint.SPSecurity.RunWithElevatedPrivileges(WaitCallback secureCode, Object param)
at Microsoft.SharePoint.SPSecurity.RunWithElevatedPrivileges(CodeToRunElevated secureCode)
at Microsoft.Office.Server.Search.Administration.BRIndexComponent.RetryWhileNoEndPoint[T](Func`2 action, SPBackupRestoreInformation args, Guid ssaId)
at Microsoft.Office.Server.Search.Administration.BRIndexComponent.WaitPhaseComplete(SPBackupInformation args, Func`2 getProgress, Int32 sleepTime)
at Microsoft.Office.Server.Search.Administration.BRIndexComponent.WaitSecondPhaseBackupComplete(SPBackupInformation args)
at Microsoft.Office.Server.Search.Administration.TwoPhaseBackupHelper.WaitSecondPhaseBackupCompleteChildren(SPBackupInformation args)
at Microsoft.Office.Server.Search.Administration.SearchServiceApplication.OnBackup(SPBackupInformation args)