refactor(sync): add trace log for elect count, become leader count, config change count
This commit is contained in:
parent
ab40b8190f
commit
ebe1103964
|
@ -192,6 +192,10 @@ typedef struct SSyncNode {
|
|||
int64_t leaderTime;
|
||||
int64_t lastReplicateTime;
|
||||
|
||||
int32_t electNum;
|
||||
int32_t becomeLeaderNum;
|
||||
int32_t configChangeNum;
|
||||
|
||||
bool isStart;
|
||||
|
||||
} SSyncNode;
|
||||
|
|
|
@ -61,7 +61,8 @@ static int32_t syncNodeRequestVotePeers(SSyncNode* pNode) {
|
|||
}
|
||||
|
||||
int32_t syncNodeElect(SSyncNode* pSyncNode) {
|
||||
sNTrace(pSyncNode, "begin election");
|
||||
sNInfo(pSyncNode, "begin election");
|
||||
pSyncNode->electNum++;
|
||||
|
||||
int32_t ret = 0;
|
||||
if (pSyncNode->state == TAOS_SYNC_STATE_FOLLOWER) {
|
||||
|
@ -86,7 +87,7 @@ int32_t syncNodeElect(SSyncNode* pSyncNode) {
|
|||
syncNodeCandidate2Leader(pSyncNode);
|
||||
pSyncNode->pVotesGranted->toLeader = true;
|
||||
return ret;
|
||||
}
|
||||
}
|
||||
|
||||
if (pSyncNode->replicaNum == 1) {
|
||||
// only myself, to leader
|
||||
|
@ -98,7 +99,6 @@ int32_t syncNodeElect(SSyncNode* pSyncNode) {
|
|||
syncNodeCandidate2Leader(pSyncNode);
|
||||
pSyncNode->pVotesGranted->toLeader = true;
|
||||
return ret;
|
||||
|
||||
}
|
||||
|
||||
ret = syncNodeRequestVotePeers(pSyncNode);
|
||||
|
|
|
@ -1008,6 +1008,10 @@ SSyncNode* syncNodeOpen(SSyncInfo* pSyncInfo) {
|
|||
atomic_store_64(&pSyncNode->snapshottingIndex, SYNC_INDEX_INVALID);
|
||||
|
||||
pSyncNode->isStart = true;
|
||||
pSyncNode->electNum = 0;
|
||||
pSyncNode->becomeLeaderNum = 0;
|
||||
pSyncNode->configChangeNum = 0;
|
||||
|
||||
sNTrace(pSyncNode, "sync open, node:%p", pSyncNode);
|
||||
|
||||
return pSyncNode;
|
||||
|
@ -1340,6 +1344,8 @@ void syncNodeDoConfigChange(SSyncNode* pSyncNode, SSyncCfg* pNewConfig, SyncInde
|
|||
pSyncNode->pRaftCfg->cfg = *pNewConfig;
|
||||
pSyncNode->pRaftCfg->lastConfigIndex = lastConfigChangeIndex;
|
||||
|
||||
pSyncNode->configChangeNum++;
|
||||
|
||||
bool IamInOld = syncNodeInConfig(pSyncNode, &oldConfig);
|
||||
bool IamInNew = syncNodeInConfig(pSyncNode, pNewConfig);
|
||||
|
||||
|
@ -1363,7 +1369,7 @@ void syncNodeDoConfigChange(SSyncNode* pSyncNode, SSyncCfg* pNewConfig, SyncInde
|
|||
char newCfgStr[1024] = {0};
|
||||
syncCfg2SimpleStr(&oldConfig, oldCfgStr, sizeof(oldCfgStr));
|
||||
syncCfg2SimpleStr(pNewConfig, oldCfgStr, sizeof(oldCfgStr));
|
||||
sNTrace(pSyncNode, "begin do config change, from %s to %s", oldCfgStr, oldCfgStr);
|
||||
sNInfo(pSyncNode, "begin do config change, from %s to %s", oldCfgStr, oldCfgStr);
|
||||
|
||||
if (IamInNew) {
|
||||
pSyncNode->pRaftCfg->isStandBy = 0; // change isStandBy to normal
|
||||
|
@ -1495,13 +1501,13 @@ void syncNodeDoConfigChange(SSyncNode* pSyncNode, SSyncCfg* pNewConfig, SyncInde
|
|||
} else {
|
||||
// persist cfg
|
||||
raftCfgPersist(pSyncNode->pRaftCfg);
|
||||
sNTrace(pSyncNode, "do not config change from %d to %d, index:%" PRId64 ", %s --> %s", oldConfig.replicaNum,
|
||||
pNewConfig->replicaNum, lastConfigChangeIndex, oldCfgStr, newCfgStr);
|
||||
sNInfo(pSyncNode, "do not config change from %d to %d, index:%" PRId64 ", %s --> %s", oldConfig.replicaNum,
|
||||
pNewConfig->replicaNum, lastConfigChangeIndex, oldCfgStr, newCfgStr);
|
||||
}
|
||||
|
||||
_END:
|
||||
// log end config change
|
||||
sNTrace(pSyncNode, "end do config change, from %s to %s", oldCfgStr, newCfgStr);
|
||||
sNInfo(pSyncNode, "end do config change, from %s to %s", oldCfgStr, newCfgStr);
|
||||
}
|
||||
|
||||
// raft state change --------------
|
||||
|
@ -1598,6 +1604,8 @@ void syncNodeBecomeFollower(SSyncNode* pSyncNode, const char* debugStr) {
|
|||
void syncNodeBecomeLeader(SSyncNode* pSyncNode, const char* debugStr) {
|
||||
pSyncNode->leaderTime = taosGetTimestampMs();
|
||||
|
||||
pSyncNode->becomeLeaderNum++;
|
||||
|
||||
// reset restoreFinish
|
||||
pSyncNode->restoreFinish = false;
|
||||
|
||||
|
@ -1666,7 +1674,7 @@ void syncNodeBecomeLeader(SSyncNode* pSyncNode, const char* debugStr) {
|
|||
pSyncNode->minMatchIndex = SYNC_INDEX_INVALID;
|
||||
|
||||
// trace log
|
||||
sNTrace(pSyncNode, "become leader %s", debugStr);
|
||||
sNInfo(pSyncNode, "become leader %s", debugStr);
|
||||
}
|
||||
|
||||
void syncNodeCandidate2Leader(SSyncNode* pSyncNode) {
|
||||
|
@ -1971,7 +1979,7 @@ static void syncNodeEqHeartbeatTimer(void* param, void* tmrId) {
|
|||
return;
|
||||
}
|
||||
|
||||
sTrace("enqueue heartbeat timer");
|
||||
sTrace("vgId:%d, enqueue heartbeat timer", pNode->vgId);
|
||||
code = pNode->syncEqMsg(pNode->msgcb, &rpcMsg);
|
||||
if (code != 0) {
|
||||
sError("failed to enqueue heartbeat msg since %s", terrstr());
|
||||
|
|
|
@ -52,7 +52,7 @@ static void syncNodeCleanConfigIndex(SSyncNode* ths) {
|
|||
}
|
||||
|
||||
static int32_t syncNodeTimerRoutine(SSyncNode* ths) {
|
||||
sNTrace(ths, "timer routines");
|
||||
sNInfo(ths, "timer routines");
|
||||
|
||||
// timer replicate
|
||||
syncNodeReplicate(ths);
|
||||
|
|
|
@ -275,18 +275,18 @@ void syncPrintNodeLog(const char* flags, ELogLevel level, int32_t dflag, SSyncNo
|
|||
terrno = errCode;
|
||||
|
||||
if (pNode != NULL && pNode->pRaftCfg != NULL) {
|
||||
taosPrintLog(flags, level, dflag,
|
||||
"vgId:%d, sync %s "
|
||||
"%s"
|
||||
", tm:%" PRIu64 ", cmt:%" PRId64 ", fst:%" PRId64 ", lst:%" PRId64 ", min:%" PRId64 ", snap:%" PRId64
|
||||
", snap-tm:%" PRIu64 ", sby:%d, aq:%d, snaping:%" PRId64 ", r-num:%d, lcfg:%" PRId64
|
||||
", chging:%d, rsto:%d, dquorum:%d, elt:%" PRId64 ", hb:%" PRId64 ", %s, %s, %s, %s",
|
||||
pNode->vgId, syncStr(pNode->state), eventLog, currentTerm, pNode->commitIndex, logBeginIndex,
|
||||
logLastIndex, pNode->minMatchIndex, snapshot.lastApplyIndex, snapshot.lastApplyTerm,
|
||||
pNode->pRaftCfg->isStandBy, aqItems, pNode->snapshottingIndex, pNode->replicaNum,
|
||||
pNode->pRaftCfg->lastConfigIndex, pNode->changing, pNode->restoreFinish, quorum,
|
||||
pNode->electTimerLogicClock, pNode->heartbeatTimerLogicClockUser, peerStr, cfgStr, hbTimeStr,
|
||||
hbrTimeStr);
|
||||
taosPrintLog(
|
||||
flags, level, dflag,
|
||||
"vgId:%d, sync %s "
|
||||
"%s"
|
||||
", tm:%" PRIu64 ", cmt:%" PRId64 ", fst:%" PRId64 ", lst:%" PRId64 ", min:%" PRId64 ", snap:%" PRId64
|
||||
", snap-tm:%" PRIu64 ", elt-num:%d, bl-num:%d, cc-num:%d, aq:%d, snaping:%" PRId64 ", r-num:%d, lcfg:%" PRId64
|
||||
", chging:%d, rsto:%d, dquorum:%d, elt:%" PRId64 ", hb:%" PRId64 ", %s, %s, %s, %s",
|
||||
pNode->vgId, syncStr(pNode->state), eventLog, currentTerm, pNode->commitIndex, logBeginIndex, logLastIndex,
|
||||
pNode->minMatchIndex, snapshot.lastApplyIndex, snapshot.lastApplyTerm, pNode->electNum, pNode->becomeLeaderNum,
|
||||
pNode->configChangeNum, aqItems, pNode->snapshottingIndex, pNode->replicaNum, pNode->pRaftCfg->lastConfigIndex,
|
||||
pNode->changing, pNode->restoreFinish, quorum, pNode->electTimerLogicClock, pNode->heartbeatTimerLogicClockUser,
|
||||
peerStr, cfgStr, hbTimeStr, hbrTimeStr);
|
||||
}
|
||||
}
|
||||
|
||||
|
@ -438,7 +438,8 @@ void syncLogRecvAppendEntriesReply(SSyncNode* pSyncNode, const SyncAppendEntries
|
|||
host, port, pMsg->term, pMsg->privateTerm, pMsg->success, pMsg->lastSendIndex, pMsg->matchIndex, s);
|
||||
}
|
||||
|
||||
void syncLogSendHeartbeat(SSyncNode* pSyncNode, const SyncHeartbeat* pMsg, bool printX, int64_t timerElapsed, int64_t execTime) {
|
||||
void syncLogSendHeartbeat(SSyncNode* pSyncNode, const SyncHeartbeat* pMsg, bool printX, int64_t timerElapsed,
|
||||
int64_t execTime) {
|
||||
if (!(sDebugFlag & DEBUG_TRACE)) return;
|
||||
|
||||
char host[64];
|
||||
|
|
Loading…
Reference in New Issue