Symptom
Restore of full backup works with Cohesity, but the PIT (Point In Time) recovery hangs and the TenantDB is not in GREEN state.
Following error in the trace:
[14511]{-1}[-1/-1] 2023-06-17 19:35:34.478787 a Backup BackupDestBackint_Executor.cpp(00186) : Exit void Backup::BackupDestBackint_Executor::waitForBackintTermination(Backup::BackupDestBackint_Job&, uint64_t)(4usec)
[14511]{-1}[-1/-1] 2023-06-17 19:35:34.478789 i Backup BackupExe_BackintHandlerImpl.cpp(00047) : ~BackupExe_BackintHandlerImpl: backint terminated
[14511]{-1}[-1/-1] 2023-06-17 19:35:34.478881 a Backup BackupMgr_Client.cpp(00862) : Enter virtual void Backup::BackupMgr_Client::sendRequest(const Backup::BackupMgr_Request&, Backup::BackupMgr_Response&)
[31590]{-1}[-1/-1] 2023-06-17 19:35:34.479374 a Backup BackupMgr_Manager.cpp(00503) : Enter virtual void Backup::BackupMgr_Manager::handleRequest(Backup::BackupMgr_Request&, Backup::BackupMgr_Response&)
Arg request = (S)SenderHost=sothdXXX0101|SenderPort=30103|TextMessage=2023-06-17 19:35:34.478 backint terminated:
pid: 33389
exit code: 0
output:
#SOFTWAREID "1.04" "Cohesity DataProtect 6.6 for SAP HANA"
#RESTORED 1687003444474522_764225954 "/usr/sap/XXX/SYS/global/hdb/backint/DB_XXX/log_backup_3_0_5394780385344_5394780575104"
#RESTORED 1687012028905289_1200559192 "/usr/sap/XXX/SYS/global/hdb/backint/DB_XXX/log_backup_3_0_5394780848768_5394780848832"
#RESTORED 1687012897081574_1940334891 "/usr/sap/XXX/SYS/global/hdb/backint/DB_XXX/log_backup_3_0_5394780848832_5394781185344"
#RESTORED 1687018452419615_400478964 "/usr/sap/XXX/SYS/global/hdb/backint/DB_XXX/log_backup_3_0_5394781185344_5394781185408"
|(I)Method=23|SenderDatabaseId=3|SenderService=1|VolumeID=3|
[31590]{-1}[-1/-1] 2023-06-17 19:35:34.479585 a Backup BackupMgr_Manager.cpp(00651) : Return (I)ReturnCode=0|
[31590]{-1}[-1/-1] 2023-06-17 19:35:34.479589 a Backup BackupMgr_Manager.cpp(00651) : Exit virtual void Backup::BackupMgr_Manager::handleRequest(Backup::BackupMgr_Request&, Backup::BackupMgr_Response&)(215usec)
[14511]{-1}[-1/-1] 2023-06-17 19:35:34.479885 a Backup BackupMgr_Client.cpp(00862) : Exit virtual void Backup::BackupMgr_Client::sendRequest(const Backup::BackupMgr_Request&, Backup::BackupMgr_Response&)(1004usec)
[14511]{-1}[-1/-1] 2023-06-17 19:35:34.480016 a Backup BackupExe_SimpleExecutor.cpp(00431) : Exit virtual void Backup::BackupExe_SimpleExecutor::executeRestore(DataAccess::RedoLogPosition, Backup::BackupExe_JobRestoreGlobalParams&, Backup::Executor::BackupType, Backup::Executor::RecoveryResults&)(44837245usec)
[14511]{-1}[-1/-1] 2023-06-17 19:35:34.480245 d Backup BackupRecoverLogHandler.cpp(00402) : after everything has been done: finish the redo
[14511]{-1}[-1/-1] 2023-06-17 19:35:34.480249 a Backup BackupExe_SimpleExecutor.cpp(00639) : Enter void Backup::BackupExe_SimpleExecutor::waitForFinishLogRecovery()
[32261]{-1}[-1/-1] 2023-06-17 19:35:35.143258 a Backup BackupExe_LogRecoveryCallback.cpp(00069) : Enter virtual void Backup::BackupExe_LogRecoveryCallback::recoveryPointInTimeReached(DataAccess::RedoLogPosition, const ltt::map<unsigned int, long unsigned int>&, uint64_t, DataAccess::LogRecoveryCallback::PointInTimeReason)
[32261]{-1}[-1/-1] 2023-06-17 19:35:35.143283 d Backup BackupExe_LogRecoveryCallback.cpp(00071) : Point in time reached LogPos = 0x4e812042580 Time = 2023-06-17 13:59:42.293159 reason = point in time reached
[32261]{-1}[-1/-1] 2023-06-17 19:35:35.143301 d Backup BackupExe_LogRecoveryCallback.cpp(00078) : Slave position reached: 0x38c9a2084 at volume 2
[32261]{-1}[-1/-1] 2023-06-17 19:35:35.143348 a Backup BackupMgr_Client.cpp(00862) : Enter virtual void Backup::BackupMgr_Client::sendRequest(const Backup::BackupMgr_Request&, Backup::BackupMgr_Response&)
[31734]{-1}[-1/-1] 2023-06-17 19:35:35.143696 a Backup BackupMgr_Manager.cpp(00503) : Enter virtual void Backup::BackupMgr_Manager::handleRequest(Backup::BackupMgr_Request&, Backup::BackupMgr_Response&)
Arg request = (S)SenderHost=sothdXXX0101|SenderPort=30103|(I)Method=9|NextReason=0|NextSlaveCount=1|NextSlaveVolume_0=2|SenderDatabaseId=3|SenderService=1|VolumeID=3|(L)NextReachedPosition=5394781185408|NextSlavePos_0=15243812996|NextTimestamp=1687003182293159|
[31734]{-1}[-1/-1] 2023-06-17 19:35:35.143729 a Backup BackupMgr_Manager.cpp(02927) : Enter void Backup::BackupMgr_Manager::lrcGetNextTarget(Backup::BackupMgr_Request&, Backup::BackupMgr_Response&)
[31734]{-1}[-1/-1] 2023-06-17 19:35:35.143744 a Backup BackupMgrLRC_LogReplayCoordinator.cpp(00447) : Enter void Backup::BackupMgr_LogReplayCoordinator::getNextTargetForMaster(DataAccess::LogRecoveryCallback::PointInTimeReason, DataAccess::RedoLogPosition, uint64_t, const ltt::map<unsigned int, long unsigned int>&, Backup::BackupMgrClient_LRCGetNextTargetResponse&)
Arg this = 0x00007f6ea4970b80
[31734]{-1}[-1/-1] 2023-06-17 19:35:35.143749 d Backup BackupMgrLRC_LogReplayCoordinator.cpp(00449) : LRC::getNextTargetForMaster volume: 3, reachedPos: 5394781185408, reachedTime: 1687003182293, Reason: point in time reached
[31734]{-1}[-1/-1] 2023-06-17 19:35:35.143754 i Backup BackupMgrLRC_LogReplayCoordinator.cpp(00473) : Save next slave position 15243812996 for volume 2
[31734]{-1}[-1/-1] 2023-06-17 19:35:35.143756 d Backup BackupMgrLRC_VolumeInfo.hpp(00098) : Setting next target redo log position for volume ID 2 to 15243812996 (current: 15243807747)
[31734]{-1}[-1/-1] 2023-06-17 19:35:35.143757 d Backup BackupMgrLRC_LogReplayCoordinator.cpp(00534) : LRC::getNextTargetForMaster volume: 3, Setting m_finishReplay to 1 because EndTime or LogPos reached. Reason: point in time reached reachedPosition: 5394781185408 youngestMasterPosition: 5394781185408 endOfLogOnSlave: 0
[31734]{-1}[-1/-1] 2023-06-17 19:35:35.143764 a Backup BackupMgrLRC_LogReplayCoordinator.hpp(00318) : Enter void Backup::BackupMgr_LogReplayCoordinator::finalTargetsAvailable()
[31734]{-1}[-1/-1] 2023-06-17 19:35:35.143779 a Backup BackupMgrLRC_LogReplayCoordinator.hpp(00318) : Exit void Backup::BackupMgr_LogReplayCoordinator::finalTargetsAvailable()(15usec)
[31734]{-1}[-1/-1] 2023-06-17 19:35:35.143781 a Backup BackupMgrLRC_LogReplayCoordinator.cpp(00447) : Exit void Backup::BackupMgr_LogReplayCoordinator::getNextTargetForMaster(DataAccess::LogRecoveryCallback::PointInTimeReason, DataAccess::RedoLogPosition, uint64_t, const ltt::map<unsigned int, long unsigned int>&, Backup::BackupMgrClient_LRCGetNextTargetResponse&)(37usec)
[31734]{-1}[-1/-1] 2023-06-17 19:35:35.143782 a Backup BackupMgr_Manager.cpp(02927) : Exit void Backup::BackupMgr_Manager::lrcGetNextTarget(Backup::BackupMgr_Request&, Backup::BackupMgr_Response&)(53usec)
[31734]{-1}[-1/-1] 2023-06-17 19:35:35.143785 a Backup BackupMgr_Manager.cpp(00651) : Return (I)ReturnCode=0|(L)NextTargetTimestamp=1687003182293|(B)FinishReplay=1|
[31734]{-1}[-1/-1] 2023-06-17 19:35:35.143787 a Backup BackupMgr_Manager.cpp(00651) : Exit virtual void Backup::BackupMgr_Manager::handleRequest(Backup::BackupMgr_Request&, Backup::BackupMgr_Response&)(91usec)
[16899]{-1}[-1/-1] 2023-06-17 19:35:35.143841 a Backup BackupMgrLRC_LogReplayCoordinator.hpp(00313) : Exit virtual void Backup::BackupMgr_LogReplayCoordinator::waitForFinalTargets()(39432485usec)
[16899]{-1}[-1/-1] 2023-06-17 19:35:35.143850 a Backup BackupMgrLRC_LogReplayCoordinator.cpp(00190) : Enter virtual DataAccess::RedoLogPosition Backup::BackupMgr_LogReplayCoordinator::getTarget(DataAccess::VolumeID)
Arg this = 0x00007f6ea4970b80
[16899]{-1}[-1/-1] 2023-06-17 19:35:35.143856 a Backup BackupMgrLRC_LogReplayCoordinator.cpp(00190) : Exit virtual DataAccess::RedoLogPosition Backup::BackupMgr_LogReplayCoordinator::getTarget(DataAccess::VolumeID)(6usec)
[16899]{-1}[-1/-1] 2023-06-17 19:35:35.143858 d Backup BackupMgrLRC_LogReplayCoordinator.cpp(00600) : LRC::getNextTargetForSlave volume: 2, next target: 15243812996
[16899]{-1}[-1/-1] 2023-06-17 19:35:35.143867 a Backup BackupMgrLRC_LogReplayCoordinator.cpp(00580) : Exit void Backup::BackupMgr_LogReplayCoordinator::getNextTargetForSlave(DataAccess::LogRecoveryCallback::PointInTimeReason, DataAccess::RedoLogPosition, uint64_t, DataAccess::VolumeID, Backup::BackupMgrClient_LRCGetNextTargetResponse&)(39432518usec)
[16899]{-1}[-1/-1] 2023-06-17 19:35:35.143871 a Backup BackupMgr_Manager.cpp(02927) : Exit void Backup::BackupMgr_Manager::lrcGetNextTarget(Backup::BackupMgr_Request&, Backup::BackupMgr_Response&)(39432528usec)
[16899]{-1}[-1/-1] 2023-06-17 19:35:35.143874 a Backup BackupMgr_Manager.cpp(00651) : Return (I)ReturnCode=0|(L)NextTarget=15243812996|(B)FinishReplay=0|
[16899]{-1}[-1/-1] 2023-06-17 19:35:35.143879 a Backup BackupMgr_Manager.cpp(00651) : Exit virtual void Backup::BackupMgr_Manager::handleRequest(Backup::BackupMgr_Request&, Backup::BackupMgr_Response&)(39432544usec)
[32261]{-1}[-1/-1] 2023-06-17 19:35:35.143905 a Backup BackupMgr_Client.cpp(00862) : Exit virtual void Backup::BackupMgr_Client::sendRequest(const Backup::BackupMgr_Request&, Backup::BackupMgr_Response&)(557usec)
[32261]{-1}[-1/-1] 2023-06-17 19:35:35.143919 d Backup BackupExe_LogRecoveryCallback.cpp(00156) : Calling startFinishLogRecoveryJob
[32261]{-1}[-1/-1] 2023-06-17 19:35:35.143922 a Backup BackupExe_SimpleExecutor.cpp(00680) : Enter void Backup::BackupExe_SimpleExecutor::startFinishLogRecoveryJob()
[32261]{-1}[-1/-1] 2023-06-17 19:35:35.143963 a Backup BackupExe_SimpleExecutor.cpp(00680) : Exit void Backup::BackupExe_SimpleExecutor::startFinishLogRecoveryJob()(41usec)
[32261]{-1}[-1/-1] 2023-06-17 19:35:35.143971 a Backup BackupExe_LogRecoveryCallback.cpp(00069) : Exit virtual void Backup::BackupExe_LogRecoveryCallback::recoveryPointInTimeReached(DataAccess::RedoLogPosition, const ltt::map<unsigned int, long unsigned int>&, uint64_t, DataAccess::LogRecoveryCallback::PointInTimeReason)(713usec)
[31801]{-1}[-1/-1] 2023-06-17 19:35:35.144047 a Backup BackupExe_SimpleExecutor.cpp(00690) : Enter void Backup::BackupExe_SimpleExecutor::finishLogRecovery()
[31801]{-1}[-1/-1] 2023-06-17 19:35:35.144065 i PersistenceManag PersistenceManagerSPI.cpp(01162) : Notify RedoHandler listener about new state: 0
[31801]{-1}[-1/-1] 2023-06-17 19:35:35.144081 i CSARedo RedoMerge.cpp(02933) : Cancel ongoing merges that are not ready to be committed
[31801]{-1}[-1/-1] 2023-06-17 19:35:35.144086 i PersistenceManag PersistenceManagerSPI.cpp(01182) : Notification of RedoHandler listener finished
[31801]{-1}[-1/-1] 2023-06-17 19:35:35.144103 i Logger RecoveryHandlerImpl.cpp(01910) : Finishing log recovery, waiting for in-process and in-load segments
[32280]{-1}[-1/-1] 2023-06-17 19:35:35.144152 i Logger RecoveryHandlerImpl.cpp(03144) : LogRecovery: no further point in time, stopping (pointInTime=0x0, pos=0x4e812042580 reason=point in time reached)
[32280]{-1}[-1/-1] 2023-06-17 19:35:35.144187 w Logger RecoveryHandlerImpl.cpp(02681) : Log ends at 0x4e812042580, cannot recover until 0x0 (inexact)
[32280]{-1}[-1/-1] 2023-06-17 19:35:35.144401 i Logger RecoveryHandlerImpl.cpp(04290) : Signaling finish wait barrier
[31801]{-1}[-1/-1] 2023-06-17 19:35:35.144741 i Logger RecoveryHandlerImpl.cpp(01913) : Finish wait barrier signaled
[31801]{-1}[-1/-1] 2023-06-17 19:35:35.145073 i Logger RecoveryHandlerImpl.cpp(01941) : Wait for recovery queue threads
[32275]{-1}[-1/-1] 2023-06-17 19:35:35.146387 a Backup BackupExe_LogRecoveryCallback.cpp(00069) : Enter virtual void Backup::BackupExe_LogRecoveryCallback::recoveryPointInTimeReached(DataAccess::RedoLogPosition, const ltt::map<unsigned int, long unsigned int>&, uint64_t, DataAccess::LogRecoveryCallback::PointInTimeReason)
[32275]{-1}[-1/-1] 2023-06-17 19:35:35.146393 d Backup BackupExe_LogRecoveryCallback.cpp(00071) : Point in time reached LogPos = 0x4e812042580 Time = 2023-06-17 13:59:42.293159 reason = end of log
[32275]{-1}[-1/-1] 2023-06-17 19:35:35.146406 d Backup BackupExe_LogRecoveryCallback.cpp(00078) : Slave position reached: 0x38c9a2084 at volume 2
[32275]{-1}[-1/-1] 2023-06-17 19:35:35.146407 d Backup BackupExe_LogRecoveryCallback.cpp(00085) : pointInTimeReached-callback ignored because isFinishReplay has been set before
[32275]{-1}[-1/-1] 2023-06-17 19:35:35.146409 a Backup BackupExe_LogRecoveryCallback.cpp(00069) : Exit virtual void Backup::BackupExe_LogRecoveryCallback::recoveryPointInTimeReached(DataAccess::RedoLogPosition, const ltt::map<unsigned int, long unsigned int>&, uint64_t, DataAccess::LogRecoveryCallback::PointInTimeReason)(22usec)
[31801]{-1}[-1/-1] 2023-06-17 19:35:35.150168 i Logger RecoveryHandlerImpl.cpp(01948) : Recovery finished at log position 0x4e812042580
Read more...
Environment
SAP HANA DB Version 2.0
Keywords
KBA , HAN-DB-BAC , SAP HANA Backup & Recovery , Problem
About this page
This is a preview of a SAP Knowledge Base Article. Click more to access the full version on SAP for Me (Login required).Search for additional results
Visit SAP Support Portal's SAP Notes and KBA Search.