Hi All.
I configured file archiving with the required configuration. Windows 2016 Server with local disk where all the files reside.
Archiving and stubbing is working as expected. I am also able to restore the file as data out of place to the same or different server.
However when trying to recall the file by double clicking the Explorer Windows hangs up. The recall doesn't progress. The Persistent Recovery job start but there is no progress.
I have added the below Additional Settings on the client which is also the Media Server.
GXHSMRECALL_ENABLE_EARLY_DRIVER_NOTIFICATION
StageRecalls
GXHSM_RESTUB_ENABLED
The server has Symantec Endpoint Protection 14.x installed. The Security team has confirmed that all the settings contained in "Symantec® Endpoint Security v14xAV Settings for Windows File Archiver" is configured. I have requested to have the AV temporarily disabled to test but are yet to receive feedback.
I have restarted the services and the server but this does not improve things at all.
Below is an extract of the ClMgrs log file.
4600 14e8 01/26 14:43:37 ### CFSDMAPI::RecallFile(223) - Received recall request for C:\RestoreTesting\Information Technology\CAB 2018\Recordings\2018.01.31_13.48_01.MP3, stubType=LOCAL
4600 14e8 01/26 14:43:37 ### CFSDMAPIPrivate::RecallFile(374) - Reparse data :
Version=2, CommcellID=2, AFileGroupID=5, AFileNumber=88, AFileOffset=1302385439
VolumeGUID=0510bb0b-0000-0000-0000-501f00000000, FileGUID=60411ebcea4b1aaf41ae8300a461ad00
SubclientID=18, JobID=137, SubclientFlagsPresent=0, SubclientGUID=1D1D0CBF-52BF-4A42-A644-A50E05B1A1B8
CommcellNo=182045765, OrigMigratedFilePath=C:\RestoreTesting\Information Technology\CAB 2018\Recordings\2018.01.31_13.48_01.MP3, MigrationTime=1611566598
EvMgrcPortNo=0, MigratedFileSize=0, AgentName=
4600 1e74 01/26 14:43:37 ### AreRecallsBlockedForThisSubclient(208) - SecureRecallEnabled [0]
4600 1e74 01/26 14:43:37 ### DMRRequest::SubmitInternal(1519) - Index Mode [NEW]
4600 1e74 01/26 14:43:37 ### ShouldLookUpBeOnSpecificAFile(278) - bDaysBasedRetention [1] for appId:18 fetched from CS
4600 1e74 01/26 14:43:37 ### DMRIndexLookup::Initialize(79) - Index lookup browse retry limit=1
4600 1e74 01/26 14:43:37 ### DMRIndexLookup::Initialize(84) - Index lookup browse retry wait time=0
4600 1e74 01/26 14:43:38 ### IDXBROWSECL Sending init request [<?xml version="1.0" encoding="UTF-8" standalone="no" ?><databrowse_BrowseRequest opType="1" pathType="0"><session sessionId="1D1D0CBF-52BF-4A42-A644-A50E05B1A1B8"/><entity _type_="0" applicationId="33" commCellId="182045765"/><paths><pathParams optionalParameterStr="60411ebcea4b1aaf41ae8300a461ad00"/></paths><timeRange fromTime="0" toTime="0"/><options DoNotCacheFilters="0" PreferContentServer="0" adjustPerLastDRTime="0" browseFromCSDB="0" bulkOperation="0" bypassSubclientConfig="1" caseInsensitive="0" caseManagerDataCopy="0" createRestoreVectors="0" cycleBrowse="0" disableSnapOptimizer="0" doPrediction="0" downloadSystemScan="0" downloadTrueUpStubScanOutput="0" enforceSuperBrowse="0" fetchFileProperties="0" folderDelete="0" fsExtentBrowse="0" getACLs="0" hideEmptyExtents="0" imageBrowse="0" includeAgedData="0" includeAllParents="0" includeCheckSum="0" includeEndUserErasedItems="0" includeExtentCRC="0" includeMetadata="0" includeRunningJobs="0" includeSoftCommittedJobs="0" includeVersions="0" instantSend="0" internalReq="0" isOneTouchRestore="0" machineLiveBrowse="0" nasSynthDirRestore="2" nasSynthRestore="0" nonRecursiveNASRestore="0" onePassRedundancy="0" onePassStubQuery="0" prepareSystemScan="0" pruneFromSource="0" queryAgedArchiveFileData="0" reCreateRestoreVector="0" refCopy="0" refCopyCloudMigration="0" refCopySF="0" relationshipBrowse="0" restoreIndex="1" sendBackListOfAfiles="0" sendOutputToFile="0" sharedFolderBrowse="0" showDeletedFiles="0" showFolderSize="0" showOnlyDeleted="0" showThumbnail="0" skipDataPrediction="0" skipIndexRestore="0" skipMountPoints="0" skipNasRenamedDirs="0" skipProgressMessage="0" skipSynthFullJobs="0" synthFull="0" tableViewBrowse="0" translateSyncPath="0" translateToVMReq="0" useLatestCycle="0" useUptoDateIndexOnly="0" verifyArchiverQuery="0" viewBackupCopy="0" vsDiskBrowse="0" vsExtentBrowse="0" vsFileBrowse="1" vsListVMs="0" vsLiveSyncBrowse="0" vsVolumeBrowse="0" vsaFileLevelRestore="0"/><mode mode="2"/><advOptions applyStrictACL="0" copyPrecedence="0" includePsuedoItems="0" retryLimit="1" retryWaitSecs="0" skipUptodateCheck="0" stubAsData="0" timeoutSecs="150" validateAfiles="0" vmCentricClient="0"><advConfig recallRequest="0"><initBy aFileId="88"><commcell _type_="1" commCellId="182045765"/></initBy></advConfig></advOptions></databrowse_BrowseRequest>] to CS
4600 1e74 01/26 14:43:38 ### NoPrefix initialized a new browse session [1D1D0CBF-52BF-4A42-A644-A50E05B1A1B8]
4600 1e74 01/26 14:43:40 ### CVOnDemandSvcClient::SubmitTask() - On Demand service CVODS_indexserver_rr-cvma_1 launched at host rr-cvma.local*rr-cvma*8400. Unique ID is 9A62478C-FDE0-48B9-8D81-1BF4DD51AD31
4600 1e74 01/26 14:43:40 ### CVOnDemandSvcClient::Attach() - Successfully attached to on Demand service CVODS_indexserver_rr-cvma_1 launched at host rr-cvma.local*rr-cvma*8400. Unique ID is 9A62478C-FDE0-48B9-8D81-1BF4DD51AD31
4600 1e74 01/26 14:43:41 ### getPipeLineInfo() - Input : commcellId[2], archGroupId[5], copyId[0], archFileId[88], appId[0], jobId[0], copyPrec[0], flags[0], IncludeMediaInfo[1]
4600 1e74 01/26 14:43:42 ### getPipeLineInfo() - OutPut : CopyId - 5, Mangled MediaAgent Name- rr-cvma.local*rr-cvma*8400
4600 1e74 01/26 14:43:42 ### DMRRequest::SubmitInternal(1755) - nRETRY_RECALL_CHECK_ISTAPEEXPORTED_BEFORE_RECALL not present
4600 1668 01/26 14:43:42 153 DMRPipelineReader::StartPipelineWithoutLookup(1495) - Starting pipeline from [rr-cvma.local-rr-cvma-8400] to [rr-cvma.local*rr-cvma*8400].
4600 1668 01/26 14:43:42 ### Reusing running restore DataPipe
4600 1668 01/26 14:43:42 153 DMRPipelineReader::StartPipelineWithoutLookup(1516) - Currently connected to MediaAgent : rr-cvma.local.
4600 1668 01/26 14:43:42 ### DMRPipelineReader::OpenAFile(1344) - copyId:5 for appId:18, AGroupNo:5, CommCellId:2
4600 1668 01/26 14:43:42 153 DMRPipelineReader::OpenAFile(1374) - Currently connected to MediaAgent: rr-cvma.local, Pipeline ID : 0
4600 1768 01/26 14:43:43 153 SdtEncDec::processSetEncProps: [000001D47B9D59D0] AfIds [88 ]
4600 1768 01/26 14:43:43 153 CArchFileKeys::Init() - Max Afile key map size set to 8192. Connection Count = 8
4600 1764 01/26 14:43:43 153 SdtBase::SetNwCrcProps: Enabled n/w crc on SdtTail. [Using slice-by-8] RCId [2]
4600 1664 01/26 14:43:43 ### CVArchive::ReadBuffer() - PL_SET_ENC_PROPS(0, 0, 0)
4600 1664 01/26 14:43:43 ### CVArchive::ReadBuffer() - PL_SET_NETWORK_CRC_PROPS (0, 0, 0)
4600 1664 01/26 14:43:43 ### CVArchive::ReadBuffer() - PL_FS_OPEN_AFILE(2, 5, 88)
4600 1664 01/26 14:43:43 ### DMRBufferHandlerWinFSDM::OnBufferPlFsHdr(3675) - Received PL_FS_HDR for fileName:C:\RestoreTesting\Information Technology\CAB 2018\Recordings\2018.01.31_13.48_01.MP3
4600 1388 01/26 14:47:06 ### CFSDMConfigCache::RefreshConfigEx(361) - ProcessPendingRepairFromStubPhase as part of timeout
4600 1388 01/26 14:47:06 ### CFSDMAPI::RepairStubsFromStubbingFailures(369) - No stubs found for repair
4600 1388 01/26 14:47:06 ### CFSDMConfigCache::RefreshConfig(387) - RefreshConfig
4600 1388 01/26 14:47:06 ### CVPlatformInfo::getRegInt() - Field GXHSMSERVICEMINRECALLFREESPACE in key ~WinFSDataMigrator is not a DWORD.
4600 1388 01/26 14:47:07 ### CFSDMAPIPrivate::RepairAbortedRecallsInternal(2244) - Checking if there are aborted [LOCAL] recalls in the pending recalls database for stub repair for filer: []
4600 1388 01/26 14:47:07 ### CFSDMAPIPrivate::RepairAbortedRecallsInternal(2256) - [1] stubs to be repaired
4600 d84 01/26 14:47:07 ### CFSDMAPIPrivate::RepairAbortedRecallsInternal(2244) - Checking if there are aborted [LOCAL] recalls in the pending recalls database for stub repair for filer: []
4600 d84 01/26 14:47:07 ### CFSDMAPIPrivate::RepairAbortedRecallsInternal(2256) - [1] stubs to be repaired
4600 1388 01/26 14:47:07 ### CFSDMAPIPrivate::RepairStub(2094) - Skipping file C:\RestoreTesting\Information Technology\CAB 2018\Recordings\2018.01.31_13.48_01.MP3 from repair since it is being recalled currently.
4600 d84 01/26 14:47:07 ### CFSDMAPIPrivate::RepairStub(2094) - Skipping file C:\RestoreTesting\Information Technology\CAB 2018\Recordings\2018.01.31_13.48_01.MP3 from repair since it is being recalled currently.
4600 1388 01/26 14:47:07 ### CFSDMAPIPrivate::RepairAbortedRecallsInternal(2395) - Successfully repaired all stubs (to be repaired [1], skipped upon request from listener [0])
4600 d84 01/26 14:47:07 ### CFSDMAPIPrivate::RepairAbortedRecallsInternal::<lambda_38dc48081048ece1ad70825460b17da4>::operator ((2309) - Failed to delete [C:\RestoreTesting\Information Technology\CAB 2018\Recordings\2018.01.31_13.48_01.MP3] entry from pending recalls database. Error [0x80070002:{FXRegistry::DeleteRegKey(178)} + {FXRegistry::DeleteRegKey(191)/W32.2.(The system cannot find the file specified. (ERROR_FILE_NOT_FOUND.2))-RegDeleteKeyW failed, Key=[SOFTWARE\CommVault Systems\Galaxy\Instance001\WinFSDataMigrator\PendingRecalls\LOCAL\e397da748b21ad3e6d195109606f0fca], RegOptions=[0x0]}]
4600 d84 01/26 14:47:07 ### CFSDMAPIPrivate::RepairAbortedRecallsInternal(2395) - Successfully repaired all stubs (to be repaired [1], skipped upon request from listener [0])
4600 d84 01/26 14:47:07 ### CFSDMAPIPrivate::RepairAbortedRecallsInternal::<lambda_050fcef43613ab824ff71b56a89a4e72>::operator ((2249) - Failed to remove repair in progress flag. error [0x80070002:{CPendingRecalls::UnMarkRepairInProgress(218)} + {FXRegistry::DeleteRegValue(235)} + {FXRegistry::DeleteRegValue(279)/W32.2.(The system cannot find the file specified. (ERROR_FILE_NOT_FOUND.2))-RegDeleteValueW failed, Key=[SOFTWARE\CommVault Systems\Galaxy\Instance001\WinFSDataMigrator\PendingRecalls\LOCAL\], Value=[RepairInProgress], RegOptions=[0x0]}]
4600 1760 01/26 14:47:08 ### TPool [IOCPServerPool_RecallService]. Ser# [1] Tot [4], Pend [4], Comp [0], Max Par [4], Avg Work Time [0.00 s], Avg Wait Time [0.00 s]
4600 1760 01/26 14:47:08 ### TPool [CRecallServiceProcessor]. Ser# [0] Tot [1], Pend [0], Comp [1], Max Par [1], Avg Work Time [5.07 s], Avg Wait Time [148.04 us]
4600 1760 01/26 14:47:08 ### TPool [SdtTailThPool]. Tot [38], Pend [0], Comp [38], Max Par [3], Avg Work Time [671.53 us], Avg Wait Time [566.44 us]
4600 1388 01/26 14:52:07 ### CFSDMConfigCache::RefreshConfigEx(361) - ProcessPendingRepairFromStubPhase as part of timeout
4600 1388 01/26 14:52:07 ### CFSDMAPI::RepairStubsFromStubbingFailures(369) - No stubs found for repair
4600 1388 01/26 14:52:07 ### CFSDMConfigCache::RefreshConfig(387) - RefreshConfig
4600 1388 01/26 14:52:07 ### CVPlatformInfo::getRegInt() - Field GXHSMSERVICEMINRECALLFREESPACE in key ~WinFSDataMigrator is not a DWORD.
4600 1388 01/26 14:52:07 ### CFSDMAPI::RepairAbortedRecalls(325) - No stubs found for repair
4600 1760 01/26 14:52:08 ### TPool [IOCPServerPool_RecallService]. Ser# [1] Tot [4], Pend [4], Comp [0], Max Par [0], Avg Work Time [0.00 s], Avg Wait Time [0.00 s]
4600 1760 01/26 14:52:08 ### TPool [SdtTailThPool]. Tot [0], Pend [0], Comp [0], Max Par [0], Avg Work Time [0.00 s], Avg Wait Time [0.00 s]
4600 1388 01/26 14:57:07 ### CFSDMConfigCache::RefreshConfigEx(361) - ProcessPendingRepairFromStubPhase as part of timeout
4600 1388 01/26 14:57:07 ### CFSDMAPI::RepairStubsFromStubbingFailures(369) - No stubs found for repair
4600 1388 01/26 14:57:07 ### CFSDMConfigCache::RefreshConfig(387) - RefreshConfig
4600 1388 01/26 14:57:07 ### CVPlatformInfo::getRegInt() - Field GXHSMSERVICEMINRECALLFREESPACE in key ~WinFSDataMigrator is not a DWORD.
4600 1388 01/26 14:57:07 ### CFSDMAPIPrivate::RepairAbortedRecallsInternal(2244) - Checking if there are aborted [LOCAL] recalls in the pending recalls database for stub repair for filer: []
4600 1388 01/26 14:57:07 ### CFSDMAPIPrivate::RepairAbortedRecallsInternal(2258) - No stubs found for repair
4600 1d4c 01/26 14:57:07 ### CFSDMAPIPrivate::RepairAbortedRecallsInternal(2244) - Checking if there are aborted [LOCAL] recalls in the pending recalls database for stub repair for filer: []
4600 1d4c 01/26 14:57:07 ### CFSDMAPIPrivate::RepairAbortedRecallsInternal(2258) - No stubs found for repair
4600 1d4c 01/26 14:57:07 ### CFSDMAPIPrivate::RepairAbortedRecallsInternal::<lambda_050fcef43613ab824ff71b56a89a4e72>::operator ((2249) - Failed to remove repair in progress flag. error [0x80070002:{CPendingRecalls::UnMarkRepairInProgress(218)} + {FXRegistry::DeleteRegValue(235)} + {FXRegistry::DeleteRegValue(279)/W32.2.(The system cannot find the file specified. (ERROR_FILE_NOT_FOUND.2))-RegDeleteValueW failed, Key=[SOFTWARE\CommVault Systems\Galaxy\Instance001\WinFSDataMigrator\PendingRecalls\LOCAL\], Value=[RepairInProgress], RegOptions=[0x0]}]
4600 1760 01/26 14:57:08 ### TPool [IOCPServerPool_RecallService]. Ser# [1] Tot [4], Pend [4], Comp [0], Max Par [0], Avg Work Time [0.00 s], Avg Wait Time [0.00 s]
4600 1760 01/26 14:57:08 ### TPool [SdtTailThPool]. Tot [0], Pend [0], Comp [0], Max Par [0], Avg Work Time [0.00 s], Avg Wait Time [0.00 s]
4600 1388 01/26 15:02:07 ### CFSDMConfigCache::RefreshConfigEx(361) - ProcessPendingRepairFromStubPhase as part of timeout
4600 1388 01/26 15:02:07 ### CFSDMAPI::RepairStubsFromStubbingFailures(369) - No stubs found for repair
4600 1388 01/26 15:02:07 ### CFSDMConfigCache::RefreshConfig(387) - RefreshConfig
4600 1388 01/26 15:02:07 ### CVPlatformInfo::getRegInt() - Field GXHSMSERVICEMINRECALLFREESPACE in key ~WinFSDataMigrator is not a DWORD.
4600 1388 01/26 15:02:07 ### CFSDMAPI::RepairAbortedRecalls(325) - No stubs found for repair
4600 1760 01/26 15:02:08 ### TPool [IOCPServerPool_RecallService]. Ser# [1] Tot [4], Pend [4], Comp [0], Max Par [0], Avg Work Time [0.00 s], Avg Wait Time [0.00 s]
4600 1760 01/26 15:02:08 ### TPool [SdtTailThPool]. Tot [0], Pend [0], Comp [0], Max Par [0], Avg Work Time [0.00 s], Avg Wait Time [0.00 s]
4600 1388 01/26 15:07:07 ### CFSDMConfigCache::RefreshConfigEx(361) - ProcessPendingRepairFromStubPhase as part of timeout
4600 1388 01/26 15:07:07 ### CFSDMAPI::RepairStubsFromStubbingFailures(369) - No stubs found for repair
4600 1388 01/26 15:07:07 ### CFSDMConfigCache::RefreshConfig(387) - RefreshConfig
4600 1388 01/26 15:07:07 ### CVPlatformInfo::getRegInt() - Field GXHSMSERVICEMINRECALLFREESPACE in key ~WinFSDataMigrator is not a DWORD.
4600 1388 01/26 15:07:07 ### CFSDMAPIPrivate::RepairAbortedRecallsInternal(2244) - Checking if there are aborted [LOCAL] recalls in the pending recalls database for stub repair for filer: []
4600 1388 01/26 15:07:07 ### CFSDMAPIPrivate::RepairAbortedRecallsInternal(2258) - No stubs found for repair
4600 179c 01/26 15:07:07 ### CFSDMAPIPrivate::RepairAbortedRecallsInternal(2244) - Checking if there are aborted [LOCAL] recalls in the pending recalls database for stub repair for filer: []
4600 179c 01/26 15:07:07 ### CFSDMAPIPrivate::RepairAbortedRecallsInternal(2258) - No stubs found for repair
4600 179c 01/26 15:07:07 ### CFSDMAPIPrivate::RepairAbortedRecallsInternal::<lambda_050fcef43613ab824ff71b56a89a4e72>::operator ((2249) - Failed to remove repair in progress flag. error [0x80070002:{CPendingRecalls::UnMarkRepairInProgress(218)} + {FXRegistry::DeleteRegValue(235)} + {FXRegistry::DeleteRegValue(279)/W32.2.(The system cannot find the file specified. (ERROR_FILE_NOT_FOUND.2))-RegDeleteValueW failed, Key=[SOFTWARE\CommVault Systems\Galaxy\Instance001\WinFSDataMigrator\PendingRecalls\LOCAL\], Value=[RepairInProgress], RegOptions=[0x0]}]
4600 1760 01/26 15:07:08 ### TPool [IOCPServerPool_RecallService]. Ser# [1] Tot [4], Pend [4], Comp [0], Max Par [0], Avg Work Time [0.00 s], Avg Wait Time [0.00 s]
4600 1760 01/26 15:07:08 ### TPool [SdtTailThPool]. Tot [0], Pend [0], Comp [0], Max Par [0], Avg Work Time [0.00 s], Avg Wait Time [0.00 s]
4600 1388 01/26 15:12:07 ### CFSDMConfigCache::RefreshConfigEx(361) - ProcessPendingRepairFromStubPhase as part of timeout
4600 1388 01/26 15:12:07 ### CFSDMAPI::RepairStubsFromStubbingFailures(369) - No stubs found for repair
4600 1388 01/26 15:12:07 ### CFSDMConfigCache::RefreshConfig(387) - RefreshConfig
4600 1388 01/26 15:12:07 ### CVPlatformInfo::getRegInt() - Field GXHSMSERVICEMINRECALLFREESPACE in key ~WinFSDataMigrator is not a DWORD.
4600 1388 01/26 15:12:07 ### CFSDMAPI::RepairAbortedRecalls(325) - No stubs found for repair
4600 1760 01/26 15:12:08 ### TPool [IOCPServerPool_RecallService]. Ser# [1] Tot [4], Pend [4], Comp [0], Max Par [0], Avg Work Time [0.00 s], Avg Wait Time [0.00 s]
4600 1760 01/26 15:12:08 ### TPool [SdtTailThPool]. Tot [0], Pend [0], Comp [0], Max Par [0], Avg Work Time [0.00 s], Avg Wait Time [0.00 s]
4600 1388 01/26 15:17:07 ### CFSDMConfigCache::RefreshConfigEx(361) - ProcessPendingRepairFromStubPhase as part of timeout
4600 1388 01/26 15:17:07 ### CFSDMAPI::RepairStubsFromStubbingFailures(369) - No stubs found for repair
4600 1388 01/26 15:17:07 ### CFSDMConfigCache::RefreshConfig(387) - RefreshConfig
4600 1388 01/26 15:17:07 ### CVPlatformInfo::getRegInt() - Field GXHSMSERVICEMINRECALLFREESPACE in key ~WinFSDataMigrator is not a DWORD.
4600 1388 01/26 15:17:07 ### CFSDMAPIPrivate::RepairAbortedRecallsInternal(2244) - Checking if there are aborted [LOCAL] recalls in the pending recalls database for stub repair for filer: []
4600 720 01/26 15:17:07 ### CFSDMAPIPrivate::RepairAbortedRecallsInternal(2244) - Checking if there are aborted [LOCAL] recalls in the pending recalls database for stub repair for filer: []
4600 720 01/26 15:17:07 ### CFSDMAPIPrivate::RepairAbortedRecallsInternal(2258) - No stubs found for repair
4600 1388 01/26 15:17:07 ### CFSDMAPIPrivate::RepairAbortedRecallsInternal(2258) - No stubs found for repair
4600 720 01/26 15:17:07 ### CFSDMAPIPrivate::RepairAbortedRecallsInternal::<lambda_050fcef43613ab824ff71b56a89a4e72>::operator ((2249) - Failed to remove repair in progress flag. error [0x80070002:{CPendingRecalls::UnMarkRepairInProgress(218)} + {FXRegistry::DeleteRegValue(235)} + {FXRegistry::DeleteRegValue(279)/W32.2.(The system cannot find the file specified. (ERROR_FILE_NOT_FOUND.2))-RegDeleteValueW failed, Key=[SOFTWARE\CommVault Systems\Galaxy\Instance001\WinFSDataMigrator\PendingRecalls\LOCAL\], Value=[RepairInProgress], RegOptions=[0x0]}]
4600 1760 01/26 15:17:08 ### TPool [IOCPServerPool_RecallService]. Ser# [1] Tot [4], Pend [4], Comp [0], Max Par [0], Avg Work Time [0.00 s], Avg Wait Time [0.00 s]
4600 1760 01/26 15:17:08 ### TPool [SdtTailThPool]. Tot [0], Pend [0], Comp [0], Max Par [0], Avg Work Time [0.00 s], Avg Wait Time [0.00 s]
Thanks.