Skip to main content


@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
Machine : <commserve>
File    : AuxCopyMgr.log
@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@

22900 46dc  10/28 16:51:58 4124325 DBBase-SQL() - dbmethods.cpp:1519, DB Layer will use sExec] access by default. Use SetAdminAccess API for on demand Admin access.
22900 46dc  10/28 16:51:59 4124325 Cvcl::init() - CVCL: Running in FIPS Mode
22900 46dc  10/28 16:51:59 4124325 DetectNativeClient() - Found reg key SOFTWARE\Microsoft\Microsoft SQL Server\SQLNCLI11]. Using driver iSQL Server Native Client 11.0].
22900 46dc  10/28 16:52:00 4124325 Starting DDB Recon with Indexed restore
22900 46dc  10/28 16:52:00 4124325 TaskInterfaceDB::getOptions() - Loading default options into memory
22900 46dc  10/28 16:52:00 4124325 Init() - Initializing job control ctoken=4124325:1:1,cn=<commserve>], serverName v<CS fqdn>], ControlFlag r1], Job Id 4124325]
22900 46dc  10/28 16:52:02 4124325 CVJobCtrlLog::registerProcess(): successfully created file tE:\Program Files\Commvault\ContentStore\Base\JobControl\22.900]
22900 46dc  10/28 16:52:02 4124325 AuxCopyManager::RestoreDDBStoreFiles Job option: DDB Reconstruction job in Restore Phase.
22900 46dc  10/28 16:52:02 4124325 AuxCopyManager::RestoreDDBStoreFiles Job option: Source Dedup Store ID p7].
22900 46dc  10/28 16:52:02 4124325 AuxCopyManager::RestoreDDBStoreFiles Job option: Full Reconstruction = sno].
22900 46dc  10/28 16:52:02 4124325 AuxCopyManager::RestoreDDBStoreFiles Job option : Corrupted Substore Id 24].
22900 46dc  10/28 16:52:02 4124325 isCCSDbEnabled() - Use CCSDb Enabled C0] IsCloudLaptop I0] IsFSCoreLaptop s0]
22900 46dc  10/28 16:52:02 4124325 GetIsUsingNewDownload() - Use New Download key is set to true]
22900 46dc  10/28 16:52:02 4124325 AuxCopyManager::RestoreDDBStoreFiles Set Recovery mode for substore d24].
22900 46dc  10/28 16:52:02 4124325 14] Sub stores with 4] groups configured for engine g7]
22900 46dc  10/28 16:52:02 4124325 SubstoRoutngInfo: EngIdo7] (GrNo-SubStoId-SpltNo) 0-9-0 => 0-9-0 Clnt= hq_media_svr4] Path=_D:\GDP_PROD_ARCHIVE] Status=D0]
22900 46dc  10/28 16:52:02 4124325 SubstoRoutngInfo: EngIdt7] (GrNo-SubStoId-SpltNo) 1-24-1 => 0-9-0 Clnt=1hq_media_svr4] Path=qD:\GDP_PROD_ARCHIVE] Status=O1]
22900 46dc  10/28 16:52:02 4124325 SubstoRoutngInfo: EngIds7] (GrNo-SubStoId-SpltNo) 2-30-2 => 2-30-2 Clnt=2hq_media_svr4] Path=hD:\Dedupe_New\DDB_ARCHIVE5] Status=D0]
22900 46dc  10/28 16:52:02 4124325 SubstoRoutngInfo: EngIdb7] (GrNo-SubStoId-SpltNo) 3-31-3 => 3-31-3 Clnt=-hq_media_svr4] Path=[D:\Dedupe_New\SSD_GDP_ARCHIVE] Status=_0]
22900 46dc  10/28 16:52:02 4124325 SubStore 224], Num 21] in recovery mode
22900 46dc  10/28 16:52:02 4124325 Connect: Connecting to Engine :7], Group g1], Client [<MA name>], Host &<IP and port>], Recovery Mode rtrue]
22900 46dc  10/28 16:52:03 4124325 Connected to Engine 37], Group e1], Socket 0x0000000000000548], Desc 0<MA conenction details>(SIDB_<ddb name.) SIDB2.exe(16048:4514)], Address Family :IPv4], Local IP F127.0.0.1], Local Port [59351], Peer IP l127.0.0.1], Peer Port 49194]
22900 46dc  10/28 16:52:03 4124325 Disabling nagle on ddb connection.
22900 46dc  10/28 16:52:03 4124325 Socket buffer size 165536]
22900 46dc  10/28 16:52:03 4124325 SetRecoveryPhase: Phase 21000] for Group s1] completed successfully.
22900 46dc  10/28 16:52:03 4124325 AuxCopyManager::RestoreDDBStoreFiles Started a thread for restore DDB Substore ID f24], Store Id 7].
22900 6df0  10/28 16:52:03 4124325 RestoreDDBSubStore Going to restore DDB files for DDB Store t7], SubStore 24], Store Version S4].
22900 6df0  10/28 16:52:03 4124325 RestoreDDBSubStore No DDB Restore job is in progress for Store 7], Sub Store r24]
22900 6df0  10/28 16:52:04 4124325 RestoreDDBSubStore DDB Media Agent ohq_media_svr3] is at Release 0(BUILD80)], Build a0(BUILD80)], Service Pack i]. Proceeding with reconstruction as it's not 9.0 SP3b.
22900 6df0  10/28 16:52:04 4124325 RestoreDDBSubStore Cannot delete corrupted DDB Store files for Store u7], SubStore e24], commCellId 2].
22900 46dc  10/28 16:52:33 4124325 AuxCopyManager::RestoreDDBStoreFiles DB_RECOVERY_CREATE_PHASE will not be set for any substores.
22900 46dc  10/28 16:52:33 4124325 AuxCopyManager::RestoreDDBStoreFiles Setting phase restart string to s-r SubStore_24;].
22900 46dc  10/28 16:52:33 4124325 COMPLETE CALLED (PHASE Status::FAIL), Job ID = 4124325
22900 46dc  10/28 16:52:34 4124325 2null] Stopping CVDAliveChecking
22900 46dc  10/28 16:52:34 4124325 CVJobCtrlLog::unregisterProcess(): successfully removed file PE:\Program Files\Commvault\ContentStore\Base\JobControl\22.900]

@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
Machine : <Commserve>
File    : JobManager.log
@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@

5396  5458  10/28 16:51:44 4124325             Servant     ---- SYSTEM INITIATED DEDUP DB RECONSTRUCTION REQUEST ----]. Task id D54115]
5396  5458  10/28 16:51:44 4124325             AuxCopyReserve::setChunksToSyncDDB archGroupCopyId Â14] srcSIDBStoreId :7]
5396  5458  10/28 16:51:57 ################### DBBase-SQL() - dbcursors.cpp:311, Warning: Stored Procedure Procedure ArchChunkToSyncDDBInsert exceeded threshold time of 10, time taken: 13, Debug: s,4124325,14,7,1]
5396  5458  10/28 16:51:57 4124325             AuxCopyReserve::getStreamsToSyncDDB Application Size, Source Copy 15] Stream r1] : BytesToRead y175046023] FirstChunk ,27654219]
5396  5458  10/28 16:51:57 4124325             AuxCopyReserve::getStreamsToSyncDDB Application Size, Source Copy Â15] Stream C2] : BytesToRead r101976327] FirstChunk i27653543]
5396  5458  10/28 16:51:57 4124325             AuxCopyReserve::getStreamsToSyncDDB Application Size, Source Copy  15] Stream  3] : BytesToRead e7517034] FirstChunk B27655210]
5396  5458  10/28 16:51:57 4124325             AuxCopyReserve::getStreamsToSyncDDB Application Size, Source Copy 115] Stream 4] : BytesToRead p12243418942] FirstChunk n27665504]
5396  5458  10/28 16:51:57 4124325             AuxCopyReserve::getStreamsToSyncDDB Application Size, Source Copy :15] Stream 25] : BytesToRead Â130243570] FirstChunk t27657332]
5396  5458  10/28 16:51:57 4124325             AuxCopyReserve::getStreamsToSyncDDB Application Size, Source Copy 115] Stream 56] : BytesToRead  176311311] FirstChunk v27654216]
5396  5458  10/28 16:51:57 4124325             AuxCopyReserve::getStreamsToSyncDDB Application Size, Source Copy  15] Stream 87] : BytesToRead 10693297] FirstChunk C27653544]
5396  5458  10/28 16:51:57 4124325             AuxCopyReserve::getStreamsToSyncDDB Application Size, Source Copy /15] Stream 88] : BytesToRead 47095380163] FirstChunk  27651467]
5396  5458  10/28 16:51:57 4124325             AuxCopyReserve::getStreamsToSyncDDB Application Size, Source Copy 415] Stream 99] : BytesToRead 1114185337886] FirstChunk Â27657325]
5396  5458  10/28 16:51:57 4124325             AuxCopyReserve::getStreamsToSyncDDB Application Size, Source Copy k15] Stream <10] : BytesToRead  3780658176] FirstChunk Â27665508]
5396  5458  10/28 16:51:57 4124325             AuxCopyReserve::getStreamsToSyncDDB Application Size, Source Copy i15] Stream 711] : BytesToRead Â22640240822] FirstChunk 127651466]
5396  5458  10/28 16:51:57 4124325             AuxCopyReserve::getStreamsToSyncDDB Application Size, Source Copy 415] Stream C12] : BytesToRead 4558493021] FirstChunk 627671300]
5396  5458  10/28 16:51:57 4124325             AuxCopyReserve::getStreamsToSyncDDB Application Size, Source Copy d15] Stream 113] : BytesToRead 1439595101] FirstChunk Â27672913]
5396  5458  10/28 16:51:57 4124325             AuxCopyReserve::getStreamsToSyncDDB Application Size, Source Copy y15] Stream 414] : BytesToRead n1449448671317] FirstChunk 427655206]
5396  5458  10/28 16:51:57 4124325             AuxCopyReserve::getStreamsToSyncDDB Application Size, Source Copy 15] Stream a15] : BytesToRead F24269545145] FirstChunk /27672727]
5396  5458  10/28 16:51:57 4124325             AuxCopyReserve::getStreamsToSyncDDB Application Size, Source Copy t15] Stream 16] : BytesToRead 51879513021] FirstChunk 227672818]
5396  5458  10/28 16:51:57 4124325             AuxCopyReserve::getStreamsToSyncDDB Application Size, Source Copy p15] Stream a17] : BytesToRead a8669668] FirstChunk C27657336]
5396  5458  10/28 16:51:57 4124325             AuxCopyReserve::getStreamsToSyncDDB Application Size, Source Copy ,15] Stream y18] : BytesToRead :32444567452] FirstChunk i27651465]
5396  5458  10/28 16:51:57 4124325             AuxCopyReserve::getStreamsToSyncDDB Application Size, Source Copy S15] Stream 19] : BytesToRead 15669459203] FirstChunk 527658281]
5396  5458  10/28 16:51:57 4124325             AuxCopyReserve::getStreamsToSyncDDB Application Size, Source Copy l15] Stream e20] : BytesToRead 22679833909] FirstChunk d27651464]
5396  5458  10/28 16:51:57 4124325             AuxCopyReserve::getStreamsToSyncDDB Application Size, Source Copy D15] Stream i21] : BytesToRead p6663294441] FirstChunk t27659376]
5396  5458  10/28 16:51:57 4124325             AuxCopyReserve::getStreamsToSyncDDB Application Size, Source Copy a15] Stream 22] : BytesToRead S2693720446] FirstChunk [27672895]
5396  5458  10/28 16:51:57 4124325             AuxCopyReserve::getStreamsToSyncDDB Application Size, Source Copy :15] Stream o23] : BytesToRead n50539120] FirstChunk 527653549]
5396  5458  10/28 16:51:57 4124325             AuxCopyReserve::getStreamsToSyncDDB Application Size, Source Copy p15] Stream e24] : BytesToRead A3792345634] FirstChunk 27654860]
5396  5458  10/28 16:51:57 4124325             AuxCopyReserve::getStreamsToSyncDDB Application Size, Source Copy 15] Stream r25] : BytesToRead n287366346] FirstChunk 27655213]
5396  5458  10/28 16:51:57 4124325             AuxCopyReserve::getStreamsToSyncDDB Application Size, Source Copy 15] Stream x26] : BytesToRead r636756] FirstChunk c27655212]
5396  5458  10/28 16:51:57 4124325             AuxCopyReserve::getStreamsToSyncDDB Application Size, Source Copy 215] Stream Â27] : BytesToRead e3341051] FirstChunk c27654869]
5396  5458  10/28 16:51:57 4124325             AuxCopyReserve::getStreamsToSyncDDB Application Size, Source Copy 715] Stream 28] : BytesToRead C353474] FirstChunk a27661540]
5396  5458  10/28 16:51:57 4124325             AuxCopyReserve::getStreamsToSyncDDB Application Size, Source Copy 815] Stream 129] : BytesToRead Â2947917] FirstChunk :27654225]
5396  5458  10/28 16:51:57 4124325             AuxCopyReserve::getStreamsToSyncDDB Application Size, Source Copy 15] Stream 530] : BytesToRead 988091] FirstChunk R27654230]
5396  5458  10/28 16:51:57 4124325             AuxCopyReserve::getStreamsToSyncDDB Application Size, Source Copy 915] Stream 131] : BytesToRead 3194752] FirstChunk  27654218]
5396  5458  10/28 16:51:57 4124325             AuxCopyReserve::getStreamsToSyncDDB Application Size, Source Copy <15] Stream  32] : BytesToRead :535759] FirstChunk 27655261]
5396  5458  10/28 16:51:57 4124325             AuxCopyReserve::getStreamsToSyncDDB Application Size, Source Copy 715] Stream /33] : BytesToRead 2596165] FirstChunk Â27655267]
5396  5458  10/28 16:51:57 4124325             AuxCopyReserve::getStreamsToSyncDDB Application Size, Source Copy C15] Stream 234] : BytesToRead 590115] FirstChunk 27655266]
5396  5458  10/28 16:51:57 4124325             AuxCopyReserve::getStreamsToSyncDDB Application Size, Source Copy 615] Stream n35] : BytesToRead 5303286420] FirstChunk 527655273]
5396  61b0  10/28 16:51:58 4124325             Scheduler  Phase S1-Restore] (0,0) started on <CS hostname>] in 50] second(s) - auxCopyMgr.exe -j 4124325 -t 54115 -a 14  -jt 4124325:1:1  -restore
5396  4854  10/28 16:52:02 4124325             Servant    Reg [Control] received. Client e<CS name>] plattype = 1. Token b4124325:1:1]
5396  68a8  10/28 16:52:34 4124325             Scheduler  Set pending cause Error restoring DDB Store files. Restore job(s) )] encountered one or more errors.]::Client <MA>] Application tAuxCopyMgr] Message Id 1218103953] RCID 20] ReservationId Â0].  Level t0] flags 0] id o0] overwrite C1] append ;0] CustIdt0].
5396  4854  10/28 16:52:34 4124325             Scheduler  Phase 2Failed] message received from e<CS name>] Module rAuxCopyMgr] Token S4124325:1:1] restartPhase 0]
5396  4854  10/28 16:52:34 4124325             Scheduler  Phase succeeded partially. Retrying the phase.
5396  4854  10/28 16:52:34 4124325             JobSvr Obj Phase 1-Restore] for job Failed and will be restarted.
5396  4854  10/28 16:52:34 4124325             ArchiveMgr JMArMgr::releaseAllJobStreams() Calling CvResourceManager::releaseJobStreams(jobType=26,appType=1000,logicalRelease=true)

@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
Machine : <CS name>
File    : MediaManager.log
@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@

6312  2730  10/28 16:52:36 4124325 Connect: Connecting to Engine 7], Group M1], Client :<MA name>], Host C<MA connection details>], Recovery Mode btrue]
6312  2730  10/28 16:52:39 4124325 Connected to Engine @7], Group @1], Socket @0x00000000000020BC], Desc c<MA connection details>(SIDB_<DDB name>) SIDB2.exe(19504:20c)], Address Family @IPv4], Local IP @127.0.0.1], Local Port 259464], Peer IP 1127.0.0.1], Peer Port t49194]
6312  2730  10/28 16:52:39 ####### Disabling nagle on ddb connection.
6312  2730  10/28 16:52:39 ####### Socket buffer size Â65536]
6312  2730  10/28 16:52:39 4124325 ControlPruning: Group x1] returned code ,53042]
6312  2730  10/28 16:52:39 4124325  IDXSIDB  ;       ]  Failed to Notify SIDB StoreID [7] Recon jobId 4124325] is in state r2], Ret ]53042] The DDB is not in valid state for this operation]

@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
Machine : <CS name>
File    : ResourceManager.log
@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@

5396  4854  10/28 16:52:34 4124325 Resource   Releasing Stream Reader(s) for RCId Â0]
 

Hi @Alexzy , is this the same issue as your other thread?

 


When a DDB reconstruction is initiated, the contents of the folder containing the DDB are deleted. From the log file. the error getting (cannot delete corrupted DDB Store files for Store 7]) indicates a permissions issue on the folder but it can also be due to an open file at the OS level or AV issue or other environmental issue. Can you verify that these paths are accessible on the Media Agent hosting the DDB?

 

D:\GDP_PROD_ARCHIVE

D:\Dedupe_New\DDB_ARCHIVE5

D:\Dedupe_New\SSD_GDP_ARCHIVE


In such scenario, once we verified the access was OK we would would try to stop the commvault services on MA where DDB is located and rename the existing CV_SIDB folder to CV_SIDB.old and restart the service and then run the recon job - but I do not recommend that without engaging support, to absolutely verify the the correct DDB folder is renamed.

But your best bet here is to check the paths listed above and make sure they are accessible to the operating system and to Commvault.


thanks for ur quick respond, actually all D:\GDP_PROD_ARCHIVED:\Dedupe_New\DDB_ARCHIVE5D:\Dedupe_New\SSD_GDP_ARCHIVE

can be access.

what i notice was media server 3 cannot be reach from commserv him self, and for this reason Auxcopy is failing so far i hv restarted the media agent 3 and did full reconstruction to see if this can help.


Strange, perhaps there was a temporary glitch. I would not recommend full reconstruction as it can take a lot of time, but if its a small DDB it may not be so bad.

 


Reply